Skip to content

Instantly share code, notes, and snippets.

Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save shanthoosh/55410fe4ebf3cfb65281b35f16397cad to your computer and use it in GitHub Desktop.
Save shanthoosh/55410fe4ebf3cfb65281b35f16397cad to your computer and use it in GitHub Desktop.
Sample exception logs.
--- Shutdown of current leader. Leader joins the group as follower.
1074 00:26:10.274 [DEBUG] [TestEventLogger] 122723 [ZkClient-EventThread-585-127.0.0.1:54727] WARN org.apache.samza.zk.ZkJobCoordinator - Got Disconnected event for processor=2. Scheduling a coordinator stop.
1075 00:26:10.275 [DEBUG] [TestEventLogger] 122724 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: ZK_SESSION_ERROR to run after: 500 milliseconds.
1076 00:26:10.275 [DEBUG] [TestEventLogger] 122724 [ZkClient-EventThread-585-127.0.0.1:54727] WARN org.apache.samza.zk.ZkJobCoordinator - Got Expired event for processor=2. Stopping the container and unregister the processor node.
1077 00:26:10.276 [DEBUG] [TestEventLogger] 122724 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.processor.StreamProcessor - Shutting down container in onJobModelExpired for processor:2
1078 00:26:10.276 [DEBUG] [TestEventLogger] 122724 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down.
1079 00:26:10.277 [DEBUG] [TestEventLogger] 122726 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down consumer multiplexer.
1080 00:26:10.277 [DEBUG] [TestEventLogger] 122726 [p-2-container-thread-0] INFO org.apache.samza.system.kafka.BrokerProxy - Shutting down BrokerProxy for localhost:54730
1081 00:26:10.278 [DEBUG] [TestEventLogger] 122726 [p-2-container-thread-0] INFO org.apache.samza.system.kafka.BrokerProxy - closing simple consumer...
1082 00:26:10.289 [DEBUG] [TestEventLogger] 122735 [Samza BrokerProxy BrokerProxy thread pointed at localhost:54730 for client samza_consumer-test_job-1] INFO org.apache.samza.system.kafka.BrokerProxy - Shutting down due to interrupt.
1083 00:26:10.289 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down task instance stream tasks.
1084 00:26:10.290 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down timer executor
1085 00:26:10.290 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Committing offsets for all task instances
1086 00:26:10.290 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down task instance table manager.
1087 00:26:10.290 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down task instance stores.
1088 00:26:10.291 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down host statistics monitor.
1089 00:26:10.291 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down producer multiplexer.
1090 00:26:10.291 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.samza.system.kafka.KafkaSystemProducer - Stopping producer for system: test_ZKS_test-system1
1091 00:26:10.291 [DEBUG] [TestEventLogger] 122736 [p-2-container-thread-0] INFO org.apache.kafka.clients.producer.KafkaProducer - Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms.
1092 00:26:10.292 [DEBUG] [TestEventLogger] 122739 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down offset manager.
1093 00:26:10.292 [DEBUG] [TestEventLogger] 122739 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down metrics reporters.
1094 00:26:10.292 [DEBUG] [TestEventLogger] 122739 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down JVM metrics.
1095 00:26:10.292 [DEBUG] [TestEventLogger] 122739 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutting down admin multiplexer.
1096 00:26:10.293 [DEBUG] [TestEventLogger] 122739 [p-2-container-thread-0] INFO org.apache.samza.container.SamzaContainer - Shutdown complete.
1097 00:26:10.293 [DEBUG] [TestEventLogger] 122739 [p-2-container-thread-0] INFO org.apache.samza.processor.StreamProcessor - Container org.apache.samza.container.SamzaContainer@486e9741 stopped due to a request from JobCoordinator.
1098 00:26:10.293 [DEBUG] [TestEventLogger] 122740 [Test worker] INFO org.apache.samza.processor.TestZkStreamProcessorBase - Waiting on java.util.concurrent.CountDownLatch@70bb8508[Count = 1]
1099 00:26:10.293 [DEBUG] [TestEventLogger] 122740 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.processor.StreamProcessor - ShutdownComplete=true
1100 00:26:10.294 [DEBUG] [TestEventLogger] 122740 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.processor.StreamProcessor - Shutting down container done for pid=2; complete =true
1101 00:26:10.294 [DEBUG] [TestEventLogger] 122740 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkJobCoordinator - Got new session created event for processor=2
1102 00:26:10.294 [DEBUG] [TestEventLogger] 122740 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkJobCoordinator - register zk controller for the new session
1103 00:26:10.294 [DEBUG] [TestEventLogger] 122742 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkUtils - Created ephemeral path: /app-test-job-1/test-job-1-coordinationData/processors/0000000002 for processor: svenkata-mn1.linkedin.biz 2 in zookeeper.
1104 00:26:10.295 [DEBUG] [TestEventLogger] 122742 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkUtils - Found these children - [0000000001, 0000000002]
1105 00:26:10.295 [DEBUG] [TestEventLogger] 122742 [ZkClient-EventThread-588-127.0.0.1:54727] WARN org.apache.samza.zk.ZkUtils - ALLOWING handleDataChanged for ProcessorChangeHandler from wrong generation. current generation=0; callback generation= 0
1106 00:26:10.295 [DEBUG] [TestEventLogger] 122742 [ZkClient-EventThread-588-127.0.0.1:54727] INFO org.apache.samza.zk.ZkControllerImpl - ZkControllerImpl::ProcessorChangeHandler::handleChildChange - Path: /app-test-job-1/test-job-1-coordinationData/processors Current Children: [0000000001, 0000000002]
1107 00:26:10.295 [DEBUG] [TestEventLogger] 122743 [ZkClient-EventThread-588-127.0.0.1:54727] INFO org.apache.samza.zk.ZkJobCoordinator - ZkJobCoordinator::onProcessorChange - list of processors changed! List size=2
1108 00:26:10.295 [DEBUG] [TestEventLogger] 122743 [ZkClient-EventThread-588-127.0.0.1:54727] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Attempting to cancel the future of action: OnProcessorChange
1109 00:26:10.296 [DEBUG] [TestEventLogger] 122743 [ZkClient-EventThread-588-127.0.0.1:54727] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: OnProcessorChange to run after: 3000 milliseconds.
1110 00:26:10.297 [DEBUG] [TestEventLogger] 122743 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkUtils - Found these children - [0000000001, 0000000002]
1111 00:26:10.298 [DEBUG] [TestEventLogger] 122743 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkLeaderElector - tryBecomeLeader: index = 1 for path=/app-test-job-1/test-job-1-coordinationData/processors/0000000002 out of [0000000001, 0000000002]
1112 00:26:10.300 [DEBUG] [TestEventLogger] 122743 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkLeaderElector - Index = 1 Not eligible to be a leader yet!
1113 00:26:10.303 [DEBUG] [TestEventLogger] 122743 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkLeaderElector - [Processor-2] Subscribing data change for 0000000001
--- Follower becomes leader.
1126 00:26:13.278 [DEBUG] [TestEventLogger] 125726 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - read the model ver=1 from /app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModels/1
1127 00:26:13.302 [DEBUG] [TestEventLogger] 125746 [debounce-thread-0] INFO org.apache.samza.coordinator.JobModelManager$ - SystemStreamPartitionGrouper org.apache.samza.container.grouper.stream.GroupByPartition@7f124766 has grouped the SystemStreamPartitions into 5 tasks with the following taskNames: [Partitio n 1, Partition 0, Partition 3, Partition 2, Partition 4]
1128 00:26:13.302 [DEBUG] [TestEventLogger] 125748 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - Found these children - [0000000001, 0000000002]
1129 00:26:13.303 [DEBUG] [TestEventLogger] 125748 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - Found these processorIds - [2, 3]
1130 00:26:13.303 [DEBUG] [TestEventLogger] 125748 [debounce-thread-0] INFO org.apache.samza.zk.ZkJobCoordinator - Generating new JobModel with processors: [2, 3].
1131 00:26:13.311 [DEBUG] [TestEventLogger] 125749 [debounce-thread-0] INFO org.apache.samza.zk.ZkJobCoordinator - pid=2Generated new JobModel with version: 2 and processors: [3]
1132 00:26:13.323 [DEBUG] [TestEventLogger] 125766 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - read the model ver=1 from /app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModels/1
--- Old leader acts upon stale events in it's debounce queue and generates new JobModel.
1223 00:26:13.347 [DEBUG] [TestEventLogger] 125784 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - wrote jobModel path =/app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModels/2
1224 00:26:13.357 [DEBUG] [TestEventLogger] 125800 [debounce-thread-0] INFO org.apache.samza.coordinator.JobModelManager$ - SystemStreamPartitionGrouper org.apache.samza.container.grouper.stream.GroupByPartition@363633c6 has grouped the SystemStreamPartitions into 5 tasks with the following taskNames: [Partitio n 1, Partition 0, Partition 3, Partition 2, Partition 4]
1225 00:26:13.359 [DEBUG] [TestEventLogger] 125808 [debounce-thread-0] INFO org.apache.samza.zk.ZkJobCoordinator - pid=3Generated new JobModel with version: 3 and processors: [2, 3]
1226 00:26:13.375 [DEBUG] [TestEventLogger] 125810 [debounce-thread-0] INFO org.apache.samza.zk.ZkBarrierForVersionUpgrade - Subscribing for child changes at /app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModelUpgradeBarrier/versionBarriers/barrier_2/barrier_participants
1227 00:26:13.378 [DEBUG] [TestEventLogger] 125811 [debounce-thread-0] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: BarrierAction to run after: 2000 milliseconds.
1228 00:26:13.382 [DEBUG] [TestEventLogger] 125812 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - publishing new version: 2; oldVersion = 1(1)
1229 00:26:13.383 [DEBUG] [TestEventLogger] 125812 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - published new version: 2; expected data version = 2(actual data version after update = 2)
1230 00:26:13.385 [DEBUG] [TestEventLogger] 125812 [debounce-thread-0] INFO org.apache.samza.zk.ZkJobCoordinator - pid=2Published new Job Model. Version = 2
1231 00:26:13.386 [DEBUG] [TestEventLogger] 125813 [debounce-thread-0] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: OnCleanUp to run after: 0 milliseconds.
-- Old leader goes first and publishes the JobModel.
1231 00:26:13.386 [DEBUG] [TestEventLogger] 125813 [debounce-thread-0] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: OnCleanUp to run after: 0 milliseconds.
1232 00:26:13.386 [DEBUG] [TestEventLogger] 125813 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - about to delete old barrier paths from /app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModelUpgradeBarrier/versionBarriers
1233 00:26:13.387 [DEBUG] [TestEventLogger] 125813 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - List of all zkNodes: [barrier_2, barrier_1]
1234 00:26:13.387 [DEBUG] [TestEventLogger] 125814 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - about to delete jm path=/app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModels
1235 00:26:13.387 [DEBUG] [TestEventLogger] 125815 [ZkClient-EventThread-585-127.0.0.1:54727] WARN org.apache.samza.zk.ZkUtils - SKIPPING handleDataChanged for ZkJobModelVersionChangeHandler from wrong generation. curGen=1; cb gen= 0
1236 00:26:13.387 [DEBUG] [TestEventLogger] 125815 [ZkClient-EventThread-588-127.0.0.1:54727] WARN org.apache.samza.zk.ZkUtils - ALLOWING handleDataChanged for ZkJobModelVersionChangeHandler from wrong generation. current generation=0; callback generation= 0
1237 00:26:13.388 [DEBUG] [TestEventLogger] 125815 [ZkClient-EventThread-588-127.0.0.1:54727] INFO org.apache.samza.zk.ZkControllerImpl - pid=3. Got notification on version update change. path=/app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModelVersion; data=2
1238 00:26:13.388 [DEBUG] [TestEventLogger] 125815 [ZkClient-EventThread-588-127.0.0.1:54727] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: JobModelVersionChange to run after: 0 milliseconds.
1239 00:26:13.388 [DEBUG] [TestEventLogger] 125815 [ZkClient-EventThread-585-127.0.0.1:54727] WARN org.apache.samza.zk.ZkUtils - ALLOWING handleDataChanged for ZkJobModelVersionChangeHandler from wrong generation. current generation=1; callback generation= 1
1240 00:26:13.389 [DEBUG] [TestEventLogger] 125815 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ZkControllerImpl - pid=2. Got notification on version update change. path=/app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModelVersion; data=2
1241 00:26:13.390 [DEBUG] [TestEventLogger] 125815 [ZkClient-EventThread-585-127.0.0.1:54727] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: JobModelVersionChange to run after: 0 milliseconds.
1242 00:26:13.390 [DEBUG] [TestEventLogger] 125815 [debounce-thread-0] INFO org.apache.samza.zk.ZkJobCoordinator - pid=2: new JobModel available
1243 00:26:13.391 [DEBUG] [TestEventLogger] 125816 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - read the model ver=2 from /app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModels/2
--- New leader fails when it tries to publish.
1356 00:26:13.416 [DEBUG] [TestEventLogger] 125828 [ZkClient-EventThread-588-127.0.0.1:54727] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: OnProcessorChange to run after: 3000 milliseconds.
1357 00:26:13.416 [DEBUG] [TestEventLogger] 125831 [debounce-thread-0] INFO org.apache.samza.zk.ZkBarrierForVersionUpgrade - Subscribing for child changes at /app-test-job-1/test-job-1-coordinationData/JobModelGeneration/jobModelUpgradeBarrier/versionBarriers/barrier_3/barrier_participants
1358 00:26:13.417 [DEBUG] [TestEventLogger] 125832 [debounce-thread-0] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Scheduled action: BarrierAction to run after: 2000 milliseconds.
1359 00:26:13.417 [DEBUG] [TestEventLogger] 125833 [debounce-thread-0] INFO org.apache.samza.zk.ZkUtils - publishing new version: 3; oldVersion = 1(2)
1360 00:26:13.417 [DEBUG] [TestEventLogger] 125833 [debounce-thread-0] ERROR org.apache.samza.zk.ScheduleAfterDebounceTime - Execution of action: OnProcessorChange failed.
1361 00:26:13.417 [DEBUG] [TestEventLogger] org.apache.samza.SamzaException: Someone changed JobModelVersion while the leader was generating one: expected1, got 2
1362 00:26:13.417 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ZkUtils.publishJobModelVersion(ZkUtils.java:465)
1363 00:26:13.417 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ZkJobCoordinator.doOnProcessorChange(ZkJobCoordinator.java:267)
1364 00:26:13.418 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ZkJobCoordinator.lambda$onProcessorChange$1(ZkJobCoordinator.java:225)
1365 00:26:13.418 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ScheduleAfterDebounceTime.lambda$getScheduleableAction$0(ScheduleAfterDebounceTime.java:153)
1366 00:26:13.418 [DEBUG] [TestEventLogger] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
1367 00:26:13.418 [DEBUG] [TestEventLogger] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
1368 00:26:13.418 [DEBUG] [TestEventLogger] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
1369 00:26:13.418 [DEBUG] [TestEventLogger] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
1370 00:26:13.419 [DEBUG] [TestEventLogger] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
1371 00:26:13.419 [DEBUG] [TestEventLogger] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
1372 00:26:13.419 [DEBUG] [TestEventLogger] at java.lang.Thread.run(Thread.java:748)
1373 00:26:13.419 [DEBUG] [TestEventLogger] 125833 [debounce-thread-0] INFO org.apache.samza.zk.ScheduleAfterDebounceTime - Shutting down debounce timer!
1374 00:26:13.419 [DEBUG] [TestEventLogger] 125833 [debounce-thread-0] ERROR org.apache.samza.zk.ZkJobCoordinator - Received exception in debounce timer! Stopping the job coordinator
1375 00:26:13.420 [DEBUG] [TestEventLogger] org.apache.samza.SamzaException: Someone changed JobModelVersion while the leader was generating one: expected1, got 2
1376 00:26:13.420 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ZkUtils.publishJobModelVersion(ZkUtils.java:465)
1377 00:26:13.420 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ZkJobCoordinator.doOnProcessorChange(ZkJobCoordinator.java:267)
1378 00:26:13.420 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ZkJobCoordinator.lambda$onProcessorChange$1(ZkJobCoordinator.java:225)
1379 00:26:13.420 [DEBUG] [TestEventLogger] at org.apache.samza.zk.ScheduleAfterDebounceTime.lambda$getScheduleableAction$0(ScheduleAfterDebounceTime.java:153)
1380 00:26:13.420 [DEBUG] [TestEventLogger] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
1381 00:26:13.421 [DEBUG] [TestEventLogger] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
1382 00:26:13.421 [DEBUG] [TestEventLogger] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
1383 00:26:13.421 [DEBUG] [TestEventLogger] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
1384 00:26:13.422 [DEBUG] [TestEventLogger] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
1385 00:26:13.422 [DEBUG] [TestEventLogger] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
1386 00:26:13.422 [DEBUG] [TestEventLogger] at java.lang.Thread.run(Thread.java:748)
1387 00:26:13.422 [DEBUG] [TestEventLogger] 125834 [debounce-thread-0] INFO org.apache.samza.zk.ZkJobCoordinator - Shutting down Job Coordinator...
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment