https://pinot.apache.org/ logo
Join Slack
Powered by
hello my friends it’s me again, does anyone know w...
# troubleshooting
l
hello my friends it’s me again, does anyone know what would be the reason of zookeeper crashing while we are ingesting data with the job yaml? we are running some migrations and it seems like zookeeper is just keeping on being sad crashing a lot, also what’s your recommended sizing for zookeeper, we are just using the default in the helm chart we may be hitting some roof
m
Too many segments (tens of thousands or more)?
l
i see 2k segments after the migration was done but at the end is def more than that
how can i tell?
m
Pinot UI should show
2k is small
l
the thing is that i don’t know if all the segments that were supposed to be migrated were migrated
we have a 512mb with 256 heap zk
3 replicas
m
@Daniel Lavoie any comments
d
What is the crash error?
l
i’m trying to find that out 😄
image.png
d
kubectl logs pinot-zookeeper-1 --previous
l
Copy code
2022-05-12 10:15:32,603 [myid:2] - INFO  [WorkerSender[myid=2]:QuorumCnxManager@430] - Have smaller server identifier, so dropping the connection: (3, 2)
2022-05-12 10:15:32,604 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:32,614 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:32,615 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:32,816 [myid:2] - INFO  [QuorumPeer[myid=2](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@919] - Notification time out: 400
2022-05-12 10:15:32,816 [myid:2] - INFO  [WorkerSender[myid=2]:QuorumCnxManager@430] - Have smaller server identifier, so dropping the connection: (3, 2)
2022-05-12 10:15:32,817 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:32,817 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:33,217 [myid:2] - INFO  [QuorumPeer[myid=2](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@919] - Notification time out: 800
2022-05-12 10:15:33,221 [myid:2] - INFO  [WorkerSender[myid=2]:QuorumCnxManager@430] - Have smaller server identifier, so dropping the connection: (3, 2)
2022-05-12 10:15:33,221 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:33,221 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:34,022 [myid:2] - INFO  [QuorumPeer[myid=2](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@919] - Notification time out: 1600
2022-05-12 10:15:34,023 [myid:2] - INFO  [WorkerSender[myid=2]:QuorumCnxManager@430] - Have smaller server identifier, so dropping the connection: (3, 2)
2022-05-12 10:15:34,023 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:34,023 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:35,624 [myid:2] - INFO  [QuorumPeer[myid=2](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@919] - Notification time out: 3200
2022-05-12 10:15:35,624 [myid:2] - INFO  [WorkerSender[myid=2]:QuorumCnxManager@430] - Have smaller server identifier, so dropping the connection: (3, 2)
2022-05-12 10:15:35,624 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:35,625 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:38,825 [myid:2] - INFO  [QuorumPeer[myid=2](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@919] - Notification time out: 6400
2022-05-12 10:15:38,826 [myid:2] - INFO  [WorkerSender[myid=2]:QuorumCnxManager@430] - Have smaller server identifier, so dropping the connection: (3, 2)
2022-05-12 10:15:38,826 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:38,826 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:45,227 [myid:2] - INFO  [QuorumPeer[myid=2](plain=/0.0.0.0:2181)(secure=disabled):FastLeaderElection@919] - Notification time out: 12800
2022-05-12 10:15:45,228 [myid:2] - INFO  [WorkerSender[myid=2]:QuorumCnxManager@430] - Have smaller server identifier, so dropping the connection: (3, 2)
2022-05-12 10:15:45,228 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:45,233 [myid:2] - INFO  [WorkerReceiver[myid=2]:FastLeaderElection@679] - Notification: 2 (message format version), 3 (n.leader), 0x110001d0cf (n.zxid), 0x6 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x12 (n.peerEPoch), LOOKING (my state)0 (n.config version)
2022-05-12 10:15:56,491 [myid:2] - INFO  [NIOWorkerThread-1:FourLetterCommands@234] - The list of known four letter word commands is : [{1936881266=srvr, 1937006964=stat, 2003003491=wchc, 1685417328=dump, 1668445044=crst, 1936880500=srst, 1701738089=envi, 1668247142=conf, -720899=telnet close, 2003003507=wchs, 2003003504=wchp, 1684632179=dirs, 1668247155=cons, 1835955314=mntr, 1769173615=isro, 1920298859=ruok, 1735683435=gtmk, 1937010027=stmk}]
2022-05-12 10:15:56,491 [myid:2] - INFO  [NIOWorkerThread-1:FourLetterCommands@235] - The list of enabled four letter word commands is : [[wchs, stat, wchp, dirs, stmk, conf, ruok, mntr, srvr, wchc, envi, srst, isro, dump, gtmk, telnet close, crst, cons]]
2022-05-12 10:15:56,491 [myid:2] - INFO  [NIOWorkerThread-1:NIOServerCnxn@518] - Processing ruok command from /127.0.0.1:56218
2022-05-12 10:15:57,298 [myid:2] - INFO  [NIOWorkerThread-2:NIOServerCnxn@518] - Processing srvr command from /127.0.0.1:56224
d
I see no shutdown command.
kubectl describe pod pinot-zookeeper-1
Should give an exit status for previous container
l
Copy code
Last State:     Terminated
      Reason:       Error
      Exit Code:    143
d
We get this error when the liveness probe stops returning exit code 0
m
Perhaps too low heap is a potential issue here?
d
For 2K segments, that’s a a reasonable assumption
But I would expect some OOM Killed or JVM OOM stacktrace
l
ops people did tell me that those pods seem to be using mostly of the memory available
d
Do you have any trace of a OOMKilled in the pod describe output?
l
like w this one? 
kubectl describe pod pinot-zookeeper-1
d
yes
kubectl describe pod pinot-zookeeper-1 | grep OOM
l
nada
d
Ok, then maybe ZK gracefully reports error status on mntr command when memory is running out. So, I would recommend bumping memory
l
this is our config
Copy code
resources: {
            requests: {
              cpu: '500m',
              memory: '1Gi',
            },
            limits: {
              cpu: '500m',
              memory: '1Gi',
            },
          },
Copy code
ZK_HEAP_SIZE: '256M',
d
I would 2x or 4x all of these values
l
AHA
Copy code
2022-05-06 15:55:56,927 [myid:3] - WARN  [LearnerHandler-/10.24.10.144:59094:LearnerHandler@928] - Ignoring unexpected exception
java.lang.InterruptedException
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
	at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:339)
	at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:926)
	at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647)
2022-05-06 15:55:56,927 [myid:3] - WARN  [QuorumPeer[myid=3](plain=/0.0.0.0:2181)(secure=disabled):ZooKeeperThread@55] - Exception occurred from thread QuorumPeer[myid=3](plain=/0.0.0.0:2181)(secure=disabled)
java.lang.OutOfMemoryError: Java heap space
2022-05-06 15:55:56,927 [myid:3] - WARN  [LearnerHandler-/10.24.7.181:38132:LearnerHandler@928] - Ignoring unexpected exception
java.lang.InterruptedException
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
	at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:339)
	at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:926)
	at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647)
2022-05-06 15:55:56,928 [myid:3] - INFO  [main:QuorumPeerMain@104] - Exiting normally
in 
pinot-zookeeper-2
d
there you go 🙂 Smoking gun
l
cpu also you recommend 2x or 4x?
d
2x is going to be fine, but my recommendation would be to instrument and measure resource usage
and adjust
l
🙏 will do so
now, in terms of the job spec yaml, if zookeeper dies what are the implications for the job
i do see a lot of exceptions in the controller where we ran the job
d
@Mayank ^^
l
and i imagine that zookeeper dying would just take all the controllers to a sad state and then mess up with the import
m
Yes, exceptions are probably effect rather than cause
l
yea, so we have beefed up those machines
also another question, is there anything we have to do to the helm config in order for us to get grafana metrics for zk?
d
Yeah current helm chart is broken
l
it seems like that future is also recent https://zookeeper.apache.org/doc/r3.6.3/zookeeperMonitor.html
d
latest ZK embedds a prometheus
We implemented it in our Cloud operator. You only meed to add a ZK properties. Chart needs that default properties and the removal of the side car containers
If you are interested in contributing to the project, that’s a nice one to look at.
f
@Yasir Khatri
Open in Slack
PreviousNext
Powered by