i started using v0.9.1 and keep running into these...
# troubleshooting
p
i started using v0.9.1 and keep running into these errors every couple of hours
Copy code
2021/12/15 19:09:59.854 ERROR [GroupCommit] [HelixTaskExecutor-message_handle_STATE_TRANSITION] Interrupted while committing change, key: /pinot-poc/INSTANCES/Server_10.220.12.85_8098/CURRENTSTATES/100000abfb404c3/km_mp_play_startree_REALTIME, record: km_mp_play_startree_REALTIME, {}{}{}
java.lang.InterruptedException: null
        at java.lang.Object.wait(Native Method) ~[?:?]
        at org.apache.helix.GroupCommit.commit(GroupCommit.java:163) [pinot-all-0.9.1-jar-with-dependencies.jar:0.9.1-f8ec6f6f8eead03488d3f4d0b9501fc3c4232961]
        at org.apache.helix.manager.zk.ZKHelixDataAccessor.updateProperty(ZKHelixDataAccessor.java:189) [pinot-all-0.9.1-jar-with-dependencies.jar:0.9.1-f8ec6f6f8eead03488d3f4d0b9501fc3c4232961]
        at org.apache.helix.manager.zk.ZKHelixDataAccessor.updateProperty(ZKHelixDataAccessor.java:177) [pinot-all-0.9.1-jar-with-dependencies.jar:0.9.1-f8ec6f6f8eead03488d3f4d0b9501fc3c4232961]
        at org.apache.helix.messaging.handling.HelixStateTransitionHandler.preHandleMessage(HelixStateTransitionHandler.java:164) [pinot-all-0.9.1-jar-with-dependencies.jar:0.9.1-f8ec6f6f8eead03488d3f4d0b9501fc3c4232961]
        at org.apache.helix.messaging.handling.HelixStateTransitionHandler.handleMessage(HelixStateTransitionHandler.java:330) [pinot-all-0.9.1-jar-with-dependencies.jar:0.9.1-f8ec6f6f8eead03488d3f4d0b9501fc3c4232961]
        at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:97) [pinot-all-0.9.1-jar-with-dependencies.jar:0.9.1-f8ec6f6f8eead03488d3f4d0b9501fc3c4232961]
        at org.apache.helix.messaging.handling.HelixTask.call(HelixTask.java:49) [pinot-all-0.9.1-jar-with-dependencies.jar:0.9.1-f8ec6f6f8eead03488d3f4d0b9501fc3c4232961]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]
m
What version were you running before? Is there GC on the servers?
p
0.9.0
m
Was the issue there as well? The only difference is log4j patch, so it shouldn't cause this issue. Can you check GC on servers?
p
yeah i am looking for that. don't have monitoring set up yet. if it helps, i have a table set up with no index. we were trying to see how much disc we end up using for retaining one day of data without any index so we can estimate with replication+index etc
i didn't try table without any index on 0.9.0 so can't really say yes definitively. but definitely didn't run into this specific issue so far for a table with a star-tree index on 0.9.0.
actually discovered logs folder....zk logs is filled with
Copy code
2021/12/15 21:47:51.196 INFO [ZooKeeperServer] [NIOWorkerThread-5] Invalid session 0x100000abfb40554 for client /10.220.15.7:33698, probably expired
2021/12/15 21:48:10.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb4055a, timeout of 30000ms exceeded
2021/12/15 21:48:22.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb4055b, timeout of 30000ms exceeded
2021/12/15 21:49:14.823 INFO [ZooKeeperServer] [NIOWorkerThread-5] Invalid session 0x100000abfb40559 for client /10.220.12.85:41466, probably expired
2021/12/15 21:49:45.753 INFO [ZooKeeperServer] [NIOWorkerThread-6] Invalid session 0x100000abfb40555 for client /10.220.0.43:58214, probably expired
2021/12/15 21:49:46.494 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb4055c, timeout of 30000ms exceeded
2021/12/15 21:49:54.268 INFO [ZooKeeperServer] [NIOWorkerThread-7] Invalid session 0x100000abfb40556 for client /10.220.9.120:53038, probably expired
2021/12/15 21:50:16.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb4055d, timeout of 30000ms exceeded
2021/12/15 21:50:23.882 INFO [ZooKeeperServer] [NIOWorkerThread-6] Invalid session 0x100000abfb40558 for client /10.220.15.16:51170, probably expired
2021/12/15 21:50:25.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb4055e, timeout of 30000ms exceeded
2021/12/15 21:50:30.365 INFO [ZooKeeperServer] [NIOWorkerThread-8] Invalid session 0x100000abfb4055b for client /10.220.15.7:33774, probably expired
2021/12/15 21:50:55.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb4055f, timeout of 30000ms exceeded
2021/12/15 21:50:56.354 INFO [ZooKeeperServer] [NIOWorkerThread-8] Invalid session 0x100000abfb4055a for client /10.220.3.107:33700, probably expired
2021/12/15 21:51:01.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb40560, timeout of 30000ms exceeded
2021/12/15 21:51:06.434 INFO [ZooKeeperServer] [NIOWorkerThread-4] Invalid session 0x100000abfb4055d for client /10.220.0.43:58262, probably expired
2021/12/15 21:51:28.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb40561, timeout of 30000ms exceeded
2021/12/15 21:51:37.493 INFO [ZooKeeperServer] [SessionTracker] Expiring session 0x100000abfb40562, timeout of 30000ms exceeded
                                                                                                                   2635,1        94%
[bagi] 0:pbagrecha@pinot-startree-zookeeper-dev-1001:~/apache-pinot-0.9.1-bin*               "pinot-startree-zookeep" 23:20 15-Dec-21
m
Was ZK killed/restarted, and you don't have ZK with HA? If so, it could explain that the zk clients from old session are unable to connect to the new ZK server.
p
zk wasn't killed or restarted. i am going to do clean up all the nodes, and restart all processes, and enable gc logging on servers. hopefully either it'll fix it or provide an insight into why.
seeing
Copy code
[2311.462s][warning][gc,alloc] km_mp_play_startree__100__3__20211216T0216Z: Retried waiting for GCLocker too often allocating 1048579 words
Exception in thread "km_mp_play_startree__100__3__20211216T0216Z" java.lang.OutOfMemoryError: Java heap space
        at it.unimi.dsi.fastutil.ints.Int2IntOpenHashMap.<init>(Int2IntOpenHashMap.java:105)
        at it.unimi.dsi.fastutil.ints.Int2IntOpenHashMap.<init>(Int2IntOpenHashMap.java:114)
        at org.apache.pinot.segment.local.segment.creator.impl.SegmentDictionaryCreator.build(SegmentDictionaryCreator.java:85)
        at org.apache.pinot.segment.local.segment.creator.impl.SegmentColumnarIndexCreator.init(SegmentColumnarIndexCreator.java:197)
        at org.apache.pinot.segment.local.segment.creator.impl.SegmentIndexCreationDriverImpl.build(SegmentIndexCreationDriverImpl.java:209)
        at org.apache.pinot.segment.local.realtime.converter.RealtimeSegmentConverter.build(RealtimeSegmentConverter.java:131)
        at org.apache.pinot.core.data.manager.realtime.LLRealtimeSegmentDataManager.buildSegmentInternal(LLRealtimeSegmentDataManager.java:815)
        at org.apache.pinot.core.data.manager.realtime.LLRealtimeSegmentDataManager.buildSegmentForCommit(LLRealtimeSegmentDataManager.java:746)
        at org.apache.pinot.core.data.manager.realtime.LLRealtimeSegmentDataManager$PartitionConsumer.run(LLRealtimeSegmentDataManager.java:644)
        at java.base/java.lang.Thread.run(Thread.java:829)
on one of the data servers.
this is how i am running server
Copy code
export JAVA_OPTS="-Xms4G -Xmx16G -Xlog:gc=debug:file=/tmp/pinot-gc.log:time,uptime,level,tags:filecount=5,filesize=100m  -Dpinot.admin.system.exit=false -Dpinot.server.instance.realtime.alloc.offheap=true" 
bin/pinot-admin.sh StartServer -configFileName ~/server.conf -clusterName pinot-poc -zkAddress 10.220.14.42:2191
the only difference between before and now (other than 0.9.1 v/s 0.9.0 is that the table is not using any index.
the only reason i was using
-Xmx 16G
because i read somewhere on docs (i can't find it now) that you guys were able to run cluster in linkedin using that....now that i read this thread i guess i should just use a bigger box 😐