Skip to content

Instantly share code, notes, and snippets.

@ottomata

ottomata/broker-analytics1018-kafka.log

Last active August 29, 2015 14:03
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 ottomata/e42480446c627ea0af22 to your computer and use it in GitHub Desktop.
Save ottomata/e42480446c627ea0af22 to your computer and use it in GitHub Desktop.
Download ZIP
kafka zookeeper state change expired logs
Raw
broker-analytics1018-kafka.log
[2014-07-02 18:53:26,021] 685198343 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.ReplicaStateMachine$BrokerChangeListener - [BrokerChangeListener on Controller 18]: Broker change listener fired for path /brokers/ids with children 22,18,12
[2014-07-02 18:53:26,034] 685198356 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.ReplicaStateMachine$BrokerChangeListener - [BrokerChangeListener on Controller 18]: Newly added brokers: , deleted brokers: 21, all live brokers: 22,18,12
[2014-07-02 18:53:26,034] 685198356 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.RequestSendThread - [Controller-18-to-broker-21-send-thread], Shutting down
[2014-07-02 18:53:26,034] 685198356 [Controller-18-to-broker-21-send-thread] INFO kafka.controller.RequestSendThread - [Controller-18-to-broker-21-send-thread], Stopped
[2014-07-02 18:53:26,035] 685198357 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.RequestSendThread - [Controller-18-to-broker-21-send-thread], Shutdown completed
[2014-07-02 18:53:26,035] 685198357 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.KafkaController - [Controller 18]: Broker failure callback for 21
[2014-07-02 18:53:26,035] 685198357 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.KafkaController - [Controller 18]: Removed ArrayBuffer() from list of shutting down brokers.
[2014-07-02 18:53:26,036] 685198358 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.PartitionStateMachine - [Partition state machine on Controller 18]: Invoking state change to OfflinePartition for partitions [webrequest_upload,5],[webrequest_text,11],[webrequest_bits,11],[webrequest_mobile,10],[webrequest_mobile,2],[webrequest_bits,7],[webrequest_text,3],[webrequest_text,7],[webrequest_upload,1],[webrequest_bits,3],[webrequest_upload,9],[webrequest_mobile,6]
...
Raw
broker-analytics1021-kafkaServer-gc.log
2014-07-02T18:53:19.533+0000: 683635.843: [GC pause (young), 0.0169900 secs]
[Parallel Time: 13.1 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 683635842.8, Avg: 683635843.1, Max: 683635843.3, Diff: 0.4]
[Ext Root Scanning (ms): Min: 1.7, Avg: 2.1, Max: 2.6, Diff: 0.9, Sum: 20.9]
[Update RS (ms): Min: 1.0, Avg: 1.5, Max: 2.2, Diff: 1.2, Sum: 14.6]
[Processed Buffers: Min: 1, Avg: 3.6, Max: 16, Diff: 15, Sum: 36]
[Scan RS (ms): Min: 5.0, Avg: 5.5, Max: 5.6, Diff: 0.6, Sum: 54.7]
[Object Copy (ms): Min: 3.2, Avg: 3.3, Max: 3.4, Diff: 0.1, Sum: 32.7]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.6]
[GC Worker Total (ms): Min: 12.2, Avg: 12.4, Max: 12.6, Diff: 0.4, Sum: 123.5]
[GC Worker End (ms): Min: 683635855.4, Avg: 683635855.4, Max: 683635855.5, Diff: 0.1]
[Code Root Fixup: 0.0 ms]
[Clear CT: 0.9 ms]
[Other: 2.9 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.8 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 1.5 ms]
[Eden: 512.0M(44.0M)->0.0B(607.0M) Survivors: 7168.0K->7168.0K Heap: 728.7M(1024.0M)->219.0M(1024.0M)]
[Times: user=0.14 sys=0.00, real=11.47 secs]
2014-07-02T18:53:31.778+0000: 683648.088: [GC pause (young), 0.0152650 secs]
[Parallel Time: 11.4 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 683648088.1, Avg: 683648088.3, Max: 683648088.5, Diff: 0.4]
[Ext Root Scanning (ms): Min: 1.6, Avg: 1.8, Max: 2.1, Diff: 0.6, Sum: 17.9]
[Update RS (ms): Min: 0.6, Avg: 0.9, Max: 1.4, Diff: 0.8, Sum: 9.1]
[Processed Buffers: Min: 2, Avg: 3.9, Max: 7, Diff: 5, Sum: 39]
[Scan RS (ms): Min: 4.2, Avg: 4.8, Max: 5.0, Diff: 0.8, Sum: 48.2]
[Object Copy (ms): Min: 3.1, Avg: 3.1, Max: 3.3, Diff: 0.2, Sum: 31.3]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
[GC Worker Total (ms): Min: 10.5, Avg: 10.7, Max: 10.9, Diff: 0.4, Sum: 107.0]
[GC Worker End (ms): Min: 683648098.9, Avg: 683648099.0, Max: 683648099.0, Diff: 0.1]
[Code Root Fixup: 0.0 ms]
[Clear CT: 0.8 ms]
[Other: 3.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 1.0 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 1.4 ms]
[Eden: 469.0M(607.0M)->0.0B(554.0M) Survivors: 7168.0K->9216.0K Heap: 766.7M(1024.0M)->299.4M(1024.0M)]
[Times: user=0.12 sys=0.00, real=0.02 secs]
2014-07-02T18:53:31.844+0000: 683648.154: [GC pause (young) (initial-mark), 0.0145400 secs]
[Parallel Time: 11.7 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 683648154.4, Avg: 683648154.7, Max: 683648154.9, Diff: 0.5]
[Ext Root Scanning (ms): Min: 1.5, Avg: 1.8, Max: 2.0, Diff: 0.4, Sum: 17.7]
[Update RS (ms): Min: 0.3, Avg: 0.6, Max: 1.1, Diff: 0.8, Sum: 6.4]
[Processed Buffers: Min: 0, Avg: 1.8, Max: 6, Diff: 6, Sum: 18]
[Scan RS (ms): Min: 5.8, Avg: 5.9, Max: 6.1, Diff: 0.3, Sum: 59.3]
[Object Copy (ms): Min: 2.8, Avg: 3.0, Max: 3.1, Diff: 0.3, Sum: 29.7]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
[GC Worker Total (ms): Min: 11.2, Avg: 11.4, Max: 11.6, Diff: 0.5, Sum: 113.7]
[GC Worker End (ms): Min: 683648166.1, Avg: 683648166.1, Max: 683648166.1, Diff: 0.0]
[Code Root Fixup: 0.0 ms]
[Clear CT: 1.2 ms]
[Other: 1.6 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 1.0 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.1 ms]
[Eden: 1024.0K(554.0M)->0.0B(105.0M) Survivors: 9216.0K->7168.0K Heap: 306.0M(1024.0M)->304.0M(1024.0M)]
[Times: user=0.11 sys=0.00, real=0.01 secs]
2014-07-02T18:53:31.859+0000: 683648.169: [GC concurrent-root-region-scan-start]
2014-07-02T18:53:31.864+0000: 683648.174: [GC concurrent-root-region-scan-end, 0.0051300 secs]
2014-07-02T18:53:31.864+0000: 683648.174: [GC concurrent-mark-start]
2014-07-02T18:53:31.916+0000: 683648.226: [GC concurrent-mark-end, 0.0519160 secs]
2014-07-02T18:53:31.917+0000: 683648.227: [GC remark 2014-07-02T18:53:31.918+0000: 683648.228: [GC ref-proc, 0.0058190 secs], 0.0098060 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
2014-07-02T18:53:31.928+0000: 683648.237: [GC cleanup 357M->253M(1024M), 0.0042620 secs]
[Times: user=0.02 sys=0.00, real=0.01 secs]
2014-07-02T18:53:31.932+0000: 683648.242: [GC concurrent-cleanup-start]
2014-07-02T18:53:31.932+0000: 683648.242: [GC concurrent-cleanup-end, 0.0003520 secs]
2014-07-02T18:53:32.051+0000: 683648.361: [GC pause (young), 0.0126590 secs]
[Parallel Time: 10.7 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 683648361.3, Avg: 683648361.5, Max: 683648361.6, Diff: 0.4]
[Ext Root Scanning (ms): Min: 2.2, Avg: 2.6, Max: 3.2, Diff: 1.0, Sum: 25.9]
[Update RS (ms): Min: 0.5, Avg: 1.1, Max: 1.4, Diff: 0.9, Sum: 10.9]
[Processed Buffers: Min: 0, Avg: 3.6, Max: 10, Diff: 10, Sum: 36]
[Scan RS (ms): Min: 3.4, Avg: 3.9, Max: 4.1, Diff: 0.7, Sum: 38.9]
[Object Copy (ms): Min: 2.5, Avg: 2.6, Max: 2.7, Diff: 0.2, Sum: 25.9]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.4]
[GC Worker Total (ms): Min: 10.0, Avg: 10.2, Max: 10.4, Diff: 0.4, Sum: 102.1]
[GC Worker End (ms): Min: 683648371.7, Avg: 683648371.7, Max: 683648371.7, Diff: 0.0]
[Code Root Fixup: 0.0 ms]
[Clear CT: 0.6 ms]
[Other: 1.3 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.5 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.4 ms]
[Eden: 105.0M(105.0M)->0.0B(44.0M) Survivors: 7168.0K->7168.0K Heap: 325.4M(1024.0M)->220.3M(1024.0M)]
[Times: user=0.10 sys=0.01, real=0.01 secs]
2014-07-02T18:53:32.246+0000: 683648.556: [GC pause (mixed), 0.0164220 secs]
[Parallel Time: 12.8 ms, GC Workers: 10]
[GC Worker Start (ms): Min: 683648556.7, Avg: 683648557.0, Max: 683648557.2, Diff: 0.5]
[Ext Root Scanning (ms): Min: 1.5, Avg: 2.1, Max: 2.6, Diff: 1.1, Sum: 20.5]
[Update RS (ms): Min: 0.4, Avg: 0.7, Max: 1.2, Diff: 0.7, Sum: 7.5]
[Processed Buffers: Min: 1, Avg: 3.4, Max: 9, Diff: 8, Sum: 34]
[Scan RS (ms): Min: 5.2, Avg: 5.3, Max: 5.4, Diff: 0.2, Sum: 53.3]
[Object Copy (ms): Min: 3.8, Avg: 3.8, Max: 3.9, Diff: 0.2, Sum: 38.4]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
[GC Worker Total (ms): Min: 11.7, Avg: 12.0, Max: 12.2, Diff: 0.5, Sum: 120.0]
[GC Worker End (ms): Min: 683648568.9, Avg: 683648569.0, Max: 683648569.0, Diff: 0.0]
[Code Root Fixup: 0.0 ms]
[Clear CT: 0.9 ms]
[Other: 2.7 ms]
[Choose CSet: 0.4 ms]
[Ref Proc: 1.0 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 0.7 ms]
[Eden: 44.0M(44.0M)->0.0B(44.0M) Survivors: 7168.0K->7168.0K Heap: 271.4M(1024.0M)->208.0M(1024.0M)]
[Times: user=0.12 sys=0.00, real=0.02 secs]
Raw
broker-analytics1021.kafka.log
[2014-07-02 18:53:31,007] 683646571 [main-SendThread(analytics1024.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Client session timed out, have not heard from server in 12073ms fo
r sessionid 0x44ff30df253948, closing socket connection and attempting reconnect
[2014-07-02 18:53:31,010] 683646574 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,018] 683646582 [kafka-processor-9092-1] INFO kafka.network.Processor - Closing socket connection to /10.64.36.122.
[2014-07-02 18:53:31,029] 683646593 [kafka-processor-9092-1] INFO kafka.network.Processor - Closing socket connection to /10.64.5.12.
[2014-07-02 18:53:31,042] 683646606 [kafka-processor-9092-1] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,044] 683646608 [kafka-processor-9092-0] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,107] 683646671 [main-EventThread] INFO org.I0Itec.zkclient.ZkClient - zookeeper state changed (Disconnected)
[2014-07-02 18:53:31,217] 683646781 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.5.12.
[2014-07-02 18:53:31,221] 683646785 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,223] 683646787 [kafka-processor-9092-0] INFO kafka.network.Processor - Closing socket connection to /10.64.5.12.
[2014-07-02 18:53:31,231] 683646795 [kafka-processor-9092-0] INFO kafka.network.Processor - Closing socket connection to /10.64.36.122.
[2014-07-02 18:53:31,251] 683646815 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.36.122.
[2014-07-02 18:53:31,260] 683646824 [main-SendThread(analytics1024.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Opening socket connection to server analytics1023.eqiad.wmnet/10.64.5.15:2181
:
[2014-07-02 18:52:55,058] 683610622 [ReplicaFetcherThread-1-22] INFO kafka.log.Log - [Kafka Log on Broker 21], Rolling log 'webrequest_text-0' to /var/spool/kafka/h/data/webrequest_text-0/00000000001237434495.log and /var/spool/kafka/h/data/webrequest_text-0/00000000001237434495.index
[2014-07-02 18:53:31,007] 683646571 [main-SendThread(analytics1024.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Client session timed out, have not heard from server in 12073ms for sessionid 0x44ff30df253948, closing socket connection and attempting reconnect
[2014-07-02 18:53:31,010] 683646574 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,018] 683646582 [kafka-processor-9092-1] INFO kafka.network.Processor - Closing socket connection to /10.64.36.122.
[2014-07-02 18:53:31,029] 683646593 [kafka-processor-9092-1] INFO kafka.network.Processor - Closing socket connection to /10.64.5.12.
[2014-07-02 18:53:31,042] 683646606 [kafka-processor-9092-1] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,044] 683646608 [kafka-processor-9092-0] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,107] 683646671 [main-EventThread] INFO org.I0Itec.zkclient.ZkClient - zookeeper state changed (Disconnected)
[2014-07-02 18:53:31,217] 683646781 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.5.12.
[2014-07-02 18:53:31,221] 683646785 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.53.10.
[2014-07-02 18:53:31,223] 683646787 [kafka-processor-9092-0] INFO kafka.network.Processor - Closing socket connection to /10.64.5.12.
[2014-07-02 18:53:31,231] 683646795 [kafka-processor-9092-0] INFO kafka.network.Processor - Closing socket connection to /10.64.36.122.
[2014-07-02 18:53:31,251] 683646815 [kafka-processor-9092-2] INFO kafka.network.Processor - Closing socket connection to /10.64.36.122.
[2014-07-02 18:53:31,260] 683646824 [main-SendThread(analytics1024.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Opening socket connection to server analytics1023.eqiad.wmnet/10.64.5.15:2181
[2014-07-02 18:53:31,264] 683646828 [main-SendThread(analytics1023.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Socket connection established to analytics1023.eqiad.wmnet/10.64.5.15:2181, initiating session
[2014-07-02 18:53:31,273] 683646837 [main-SendThread(analytics1023.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Unable to reconnect to ZooKeeper service, session 0x44ff30df253948 has expired, closing socket connection
[2014-07-02 18:53:31,273] 683646837 [main-EventThread] INFO org.I0Itec.zkclient.ZkClient - zookeeper state changed (Expired)
[2014-07-02 18:53:31,274] 683646838 [main-EventThread] INFO org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad sessionTimeout=6000 watcher=org.I0Itec.zkclient.ZkClient@781d929f
[2014-07-02 18:53:31,322] 683646886 [main-SendThread()] INFO org.apache.zookeeper.ClientCnxn - Opening socket connection to server analytics1025.eqiad.wmnet/10.64.53.13:2181
[2014-07-02 18:53:31,322] 683646886 [main-EventThread] INFO org.apache.zookeeper.ClientCnxn - EventThread shut down
[2014-07-02 18:53:31,322] 683646886 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.server.KafkaZooKeeper - re-registering broker info in ZK for broker 21
[2014-07-02 18:53:31,324] 683646888 [main-SendThread(analytics1025.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Socket connection established to analytics1025.eqiad.wmnet/10.64.53.13:2181, initiating session
[2014-07-02 18:53:31,345] 683646909 [main-SendThread(analytics1025.eqiad.wmnet:2181)] INFO org.apache.zookeeper.ClientCnxn - Session establishment complete on server analytics1025.eqiad.wmnet/10.64.53.13:2181, sessionid = 0x144ff261ca63904, negotiated timeout = 6000
[2014-07-02 18:53:31,345] 683646909 [main-EventThread] INFO org.I0Itec.zkclient.ZkClient - zookeeper state changed (SyncConnected)
[2014-07-02 18:53:31,353] 683646917 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.utils.ZkUtils$ - Registered broker 21 at path /brokers/ids/21 with address analytics1021.eqiad.wmnet:9092.
[2014-07-02 18:53:31,353] 683646917 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.server.KafkaZooKeeper - done re-registering broker
[2014-07-02 18:53:31,354] 683646918 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.server.KafkaZooKeeper - Subscribing to /brokers/topics path to watch for new topics
[2014-07-02 18:53:31,366] 683646930 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.utils.ZkUtils$ - conflict in /controller data: { "brokerid":21, "timestamp":"1404327211354", "version":1 } stored data: { "brokerid":18, "timestamp":"1403642008075", "version":1 }
[2014-07-02 18:53:31,405] 683646969 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.ControllerEpochListener - [ControllerEpochListener on 21]: Initialized controller epoch to 1 and zk version 0
[2014-07-02 18:53:31,419] 683646983 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.server.ZookeeperLeaderElector$LeaderChangeListener - New leader is 18
[2014-07-02 18:53:31,502] 683647066 [kafka-request-handler-3] INFO kafka.server.ReplicaManager - [Replica Manager on Broker 21]: Handling LeaderAndIsr request Name:LeaderAndIsrRequest;Version:0;Controller:18;ControllerEpoch:1;CorrelationId:120;ClientId:id_18-host_null-port_9092;PartitionState:(webrequest_text,7) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,22,12),(webrequest_text,11) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webrequest_bits,5) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,21,22),(webrequest_upload,1) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,18,22),(webrequest_bits,3) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,22,12),(webrequest_mobile,10) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,22,12),(webrequest_mobile,5) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,12,21),(webrequest_mobile,8) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,18,21),(webrequest_mobile,7) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,21,12),(webrequest_upload,10) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest_bits,4) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest_text,5) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,18,21),(webrequest_text,0) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,21,12),(webrequest_mobile,2) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webrequest_bits,2) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,21,22),(webrequest_mobile,6) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,18,22),(webrequest_bits,8) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,21,12),(webrequest_text,9) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,21,22),(webrequest_text,6) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,21,22),(webrequest_mobile,3) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest_upload,0) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,12,21),(webrequest_bits,7) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webrequest_bits,11) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,18,22),(webrequest_upload,5) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,22,12),(webrequest_upload,4) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,21,22),(webrequest_bits,10) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,12,21),(webrequest_upload,11) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,21,22),(webrequest_bits,1) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,18,21),(webrequest_text,8) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest_mobile,0) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,21,22),(webrequest_upload,7) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,18,21),(webrequest_upload,2) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,21,12),(webrequest_mobile,9) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,21,22),(webrequest_text,2) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,12,21),(webrequest_upload,9) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webrequest_text,3) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,18,22);Leaders:id:22,host:analytics1022.eqiad.wmnet,port:9092,id:18,host:analytics1018.eqiad.wmnet,port:9092,id:12,host:analytics1012.eqiad.wmnet,port:9092
[2014-07-02 18:53:31,568] 683647132 [kafka-request-handler-3] INFO kafka.server.ReplicaFetcherManager - [ReplicaFetcherManager on broker 21] Removing fetcher for partition [webrequest_text,7]
[2014-07-02 18:53:31,873] 683647437 [kafka-request-handler-3] INFO kafka.log.Log - [Kafka Log on Broker 21], Truncated log segment /var/spool/kafka/k/data/webrequest_text-7/00000000001234410832.log to target offset 1236977766
[2014-07-02 18:53:31,874] 683647438 [kafka-request-handler-3] INFO kafka.server.ReplicaFetcherManager - [ReplicaFetcherManager on broker 21] Adding fetcher for partition [webrequest_text,7], initOffset 1236977766 to broker 22 with fetcherId 2
[2014-07-02 18:53:31,874] 683647438 [kafka-request-handler-2] WARN kafka.server.KafkaApis - [KafkaApi-21] Produce request with correlation id 638388 from client varnishkafka on partition [webrequest_text,7] failed due to Leader not local for partition [webrequest_text,7] on broker 21
[2014-07-02 18:53:31,874] 683647438 [kafka-request-handler-8] WARN kafka.server.KafkaApis - [KafkaApi-21] Produce request with correlation id 533534 from client varnishkafka on partition [webrequest_text,7] failed due to Leader not local for partition [webrequest_text,7] on broker 21
[2014-07-02 18:53:31,874] 683647438 [kafka-request-handler-9] WARN kafka.server.KafkaApis - [KafkaApi-21] Produce request with correlation id 523241 from client varnishkafka on partition [webrequest_text,7] failed due to Leader not local for partition [webrequest_text,7] on broker 21
[2014-07-02 18:53:31,874] 683647438 [kafka-request-handler-4] WARN kafka.server.KafkaApis - [KafkaApi-21] Produce request with correlation id 638439 from client varnishkafka on partition [webrequest_text,7] failed due to Leader not local for partition [webrequest_text,7] on broker 21
[2014-07-02 18:53:31,877] 683647441 [kafka-request-handler-11] WARN kafka.server.KafkaApis - [KafkaApi-21] Produce request with correlation id 638313 from client varnishkafka on partition [webrequest_text,7] failed due to Leader not local for partition [webrequest_text,7] on broker 21
[2014-07-02 18:53:31,877] 683647441 [kafka-request-handler-0] WARN kafka.server.KafkaApis - [KafkaApi-21] Produce request with correlation id 533240 from client varnishkafka on partition [webrequest_text,7] failed due to Leader not local for partition [webrequest_text,7] on broker 21
[2014-07-02 18:53:31,874] 683647438 [kafka-request-handler-3] INFO kafka.server.ReplicaFetcherManager - [ReplicaFetcherManager on broker 21] Removing fetcher for partition [webrequest_text,11]
[2014-07-02 18:53:31,878] 683647442 [kafka-request-handler-0] WARN kafka.server.KafkaApis - [KafkaApi-21] Produce request with correlation id 533292 from client varnishkafka on partition [webcribing to /brokers/topics path to watch for new topics
[2014-07-02 18:53:31,366] 683646930 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.utils.ZkUtils$ - conflict in
/controller data: { "brokerid":21, "timestamp":"1404327211354", "version":1 } stored data: { "brokerid":18, "timestamp":"1403642008075", "version":1 }
[2014-07-02 18:53:31,405] 683646969 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.controller.ControllerEpochLis
tener - [ControllerEpochListener on 21]: Initialized controller epoch to 1 and zk version 0
[2014-07-02 18:53:31,419] 683646983 [ZkClient-EventThread-21-analytics1023.eqiad.wmnet,analytics1024.eqiad.wmnet,analytics1025.eqiad.wmnet/kafka/eqiad] INFO kafka.server.ZookeeperLeaderElector
$LeaderChangeListener - New leader is 18
[2014-07-02 18:53:31,502] 683647066 [kafka-request-handler-3] INFO kafka.server.ReplicaManager - [Replica Manager on Broker 21]: Handling LeaderAndIsr request Name:LeaderAndIsrRequest;Version
:0;Controller:18;ControllerEpoch:1;CorrelationId:120;ClientId:id_18-host_null-port_9092;PartitionState:(webrequest_text,7) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoc
h:1),ReplicationFactor:3),AllReplicas:21,22,12),(webrequest_text,11) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webre
quest_bits,5) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,21,22),(webrequest_upload,1) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,
22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,18,22),(webrequest_bits,3) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3
),AllReplicas:21,22,12),(webrequest_mobile,10) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,22,12),(webrequest_mobile,5) -> (Le
aderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,12,21),(webrequest_mobile,8) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,Con
trollerEpoch:1),ReplicationFactor:3),AllReplicas:12,18,21),(webrequest_mobile,7) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,2
1,12),(webrequest_upload,10) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest_bits,4) -> (LeaderAndIsrInfo:(Lead
er:22,ISR:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest_text,5) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,ControllerEpoch:1),Replic
ationFactor:3),AllReplicas:12,18,21),(webrequest_text,0) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,21,12),(webrequest_mobile
,2) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webrequest_bits,2) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpo
ch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,21,22),(webrequest_mobile,6) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllRepli
cas:21,18,22),(webrequest_bits,8) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,21,12),(webrequest_text,9) -> (LeaderAndIsrInfo:
(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,21,22),(webrequest_text,6) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:1,ControllerEpoch:1),R
eplicationFactor:3),AllReplicas:18,21,22),(webrequest_mobile,3) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest
_upload,0) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,12,21),(webrequest_bits,7) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,Le
aderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webrequest_bits,11) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),Al
lReplicas:21,18,22),(webrequest_upload,5) -> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,22,12),(webrequest_upload,4) -> (LeaderA
ndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,21,22),(webrequest_bits,10) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,Controlle
rEpoch:1),ReplicationFactor:3),AllReplicas:18,12,21),(webrequest_upload,11) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,21,22)
,(webrequest_bits,1) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,18,21),(webrequest_text,8) -> (LeaderAndIsrInfo:(Leader:22,IS
R:22,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,18,21),(webrequest_mobile,0) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,22,LeaderEpoch:1,ControllerEpoch:1),ReplicationF
actor:3),AllReplicas:12,21,22),(webrequest_upload,7) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:12,18,21),(webrequest_upload,2)
-> (LeaderAndIsrInfo:(Leader:22,ISR:22,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:22,21,12),(webrequest_mobile,9) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,22,LeaderEpoch
:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:18,21,22),(webrequest_text,2) -> (LeaderAndIsrInfo:(Leader:18,ISR:18,12,LeaderEpoch:1,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:
18,12,21),(webrequest_upload,9) -> (LeaderAndIsrInfo:(Leader:12,ISR:12,18,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,12,18),(webrequest_text,3) -> (LeaderAndIsrInfo:(L
eader:18,ISR:18,22,LeaderEpoch:7,ControllerEpoch:1),ReplicationFactor:3),AllReplicas:21,18,22);Leaders:id:22,host:analytics1022.eqiad.wmnet,port:9092,id:18,host:analytics1018.eqiad.wmnet,port:9
092,id:12,host:analytics1012.eqiad.wmnet,port:9092
Raw
zookeeper-analytics1023-zookeeper.log
2014-07-02 18:53:31,264 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /10.64.5.14:38878
2014-07-02 18:53:31,265 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@770] - Client attempting to renew session 0x44ff30df253948 at /10.64.5.14:38878
2014-07-02 18:53:31,265 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:Learner@103] - Revalidating client: 19420883783596360
2014-07-02 18:53:31,272 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:NIOServerCnxn@1573] - Invalid session 0x44ff30df253948 for client /10.64.5.14:38878, probably expired
2014-07-02 18:53:31,272 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /10.64.5.14:38878 which had sessionid 0x44ff30df253948
2014-07-02 18:53:31,273 - ERROR [CommitProcessor:1023:NIOServerCnxn@445] - Unexpected Exception:
java.nio.channels.CancelledKeyException
at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:418)
at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1509)
at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:359)
at org.apache.zookeeper.server.quorum.CommitProcessor.run(CommitProcessor.java:73)
Raw
zookeeper-analytics1024-zookeeper.log
2014-07-02 18:53:26,020 - INFO [CommitProcessor:1024:NIOServerCnxn@1435] - Closed socket connection for client /10.64.5.14:59029 which had sessionid 0x44ff30df253948
Raw
zookeeper-analytics1025-zookeeper.log
2014-07-02 18:53:26,001 - INFO [SessionTracker:ZooKeeperServer@316] - Expiring session 0x44ff30df253948, timeout of 6000ms exceeded
2014-07-02 18:53:26,001 - INFO [ProcessThread:-1:PrepRequestProcessor@399] - Processed session termination for sessionid: 0x44ff30df253948
2014-07-02 18:53:31,325 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /10.64.5.14:56925
2014-07-02 18:53:31,325 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@777] - Client attempting to establish new session at /10.64.5.14:56925
2014-07-02 18:53:31,345 - INFO [CommitProcessor:1025:NIOServerCnxn@1580] - Established session 0x144ff261ca63904 with negotiated timeout 6000 for client /10.64.5.14:56925
2014-07-02 18:53:31,356 - INFO [ProcessThread:-1:PrepRequestProcessor@419] - Got user-level KeeperException when processing sessionid:0x144ff261ca63904 type:create cxid:0x8 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/kafka/eqiad/controller Error:KeeperErrorCode = NodeExists for /kafka/eqiad/controller
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment