Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

WARN fsync-ing the write ahead log in SyncThread:2 took 3932ms which will adversely effect operation latency. File size is 67108880 bytes #966

Open
ATM006 opened this issue Apr 1, 2021 · 0 comments
Assignees
Labels
task/investigate Investigate a potential new feature/technology
Milestone

Comments

@ATM006
Copy link
Contributor

ATM006 commented Apr 1, 2021

WARN fsync-ing the write ahead log in SyncThread:2 took 3932ms which will adversely effect operation latency. File size is 67108880 bytes
ZK works normally when running on SSD, but in mechanical hard disk, the synchronization delay of ZK is large, which leads to unstable service.What's a good solution? Is it feasible to modify ticktime, initlimit, synclimit and forcesync = no? And modify the configuration as in strimzi, because there are not so expensive resources in the production environment.

leader:
2021-03-31 07:38:27,700 INFO Processing ruok command from /127.0.0.1:44088 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-1]2021-03-31 07:38:28,130 WARN Closing connection to peer due to transaction timeout. (org.apache.zookeeper.server.quorum.LearnerHandler) [QuorumPeermyid=1(secure=0.0.0.0:2181)]2021-03-31 07:38:28,132 WARN Closing connection to peer due to transaction timeout. (org.apache.zookeeper.server.quorum.LearnerHandler) [QuorumPeermyid=1(secure=0.0.0.0:2181)]2021-03-31 07:38:28,133 WARN ******* GOODBYE sitewhere-kafka-zookeeper-2.sitewhere-kafka-zookeeper-nodes.sitewhere-system.svc.cluster.local/10.244.20.132:60346 ******** (org.apache.zookeeper.server.quorum.LearnerHandler) [LearnerHandler-/10.244.20.132:60346]2021-03-31 07:38:28,133 WARN ******* GOODBYE sitewhere-kafka-zookeeper-1.sitewhere-kafka-zookeeper-nodes.sitewhere-system.svc.cluster.local/10.244.38.250:41806 ******** (org.apache.zookeeper.server.quorum.LearnerHandler) [LearnerHandler-/10.244.38.250:41806]2021-03-31 07:38:28,133 WARN Ignoring unexpected exception (org.apache.zookeeper.server.quorum.LearnerHandler) [LearnerHandler-/10.244.38.250:41806]
java.lang.InterruptedException at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1261)
at java.base/java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317)
at java.base/java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:330)
at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:926)
at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647)
2021-03-31 07:38:28,133 WARN Ignoring unexpected exception (org.apache.zookeeper.server.quorum.LearnerHandler) [LearnerHandler-/10.244.20.132:60346]
java.lang.InterruptedException
at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1261) at java.base/java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317)
at java.base/java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:330)
at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:926)
at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647)
2021-03-31 07:38:29,133 INFO Shutting down (org.apache.zookeeper.server.quorum.Leader) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,133 INFO Shutdown called (org.apache.zookeeper.server.quorum.Leader) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
java.lang.Exception: shutdown Leader! reason: Not sufficient followers synced, only synced with sids: [ [1] ] at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:682)
at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:662) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1266)
2021-03-31 07:38:29,134 INFO exception while shutting down acceptor: java.net.SocketException: Socket closed (org.apache.zookeeper.server.quorum.Leader) [LearnerCnxAcceptor-sitewhere-kafka-zookeeper-0.sitewhere-kafka-zookeeper-nodes.sitewhere-system.svc/10.244.36.181:2888]
2021-03-31 07:38:29,135 INFO shutting down (org.apache.zookeeper.server.ZooKeeperServer) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,135 INFO Shutting down (org.apache.zookeeper.server.SessionTrackerImpl) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,135 INFO Shutting down (org.apache.zookeeper.server.quorum.LeaderRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,135 INFO Shutting down (org.apache.zookeeper.server.PrepRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,135 INFO Shutting down (org.apache.zookeeper.server.quorum.ProposalRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,135 INFO Shutting down (org.apache.zookeeper.server.quorum.CommitProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,135 INFO PrepRequestProcessor exited loop! (org.apache.zookeeper.server.PrepRequestProcessor) [ProcessThread(sid:1 cport:-1):]
2021-03-31 07:38:29,136 INFO Shutting down (org.apache.zookeeper.server.quorum.Leader) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,136 INFO shutdown of request processor complete (org.apache.zookeeper.server.FinalRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2021-03-31 07:38:29,136 INFO Shutting down (org.apache.zookeeper.server.SyncRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]

follower:
2021-03-31 07:37:44,452 INFO Processing ruok command from /127.0.0.1:52908 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-1]
2021-03-31 07:37:45,243 WARN fsync-ing the write ahead log in SyncThread:2 took 3932ms which will adversely effect operation latency. File size is 67108880 bytes. See the ZooKeeper troubleshooting guide (org.apache.zookeeper.server.persistence.FileTxnLog) [SyncThread:2]
2021-03-31 07:37:48,368 INFO Processing ruok command from /127.0.0.1:52962 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-2]
2021-03-31 07:37:54,458 INFO Processing ruok command from /127.0.0.1:53050 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-1]
2021-03-31 07:37:58,380 INFO Processing ruok command from /127.0.0.1:53122 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-2]
2021-03-31 07:38:04,445 INFO Processing ruok command from /127.0.0.1:53206 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-1]
2021-03-31 07:38:08,370 INFO Processing ruok command from /127.0.0.1:53280 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-2]
2021-03-31 07:38:14,454 INFO Processing ruok command from /127.0.0.1:53364 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-1]
2021-03-31 07:38:18,380 INFO Processing ruok command from /127.0.0.1:53448 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-2]
2021-03-31 07:38:24,451 INFO Processing ruok command from /127.0.0.1:53552 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-1]
2021-03-31 07:38:28,195 WARN Exception when following the leader (org.apache.zookeeper.server.quorum.Learner) [QuorumPeermyid=2(secure=0.0.0.0:2181)]
java.io.EOFException
at java.base/java.io.DataInputStream.readInt(DataInputStream.java:397)
at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:84)
at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:86)
at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:118)
at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:158)
at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:92)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1253)
2021-03-31 07:38:28,197 INFO shutdown called (org.apache.zookeeper.server.quorum.Learner) [QuorumPeermyid=2(secure=0.0.0.0:2181)]
java.lang.Exception: shutdown Follower
at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:201)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1257)
2021-03-31 07:38:28,197 INFO Shutting down (org.apache.zookeeper.server.ZooKeeperServer) [QuorumPeermyid=2(secure=0.0.0.0:2181)]
2021-03-31 07:38:28,197 INFO shutting down (org.apache.zookeeper.server.ZooKeeperServer) [QuorumPeermyid=2(secure=0.0.0.0:2181)]
2021-03-31 07:38:28,197 INFO Shutting down (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) [QuorumPeermyid=2(secure=0.0.0.0:2181)]
2021-03-31 07:38:28,197 INFO Shutting down (org.apache.zookeeper.server.quorum.CommitProcessor) [QuorumPeermyid=2(secure=0.0.0.0:2181)]
2021-03-31 07:38:28,197 INFO FollowerRequestProcessor exited loop! (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) [FollowerRequestProcessor:2]
2021-03-31 07:38:28,198 INFO CommitProcessor exited loop! (org.apache.zookeeper.server.quorum.CommitProcessor) [CommitProcessor:2]
2021-03-31 07:38:28,201 INFO shutdown of request processor complete (org.apache.zookeeper.server.FinalRequestProcessor) [QuorumPeermyid=2(secure=0.0.0.0:2181)]
2021-03-31 07:38:28,368 INFO Processing ruok command from /127.0.0.1:53604 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-2]

@derekadams derekadams self-assigned this Apr 1, 2021
@derekadams derekadams added the task/investigate Investigate a potential new feature/technology label Apr 1, 2021
@derekadams derekadams added this to the 3.0 Backlog milestone Apr 1, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
task/investigate Investigate a potential new feature/technology
Projects
None yet
Development

No branches or pull requests

2 participants