[ https://issues.apache.org/jira/browse/KAFKA-4669?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16271906#comment-16271906 ]
aarti gupta commented on KAFKA-4669: ------------------------------------ unfortunately we did not have trace enabled and did not enable it when we encountered the problem Here is a scrubbed larger segment of the consumer log, in case it helps 2017-11-29 21:22:37.841 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:37.841 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:37.841 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Unable to reconnect to ZooKeeper service, session 0x15fcbdb62647c08 has expired 2017-11-29 21:22:37.841 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to reconnect to ZooKeeper service, session 0x15fcbdb62647c08 has expired, closing socket connection 2017-11-29 21:22:37.842 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386007) does not match request (386006), request header: {api_key=9,api_version=3,correlation_id=386006,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:37.842 UTC [main-EventThread, , ] INFO c.v.v.h.c.s.ConfigurableRunnableListener- Got a closing request- znode: /NetworkStretchService 2017-11-29 21:22:37.842 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ZooKeeper- Initiating client connection, connectString=localhost:2181 sessionTimeout=3000 watcher=org.apache.curator.ConnectionState@9eaa0a5 2017-11-29 21:22:37.842 UTC [main-EventThread, , ] WARN org.apache.curator.ConnectionState- Session expired event received 2017-11-29 21:22:37.842 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ZooKeeper- Initiating client connection, connectString=localhost:2181 sessionTimeout=3000 watcher=org.apache.curator.ConnectionState@50128862 2017-11-29 21:22:37.846 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647c05 2017-11-29 21:22:37.846 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386008) does not match request (386007), request header: {api_key=9,api_version=3,correlation_id=386007,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.700 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647c08 2017-11-29 21:22:40.700 UTC [RemotingService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (384729) does not match request (384728), request header: {api_key=9,api_version=3,correlation_id=384728,client_id=consumer-36} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.701 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386009) does not match request (386008), request header: {api_key=9,api_version=3,correlation_id=386008,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.702 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:40.702 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:40.704 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386010) does not match request (386009), request header: {api_key=9,api_version=3,correlation_id=386009,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.704 UTC [RemotingService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (384730) does not match request (384729), request header: {api_key=9,api_version=3,correlation_id=384729,client_id=consumer-36} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.705 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386011) does not match request (386010), request header: {api_key=9,api_version=3,correlation_id=386010,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.705 UTC [RemotingService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (384731) does not match request (384730), request header: {api_key=9,api_version=3,correlation_id=384730,client_id=consumer-36} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.705 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Session establishment complete on server wdc04-dta-1-hcx-a/127.0.0.1:2181, sessionid = 0x15fcbdb62647c1e, negotiated timeout = 4000 2017-11-29 21:22:40.705 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386012) does not match request (386011), request header: {api_key=9,api_version=3,correlation_id=386011,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.706 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386013) does not match request (386012), request header: {api_key=9,api_version=3,correlation_id=386012,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.707 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386014) does not match request (386013), request header: {api_key=9,api_version=3,correlation_id=386013,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:40.708 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647c09 2017-11-29 21:22:34.471 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 11660ms for sessionid 0x0 2017-11-29 21:22:44.226 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c0c, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.226 UTC [main-EventThread, , ] WARN org.apache.curator.ConnectionState- Session expired event received 2017-11-29 21:22:44.226 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c0f, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.226 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ZooKeeper- Initiating client connection, connectString=localhost:2181 sessionTimeout=3000 watcher=org.apache.curator.ConnectionState@268a8a24 2017-11-29 21:22:44.227 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c10, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.227 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c13, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.227 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c17, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.227 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c15, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.227 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c14, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.228 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c16, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.228 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647bfe 2017-11-29 21:22:44.228 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c19, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.228 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c1a, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.228 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to read additional data from server sessionid 0x15fcbdb62647c1b, likely server has closed socket, closing socket connection and attempting reconnect 2017-11-29 21:22:44.229 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:44.229 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:44.232 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6391ms for sessionid 0x0 2017-11-29 21:22:44.232 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6391ms for sessionid 0x0, closing socket connection and attempting reconnect 2017-11-29 21:22:44.233 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6398ms for sessionid 0x0 2017-11-29 21:22:44.233 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6398ms for sessionid 0x0, closing socket connection and attempting reconnect 2017-11-29 21:22:44.234 UTC [main-EventThread, , ] INFO c.v.v.h.orchestration.Application- com.vmware.vchs.hybridity.orchestration.Application, com.vmware.vchs.hybridity.orchestration.Application , inside process(WatchedEvent) 2017-11-29 21:22:44.235 UTC [main-EventThread, , ] WARN c.v.v.h.container.DataMonitor- Got an event that is not handled:Disconnected 2017-11-29 21:22:44.235 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647be4 2017-11-29 21:22:44.235 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647bdc 2017-11-29 21:22:34.472 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:34.477 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ZooKeeper- Initiating client connection, connectString=localhost:2181 sessionTimeout=3000 watcher=org.apache.curator.ConnectionState@4f2aa529 2017-11-29 21:22:34.478 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:44.236 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Session establishment complete on server wdc04-dta-1-hcx-a/127.0.0.1:2181, sessionid = 0x15fcbdb62647c1f, negotiated timeout = 4000 2017-11-29 21:22:34.478 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:37.837 UTC [main-EventThread, , ] INFO c.v.v.h.c.s.ConfigurableRunnableListener- Got a closing request- znode: /VrealmUpgradeService 2017-11-29 21:22:37.839 UTC [main-EventThread, , ] WARN org.apache.curator.ConnectionState- Session expired event received 2017-11-29 21:22:47.640 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6935ms for sessionid 0x15fcbdb62647c1e 2017-11-29 21:22:47.641 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:47.643 UTC [RemotingService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (384732) does not match request (384731), request header: {api_key=9,api_version=3,correlation_id=384731,client_id=consumer-36} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:47.644 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386015) does not match request (386014), request header: {api_key=9,api_version=3,correlation_id=386014,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:47.645 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 11660ms for sessionid 0x0, closing socket connection and attempting reconnect 2017-11-29 21:22:47.646 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:47.647 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6935ms for sessionid 0x15fcbdb62647c1e, closing socket connection and attempting reconnect 2017-11-29 21:22:47.647 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ZooKeeper- Initiating client connection, connectString=localhost:2181 sessionTimeout=3000 watcher=org.apache.curator.ConnectionState@7245a579 2017-11-29 21:22:47.647 UTC [main-EventThread, , ] WARN org.apache.curator.ConnectionState- Session expired event received 2017-11-29 21:22:47.647 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ZooKeeper- Initiating client connection, connectString=localhost:2181 sessionTimeout=3000 watcher=org.apache.curator.ConnectionState@257de07c 2017-11-29 21:22:47.647 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 13169ms for sessionid 0x15fcbdb62647bdd 2017-11-29 21:22:47.647 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 13169ms for sessionid 0x15fcbdb62647bdd, closing socket connection and attempting reconnect 2017-11-29 21:22:47.647 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:47.647 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:47.647 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 13170ms for sessionid 0x15fcbdb62647bde 2017-11-29 21:22:47.647 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 13170ms for sessionid 0x15fcbdb62647bde, closing socket connection and attempting reconnect 2017-11-29 21:22:47.648 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 13176ms for sessionid 0x0 2017-11-29 21:22:47.648 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 13176ms for sessionid 0x0, closing socket connection and attempting reconnect 2017-11-29 21:22:47.649 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:47.649 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:47.651 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Session establishment complete on server wdc04-dta-1-hcx-a/127.0.0.1:2181, sessionid = 0x15fcbdb62647c21, negotiated timeout = 4000 2017-11-29 21:22:47.652 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Session establishment complete on server wdc04-dta-1-hcx-a/127.0.0.1:2181, sessionid = 0x15fcbdb62647c20, negotiated timeout = 4000 2017-11-29 21:22:47.652 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Session establishment complete on server wdc04-dta-1-hcx-a/127.0.0.1:2181, sessionid = 0x15fcbdb62647c23, negotiated timeout = 4000 2017-11-29 21:22:47.655 UTC [RemotingService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (384733) does not match request (384732), request header: {api_key=9,api_version=3,correlation_id=384732,client_id=consumer-36} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:47.655 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386016) does not match request (386015), request header: {api_key=9,api_version=3,correlation_id=386015,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:47.658 UTC [RemotingService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (384734) does not match request (384733), request header: {api_key=9,api_version=3,correlation_id=384733,client_id=consumer-36} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:47.659 UTC [VrealmUpgradeService_EventListener, , ] ERROR c.v.v.h.m.k.KafkaEventConsumerDelegate- Error fetching next record java.lang.Exception: Error fetching next new record from kafka queue at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:121) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEvent(KafkaEventConsumerDelegate.java:64) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEvent(EventListenerAdapter.java:76) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter.getNextEventAndAck(EventListenerAdapter.java:94) at com.vmware.vchs.hybridity.messaging.adapter.EventListenerAdapter$1.run(EventListenerAdapter.java:125) at java.lang.Thread.run(Thread.java:748) Caused by: java.lang.IllegalStateException: Correlation id for response (386017) does not match request (386016), request header: {api_key=9,api_version=3,correlation_id=386016,client_id=consumer-57} at org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:752) at org.apache.kafka.clients.NetworkClient.parseStructMaybeUpdateThrottleTimeMetrics(NetworkClient.java:561) at org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:657) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:442) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:232) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:208) at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:168) at org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.fetchCommittedOffsets(ConsumerCoordinator.java:477) at org.apache.kafka.clients.consumer.KafkaConsumer.committed(KafkaConsumer.java:1346) at com.vmware.vchs.hybridity.messaging.kafka.KafkaEventConsumerDelegate.getNextEventWithTimeout(KafkaEventConsumerDelegate.java:86) ... 5 common frames omitted 2017-11-29 21:22:47.659 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:47.660 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:47.661 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647c07 2017-11-29 21:22:47.666 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Session establishment complete on server wdc04-dta-1-hcx-a/127.0.0.1:2181, sessionid = 0x15fcbdb62647c24, negotiated timeout = 4000 2017-11-29 21:22:47.680 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647be2 2017-11-29 21:22:50.504 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6268ms for sessionid 0x15fcbdb62647c1f 2017-11-29 21:22:50.504 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2852ms for sessionid 0x15fcbdb62647c23 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 6268ms for sessionid 0x15fcbdb62647c1f, closing socket connection and attempting reconnect 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2852ms for sessionid 0x15fcbdb62647c23, closing socket connection and attempting reconnect 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2854ms for sessionid 0x15fcbdb62647c21 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2853ms for sessionid 0x15fcbdb62647c20 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2854ms for sessionid 0x15fcbdb62647c21, closing socket connection and attempting reconnect 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2853ms for sessionid 0x15fcbdb62647c20, closing socket connection and attempting reconnect 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2839ms for sessionid 0x15fcbdb62647c24 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.505 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Client session timed out, have not heard from server in 2839ms for sessionid 0x15fcbdb62647c24, closing socket connection and attempting reconnect 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.506 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.507 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.507 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.507 UTC [main-EventThread, , ] INFO org.apache.zookeeper.ClientCnxn- EventThread shut down for session: 0x15fcbdb62647c01 2017-11-29 21:22:50.507 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.507 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Unable to reconnect to ZooKeeper service, session 0x15fcbdb62647c0b has expired 2017-11-29 21:22:50.507 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Opening socket connection to server wdc04-dta-1-hcx-a/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) 2017-11-29 21:22:50.507 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Socket connection established to wdc04-dta-1-hcx-a/127.0.0.1:2181, initiating session 2017-11-29 21:22:50.507 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Unable to reconnect to ZooKeeper service, session 0x15fcbdb62647c03 has expired 2017-11-29 21:22:50.508 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to reconnect to ZooKeeper service, session 0x15fcbdb62647c03 has expired, closing socket connection 2017-11-29 21:22:50.508 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] WARN org.apache.zookeeper.ClientCnxn- Unable to reconnect to ZooKeeper service, session 0x15fcbdb62647c04 has expired 2017-11-29 21:22:50.508 UTC [main-SendThread(wdc04-dta-1-hcx-a:2181), , ] INFO org.apache.zookeeper.ClientCnxn- Unable to reconnect to ZooKeeper service, session 0x15fcbdb62647c04 has expired, closing socket connection > KafkaProducer.flush hangs when NetworkClient.handleCompletedReceives throws > exception > ------------------------------------------------------------------------------------- > > Key: KAFKA-4669 > URL: https://issues.apache.org/jira/browse/KAFKA-4669 > Project: Kafka > Issue Type: Bug > Components: clients > Affects Versions: 0.9.0.1 > Reporter: Cheng Ju > Assignee: Rajini Sivaram > Priority: Critical > Labels: reliability > Fix For: 0.11.0.1, 1.0.0 > > > There is no try catch in NetworkClient.handleCompletedReceives. If an > exception is thrown after inFlightRequests.completeNext(source), then the > corresponding RecordBatch's done will never get called, and > KafkaProducer.flush will hang on this RecordBatch. > I've checked 0.10 code and think this bug does exist in 0.10 versions. > A real case. First a correlateId not match exception happens: > 13 Jan 2017 17:08:24,059 ERROR [kafka-producer-network-thread | producer-21] > (org.apache.kafka.clients.producer.internals.Sender.run:130) - Uncaught > error in kafka producer I/O thread: > java.lang.IllegalStateException: Correlation id for response (703766) does > not match request (703764) > at > org.apache.kafka.clients.NetworkClient.correlate(NetworkClient.java:477) > at > org.apache.kafka.clients.NetworkClient.handleCompletedReceives(NetworkClient.java:440) > at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:265) > at > org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:216) > at > org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:128) > at java.lang.Thread.run(Thread.java:745) > Then jstack shows the thread is hanging on: > at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231) > at > org.apache.kafka.clients.producer.internals.ProduceRequestResult.await(ProduceRequestResult.java:57) > at > org.apache.kafka.clients.producer.internals.RecordAccumulator.awaitFlushCompletion(RecordAccumulator.java:425) > at > org.apache.kafka.clients.producer.KafkaProducer.flush(KafkaProducer.java:544) > at org.apache.flume.sink.kafka.KafkaSink.process(KafkaSink.java:224) > at > org.apache.flume.sink.DefaultSinkProcessor.process(DefaultSinkProcessor.java:67) > at org.apache.flume.SinkRunner$PollingRunner.run(SinkRunner.java:145) > at java.lang.Thread.run(Thread.java:745) > client code -- This message was sent by Atlassian JIRA (v6.4.14#64029)