Sameer, The server logs do not contain any non-INFO logs, which is a bit wired. Did you deploy the current trunk of Kafka? Also could you enable DEBUG level logging on Kafka brokers?
Guozhang On Wed, Nov 5, 2014 at 3:50 PM, Sameer Yami <sy...@ailive.net> wrote: > The server.log was taken separately. > We ran the test again and the server and producer logs are below (to get > same timings). > > > Thanks! > > > ------------------------------------------------------------------------------------ > > > > Producer Logs - > > > 2014-11-05 23:38:58,693 > Thread-3-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680002 after 0ms > 2014-11-05 23:39:00,695 > Thread-3-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680002 after 0ms > 2014-11-05 23:39:02,696 > Thread-3-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680002 after 0ms > 2014-11-05 23:39:02,828 pool-13-thread-2 INFO > kafka.utils.VerifiableProperties-68: Verifying properties > 2014-11-05 23:39:02,829 pool-13-thread-2 INFO > kafka.utils.VerifiableProperties-68: Property auto.commit.interval.ms is > overridden to 1000 > 2014-11-05 23:39:02,829 pool-13-thread-2 INFO > kafka.utils.VerifiableProperties-68: Property auto.offset.reset is > overridden to smallest > 2014-11-05 23:39:02,829 pool-13-thread-2 INFO > kafka.utils.VerifiableProperties-68: Property consumer.timeout.ms is > overridden to 10 > 2014-11-05 23:39:02,829 pool-13-thread-2 INFO > kafka.utils.VerifiableProperties-68: Property group.id is overridden to > TestCheck > 2014-11-05 23:39:02,830 pool-13-thread-2 WARN > kafka.utils.VerifiableProperties-83: Property serializer.class is not valid > 2014-11-05 23:39:02,830 pool-13-thread-2 INFO > kafka.utils.VerifiableProperties-68: Property zookeeper.connect is > overridden to 172.31.25.198:2181 > 2014-11-05 23:39:02,831 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Connecting to > zookeeper instance at 172.31.25.198:2181 > 2014-11-05 23:39:02,831 pool-13-thread-2 DEBUG > org.I0Itec.zkclient.ZkConnection-63: Creating new ZookKeeper instance to > connect to 172.31.25.198:2181. > 2014-11-05 23:39:02,831 pool-13-thread-2 INFO > org.apache.zookeeper.ZooKeeper-379: Initiating client connection, > connectString=172.31.25.198:2181 sessionTimeout=6000 > watcher=org.I0Itec.zkclient.ZkClient@3903b165 > 2014-11-05 23:39:02,831 ZkClient-EventThread-29-172.31.25.198:2181 INFO > org.I0Itec.zkclient.ZkEventThread-64: Starting ZkClient event thread. > 2014-11-05 23:39:02,831 pool-13-thread-1 INFO > kafka.utils.VerifiableProperties-68: Verifying properties > 2014-11-05 23:39:02,836 pool-13-thread-2-SendThread() INFO > org.apache.zookeeper.ClientCnxn-1061: Opening socket connection to server / > 172.31.25.198:2181 > 2014-11-05 23:39:02,836 pool-13-thread-1 WARN > kafka.utils.VerifiableProperties-83: Property batch.size is not valid > 2014-11-05 23:39:02,832 pool-13-thread-2 DEBUG > org.I0Itec.zkclient.ZkClient-878: Awaiting connection to Zookeeper server > 2014-11-05 23:39:02,836 pool-13-thread-1 INFO > kafka.utils.VerifiableProperties-68: Property message.send.max.retries is > overridden to 10 > 2014-11-05 23:39:02,836 pool-13-thread-2 DEBUG > org.I0Itec.zkclient.ZkClient-628: Waiting for keeper state SyncConnected > 2014-11-05 23:39:02,837 pool-13-thread-1 INFO > kafka.utils.VerifiableProperties-68: Property metadata.broker.list is > overridden to 172.31.25.198:9092 > 2014-11-05 23:39:02,837 pool-13-thread-1 INFO > kafka.utils.VerifiableProperties-68: Property retry.backoff.ms is > overridden to 1000 > 2014-11-05 23:39:02,837 pool-13-thread-1 INFO > kafka.utils.VerifiableProperties-68: Property serializer.class is > overridden to kafka.serializer.StringEncoder > 2014-11-05 23:39:02,837 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > INFO org.apache.zookeeper.ClientCnxn-950: Socket connection established to > ip-172-31-25-198.us-west-1.compute.internal/172.31.25.198:2181, initiating > session > 2014-11-05 23:39:02,838 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-999: Session establishment request > sent on ip-172-31-25-198.us-west-1.compute.internal/172.31.25.198:2181 > 2014-11-05 23:39:02,837 pool-13-thread-1 WARN > kafka.utils.VerifiableProperties-83: Property zk.connectiontimeout.ms is > not valid > 2014-11-05 23:39:02,841 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > INFO org.apache.zookeeper.ClientCnxn-739: Session establishment complete on > server ip-172-31-25-198.us-west-1.compute.internal/172.31.25.198:2181, > sessionid = 0x1498251e8680003, negotiated timeout = 6000 > 2014-11-05 23:39:02,841 pool-13-thread-2-EventThread DEBUG > org.I0Itec.zkclient.ZkClient-351: Received event: WatchedEvent > state:SyncConnected type:None path:null > 2014-11-05 23:39:02,841 pool-13-thread-2-EventThread INFO > org.I0Itec.zkclient.ZkClient-449: zookeeper state changed (SyncConnected) > 2014-11-05 23:39:02,841 pool-13-thread-2-EventThread DEBUG > org.I0Itec.zkclient.ZkClient-395: Leaving process event > 2014-11-05 23:39:02,841 pool-13-thread-2 DEBUG > org.I0Itec.zkclient.ZkClient-638: State is SyncConnected > 2014-11-05 23:39:02,842 pool-13-thread-2 DEBUG > kafka.utils.KafkaScheduler-52: Initializing task scheduler. > 2014-11-05 23:39:02,842 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], starting auto > committer every 1000 ms > 2014-11-05 23:39:02,842 pool-13-thread-2 DEBUG > kafka.utils.KafkaScheduler-52: Scheduling task kafka-consumer-autocommit > with initial delay 1000 ms and period 1000 ms. > 2014-11-05 23:39:02,843 pool-13-thread-2 DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], entering consume > 2014-11-05 23:39:02,843 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], begin registering > consumer TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 in ZK > 2014-11-05 23:39:02,846 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 1,1 replyHeader:: 1,29,-101 request:: > > '/consumers/TestCheck/ids/TestCheck_ip-172-31-25-198-1415230742830-f3dfc362,#7b2276657273696f6e223a312c22737562736372697074696f6e223a7b22486561727462656174223a317d2c227061747465726e223a22737461746963222c2274696d657374616d70223a2231343135323330373432383433227d,v{s{31,s{'world,'anyone}}},1 > response:: > 2014-11-05 23:39:02,854 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 2,1 replyHeader:: 2,30,-101 request:: > '/consumers/TestCheck/ids,,v{s{31,s{'world,'anyone}}},0 response:: > 2014-11-05 23:39:02,858 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 3,1 replyHeader:: 3,31,0 request:: > '/consumers/TestCheck,,v{s{31,s{'world,'anyone}}},0 response:: > '/consumers/TestCheck > 2014-11-05 23:39:02,861 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 4,1 replyHeader:: 4,32,0 request:: > '/consumers/TestCheck/ids,,v{s{31,s{'world,'anyone}}},0 response:: > '/consumers/TestCheck/ids > 2014-11-05 23:39:02,866 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 5,1 replyHeader:: 5,33,0 request:: > > '/consumers/TestCheck/ids/TestCheck_ip-172-31-25-198-1415230742830-f3dfc362,#7b2276657273696f6e223a312c22737562736372697074696f6e223a7b22486561727462656174223a317d2c227061747465726e223a22737461746963222c2274696d657374616d70223a2231343135323330373432383433227d,v{s{31,s{'world,'anyone}}},1 > response:: > '/consumers/TestCheck/ids/TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 > 2014-11-05 23:39:02,867 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], end registering > consumer TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 in ZK > 2014-11-05 23:39:02,868 pool-13-thread-2 DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Adding topicThreadId > (Test,TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0) and queue [] to > topicThreadIdAndQueues data structure > 2014-11-05 23:39:02,868 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], starting watcher > executor thread for consumer > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 > 2014-11-05 23:39:02,868 pool-13-thread-2 DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], adding topic Test and > 1 streams to map. > 2014-11-05 23:39:02,870 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 6,3 replyHeader:: 6,33,0 request:: > '/consumers/TestCheck/ids,T response:: > s{32,32,1415230742859,1415230742859,0,1,0,0,0,1,33} > 2014-11-05 23:39:02,872 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 7,8 replyHeader:: 7,33,0 request:: > '/consumers/TestCheck/ids,T response:: > v{'TestCheck_ip-172-31-25-198-1415230742830-f3dfc362} > 2014-11-05 23:39:02,873 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 8,3 replyHeader:: 8,33,-101 request:: > '/brokers/topics/Test,T response:: > 2014-11-05 23:39:02,873 pool-13-thread-2 DEBUG > org.I0Itec.zkclient.ZkClient-137: Subscribed data changes for > /brokers/topics/Test > 2014-11-05 23:39:02,873 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], begin rebalancing > consumer TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 try #0 > 2014-11-05 23:39:02,875 pool-13-thread-1 DEBUG > kafka.producer.async.DefaultEventHandler-52: Handling 1 events > 2014-11-05 23:39:02,877 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 9,8 replyHeader:: 9,33,0 request:: > '/brokers/ids,F response:: v{'0} > 2014-11-05 23:39:02,879 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 10,4 replyHeader:: 10,33,0 request:: > '/brokers/ids/0,F response:: > > #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343135323330363632383839222c22686f7374223a2235342e3231392e3134332e313639222c2276657273696f6e223a312c22706f7274223a393039327d,s{20,20,1415230662902,1415230662902,0,0,0,92748555640897537,91,0,20} > > 2014-11-05 23:39:02,887 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 11,4 replyHeader:: 11,33,0 request:: > > '/consumers/TestCheck/ids/TestCheck_ip-172-31-25-198-1415230742830-f3dfc362,F > response:: > > #7b2276657273696f6e223a312c22737562736372697074696f6e223a7b22486561727462656174223a317d2c227061747465726e223a22737461746963222c2274696d657374616d70223a2231343135323330373432383433227d,s{33,33,1415230742861,1415230742861,0,0,0,92748555640897539,91,0,33} > > 2014-11-05 23:39:02,896 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 12,8 replyHeader:: 12,33,0 request:: > '/consumers/TestCheck/ids,T response:: > v{'TestCheck_ip-172-31-25-198-1415230742830-f3dfc362} > 2014-11-05 23:39:02,898 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 13,4 replyHeader:: 13,33,0 request:: > > '/consumers/TestCheck/ids/TestCheck_ip-172-31-25-198-1415230742830-f3dfc362,F > response:: > > #7b2276657273696f6e223a312c22737562736372697074696f6e223a7b22486561727462656174223a317d2c227061747465726e223a22737461746963222c2274696d657374616d70223a2231343135323330373432383433227d,s{33,33,1415230742861,1415230742861,0,0,0,92748555640897539,91,0,33} > > 2014-11-05 23:39:02,908 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 14,8 replyHeader:: 14,33,0 request:: > '/brokers/ids,F response:: v{'0} > 2014-11-05 23:39:02,910 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 15,4 replyHeader:: 15,33,0 request:: > '/brokers/ids/0,F response:: > > #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343135323330363632383839222c22686f7374223a2235342e3231392e3134332e313639222c2276657273696f6e223a312c22706f7274223a393039327d,s{20,20,1415230662902,1415230662902,0,0,0,92748555640897537,91,0,20} > > 2014-11-05 23:39:02,917 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 0 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:02,917 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 16,4 replyHeader:: 16,33,-101 request:: > '/brokers/topics/Test,T response:: > 2014-11-05 23:39:02,920 pool-13-thread-2 DEBUG kafka.utils.ZkUtils$-52: > Partition map for /brokers/topics/Test is Map() > 2014-11-05 23:39:02,920 pool-13-thread-2 INFO > kafka.consumer.ConsumerFetcherManager-68: > [ConsumerFetcherManager-1415230742842] Stopping leader finder thread > 2014-11-05 23:39:02,921 pool-13-thread-2 INFO > kafka.consumer.ConsumerFetcherManager-68: > [ConsumerFetcherManager-1415230742842] Stopping all fetchers > 2014-11-05 23:39:02,921 pool-13-thread-2 INFO > kafka.consumer.ConsumerFetcherManager-68: > [ConsumerFetcherManager-1415230742842] All connections stopped > 2014-11-05 23:39:02,921 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Cleared all relevant > queues for this fetcher > 2014-11-05 23:39:02,921 pool-13-thread-2 DEBUG > kafka.consumer.ConsumerIterator-52: Clearing the current data chunk for > this consumer iterator > 2014-11-05 23:39:02,921 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Cleared the data > chunks in all the consumer message iterators > 2014-11-05 23:39:02,922 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Committing all offsets > after clearing the fetcher queues > 2014-11-05 23:39:02,922 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Releasing partition > ownership > 2014-11-05 23:39:02,922 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Consumer > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 rebalancing the following > partitions: ArrayBuffer() for topic Test with consumers: > List(TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0) > 2014-11-05 23:39:02,922 pool-13-thread-2 WARN > kafka.consumer.ZookeeperConsumerConnector-83: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], No broker partitions > consumed by consumer thread > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0 for topic Test > 2014-11-05 23:39:02,922 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Updating the cache > 2014-11-05 23:39:02,923 pool-13-thread-2 DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Partitions per topic > cache Map(Test -> ArrayBuffer()) > 2014-11-05 23:39:02,923 pool-13-thread-2 DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Consumers per topic > cache Map(Test -> > List(TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0)) > 2014-11-05 23:39:02,923 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Consumer > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 selected partitions : > 2014-11-05 23:39:02,927 pool-13-thread-2 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], end rebalancing > consumer TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 try #0 > 2014-11-05 23:39:02,928 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.consumer.ConsumerFetcherManager$LeaderFinderThread-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread], > Starting > 2014-11-05 23:39:02,930 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:02,930 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:02,985 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-783: Got notification > sessionid:0x1498251e8680003 > 2014-11-05 23:39:02,986 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-800: Got WatchedEvent > state:SyncConnected type:NodeCreated path:/brokers/topics/Test for > sessionid 0x1498251e8680003 > 2014-11-05 23:39:02,987 pool-13-thread-2-EventThread DEBUG > org.I0Itec.zkclient.ZkClient-351: Received event: WatchedEvent > state:SyncConnected type:NodeCreated path:/brokers/topics/Test > 2014-11-05 23:39:02,987 pool-13-thread-2-EventThread DEBUG > org.I0Itec.zkclient.ZkEventThread-88: New event: ZkEvent[Data of > /brokers/topics/Test changed sent to > > kafka.consumer.ZookeeperConsumerConnector$ZKTopicPartitionChangeListener@523b24ee > ] > 2014-11-05 23:39:02,987 pool-13-thread-2-EventThread DEBUG > org.I0Itec.zkclient.ZkClient-395: Leaving process event > 2014-11-05 23:39:02,988 ZkClient-EventThread-29-172.31.25.198:2181 DEBUG > org.I0Itec.zkclient.ZkEventThread-69: Delivering event #1 ZkEvent[Data of > /brokers/topics/Test changed sent to > > kafka.consumer.ZookeeperConsumerConnector$ZKTopicPartitionChangeListener@523b24ee > ] > 2014-11-05 23:39:02,991 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 17,3 replyHeader:: 17,37,0 request:: > '/brokers/topics/Test,T response:: > s{37,37,1415230742983,1415230742983,0,0,0,0,44,0,37} > 2014-11-05 23:39:02,993 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 18,4 replyHeader:: 18,37,0 request:: > '/brokers/topics/Test,T response:: > > #7b2276657273696f6e223a312c22706172746974696f6e73223a7b2231223a5b305d2c2230223a5b305d7d7d,s{37,37,1415230742983,1415230742983,0,0,0,0,44,0,37} > > 2014-11-05 23:39:02,994 ZkClient-EventThread-29-172.31.25.198:2181 INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Topic info for path > /brokers/topics/Test changed to > {"version":1,"partitions":{"1":[0],"0":[0]}}, triggering rebalance > 2014-11-05 23:39:02,994 ZkClient-EventThread-29-172.31.25.198:2181 DEBUG > org.I0Itec.zkclient.ZkEventThread-79: Delivering event #1 done > 2014-11-05 23:39:02,995 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], begin rebalancing > consumer TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 try #0 > 2014-11-05 23:39:02,996 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 19,8 replyHeader:: 19,37,0 request:: > '/brokers/ids,F response:: v{'0} > 2014-11-05 23:39:02,998 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 20,4 replyHeader:: 20,37,0 request:: > '/brokers/ids/0,F response:: > > #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343135323330363632383839222c22686f7374223a2235342e3231392e3134332e313639222c2276657273696f6e223a312c22706f7274223a393039327d,s{20,20,1415230662902,1415230662902,0,0,0,92748555640897537,91,0,20} > > 2014-11-05 23:39:03,008 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 21,4 replyHeader:: 21,37,0 request:: > > '/consumers/TestCheck/ids/TestCheck_ip-172-31-25-198-1415230742830-f3dfc362,F > response:: > > #7b2276657273696f6e223a312c22737562736372697074696f6e223a7b22486561727462656174223a317d2c227061747465726e223a22737461746963222c2274696d657374616d70223a2231343135323330373432383433227d,s{33,33,1415230742861,1415230742861,0,0,0,92748555640897539,91,0,33} > > 2014-11-05 23:39:03,014 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 22,8 replyHeader:: 22,37,0 request:: > '/consumers/TestCheck/ids,T response:: > v{'TestCheck_ip-172-31-25-198-1415230742830-f3dfc362} > 2014-11-05 23:39:03,018 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 23,4 replyHeader:: 23,37,0 request:: > > '/consumers/TestCheck/ids/TestCheck_ip-172-31-25-198-1415230742830-f3dfc362,F > response:: > > #7b2276657273696f6e223a312c22737562736372697074696f6e223a7b22486561727462656174223a317d2c227061747465726e223a22737461746963222c2274696d657374616d70223a2231343135323330373432383433227d,s{33,33,1415230742861,1415230742861,0,0,0,92748555640897539,91,0,33} > > 2014-11-05 23:39:03,041 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 24,8 replyHeader:: 24,37,0 request:: > '/brokers/ids,F response:: v{'0} > 2014-11-05 23:39:03,043 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 25,4 replyHeader:: 25,37,0 request:: > '/brokers/ids/0,F response:: > > #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343135323330363632383839222c22686f7374223a2235342e3231392e3134332e313639222c2276657273696f6e223a312c22706f7274223a393039327d,s{20,20,1415230662902,1415230662902,0,0,0,92748555640897537,91,0,20} > > 2014-11-05 23:39:03,058 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 26,4 replyHeader:: 26,37,0 request:: > '/brokers/topics/Test,T response:: > > #7b2276657273696f6e223a312c22706172746974696f6e73223a7b2231223a5b305d2c2230223a5b305d7d7d,s{37,37,1415230742983,1415230742983,0,0,0,0,44,0,37} > > 2014-11-05 23:39:03,074 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.utils.ZkUtils$-52: Partition map for /brokers/topics/Test is Map(1 -> > List(0), 0 -> List(0)) > 2014-11-05 23:39:03,075 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ConsumerFetcherManager-68: > [ConsumerFetcherManager-1415230742842] Stopping leader finder thread > 2014-11-05 23:39:03,082 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ConsumerFetcherManager$LeaderFinderThread-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread], > Shutting down > 2014-11-05 23:39:03,082 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:03,089 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.consumer.ConsumerFetcherManager$LeaderFinderThread-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread], > Stopped > 2014-11-05 23:39:03,089 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ConsumerFetcherManager$LeaderFinderThread-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread], > Shutdown completed > 2014-11-05 23:39:03,089 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ConsumerFetcherManager-68: > [ConsumerFetcherManager-1415230742842] Stopping all fetchers > 2014-11-05 23:39:03,090 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ConsumerFetcherManager-68: > [ConsumerFetcherManager-1415230742842] All connections stopped > 2014-11-05 23:39:03,090 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Cleared all relevant > queues for this fetcher > 2014-11-05 23:39:03,090 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.ConsumerIterator-52: Clearing the current data chunk for > this consumer iterator > 2014-11-05 23:39:03,091 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Cleared the data > chunks in all the consumer message iterators > 2014-11-05 23:39:03,091 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Committing all offsets > after clearing the fetcher queues > 2014-11-05 23:39:03,091 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Releasing partition > ownership > 2014-11-05 23:39:03,094 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:03,096 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Consumer > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 rebalancing the following > partitions: ArrayBuffer(0, 1) for topic Test with consumers: > List(TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0) > 2014-11-05 23:39:03,098 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0 attempting to claim > partition 0 > 2014-11-05 23:39:03,100 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 27,4 replyHeader:: 27,37,-101 request:: > '/consumers/TestCheck/offsets/Test/0,F response:: > 2014-11-05 23:39:03,116 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.PartitionTopicInfo-52: initial consumer offset of Test:0: > fetched offset = -1: consumed offset = -1 is -1 > 2014-11-05 23:39:03,117 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.PartitionTopicInfo-52: initial fetch offset of Test:0: > fetched offset = -1: consumed offset = -1 is -1 > 2014-11-05 23:39:03,118 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Test:0: fetched offset > = -1: consumed offset = -1 selected new offset -1 > 2014-11-05 23:39:03,169 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0 attempting to claim > partition 1 > 2014-11-05 23:39:03,171 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 28,4 replyHeader:: 28,37,-101 request:: > '/consumers/TestCheck/offsets/Test/1,F response:: > 2014-11-05 23:39:03,172 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.PartitionTopicInfo-52: initial consumer offset of Test:1: > fetched offset = -1: consumed offset = -1 is -1 > 2014-11-05 23:39:03,172 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.PartitionTopicInfo-52: initial fetch offset of Test:1: > fetched offset = -1: consumed offset = -1 is -1 > 2014-11-05 23:39:03,172 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Test:1: fetched offset > = -1: consumed offset = -1 selected new offset -1 > 2014-11-05 23:39:03,175 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:03,175 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 29,1 replyHeader:: 29,38,-101 request:: > > '/consumers/TestCheck/owners/Test/1,#6865616c7468636865636b5f69702d3137322d33312d32352d3139382d313431353233303734323833302d66336466633336322d30,v{s{31,s{'world,'anyone}}},1 > response:: > 2014-11-05 23:39:03,179 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 30,1 replyHeader:: 30,39,-101 request:: > '/consumers/TestCheck/owners/Test,,v{s{31,s{'world,'anyone}}},0 > response:: > 2014-11-05 23:39:03,180 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:03,181 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 1 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:03,182 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:03,182 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:03,186 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 31,1 replyHeader:: 31,40,0 request:: > '/consumers/TestCheck/owners,,v{s{31,s{'world,'anyone}}},0 response:: > '/consumers/TestCheck/owners > 2014-11-05 23:39:03,189 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:03,190 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 32,1 replyHeader:: 32,41,0 request:: > '/consumers/TestCheck/owners/Test,,v{s{31,s{'world,'anyone}}},0 response:: > '/consumers/TestCheck/owners/Test > 2014-11-05 23:39:03,190 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:03,191 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:03,192 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:03,193 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 33,1 replyHeader:: 33,42,0 request:: > > '/consumers/TestCheck/owners/Test/1,#6865616c7468636865636b5f69702d3137322d33312d32352d3139382d313431353233303734323833302d66336466633336322d30,v{s{31,s{'world,'anyone}}},1 > response:: '/consumers/TestCheck/owners/Test/1 > 2014-11-05 23:39:03,193 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 10 > 2014-11-05 23:39:03,193 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0 successfully owned > partition 1 for topic Test > 2014-11-05 23:39:03,196 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 34,1 replyHeader:: 34,43,0 request:: > > '/consumers/TestCheck/owners/Test/0,#6865616c7468636865636b5f69702d3137322d33312d32352d3139382d313431353233303734323833302d66336466633336322d30,v{s{31,s{'world,'anyone}}},1 > response:: '/consumers/TestCheck/owners/Test/0 > 2014-11-05 23:39:03,196 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0 successfully owned > partition 0 for topic Test > 2014-11-05 23:39:03,196 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Updating the cache > 2014-11-05 23:39:03,197 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Partitions per topic > cache Map(Test -> ArrayBuffer(0, 1)) > 2014-11-05 23:39:03,197 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor DEBUG > kafka.consumer.ZookeeperConsumerConnector-52: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Consumers per topic > cache Map(Test -> > List(TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-0)) > 2014-11-05 23:39:03,197 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], Consumer > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 selected partitions : > Test:0: fetched offset = -1: consumed offset = -1,Test:1: fetched offset = > -1: consumed offset = -1 > 2014-11-05 23:39:03,199 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.consumer.ConsumerFetcherManager$LeaderFinderThread-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread], > Starting > 2014-11-05 23:39:03,199 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362_watcher_executor INFO > kafka.consumer.ZookeeperConsumerConnector-68: > [TestCheck_ip-172-31-25-198-1415230742830-f3dfc362], end rebalancing > consumer TestCheck_ip-172-31-25-198-1415230742830-f3dfc362 try #0 > 2014-11-05 23:39:03,202 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 35,8 replyHeader:: 35,43,0 request:: > '/brokers/ids,F response:: v{'0} > 2014-11-05 23:39:03,204 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-839: Reading reply > sessionid:0x1498251e8680003, packet:: clientPath:null serverPath:null > finished:false header:: 36,4 replyHeader:: 36,43,0 request:: > '/brokers/ids/0,F response:: > > #7b226a6d785f706f7274223a2d312c2274696d657374616d70223a2231343135323330363632383839222c22686f7374223a2235342e3231392e3134332e313639222c2276657273696f6e223a312c22706f7274223a393039327d,s{20,20,1415230662902,1415230662902,0,0,0,92748555640897537,91,0,20} > > 2014-11-05 23:39:03,214 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.utils.VerifiableProperties-68: Verifying properties > 2014-11-05 23:39:03,215 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.utils.VerifiableProperties-68: Property client.id is overridden > to TestCheck > 2014-11-05 23:39:03,215 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.utils.VerifiableProperties-68: Property metadata.broker.list is > overridden to x.x.x.x:9092 > 2014-11-05 23:39:03,215 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.utils.VerifiableProperties-68: Property request.timeout.ms is > overridden to 30000 > 2014-11-05 23:39:03,217 > TestCheck_ip-172-31-25-198-1415230742830-f3dfc362-leader-finder-thread > INFO kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:x.x.x.x,port:9092 with correlation id 0 for 1 topic(s) Set(Test) > 2014-11-05 23:39:04,195 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 2 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:04,196 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:04,196 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:04,199 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:04,199 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:04,200 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:04,200 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:04,201 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 3 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:04,201 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:04,201 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:04,205 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:04,205 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:04,206 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:04,206 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:04,206 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 9 > 2014-11-05 23:39:04,698 > Thread-3-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680002 after 0ms > 2014-11-05 23:39:05,205 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680003 after 0ms > 2014-11-05 23:39:05,207 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 4 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:05,208 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:05,208 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:05,211 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:05,211 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:05,212 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:05,212 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:05,212 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 5 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:05,213 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:05,213 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:05,217 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:05,217 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:05,217 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:05,217 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:05,218 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 8 > 2014-11-05 23:39:06,218 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 6 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:06,219 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:06,219 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:06,224 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:06,224 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:06,225 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:06,225 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:06,226 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 7 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:06,226 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:06,226 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:06,230 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:06,230 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:06,231 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:06,231 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:06,231 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 7 > 2014-11-05 23:39:06,699 > Thread-3-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680002 after 0ms > 2014-11-05 23:39:07,208 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680003 after 0ms > 2014-11-05 23:39:07,232 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 8 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:07,233 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:07,233 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:07,236 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:07,236 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:07,237 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:07,237 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:07,238 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 9 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:07,238 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:07,238 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:07,241 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:07,241 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:07,242 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:07,242 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:07,242 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 6 > 2014-11-05 23:39:08,243 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 10 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:08,243 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:08,245 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:08,249 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:08,250 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:08,250 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:08,251 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:08,251 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 11 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:08,251 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:08,252 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:08,255 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:08,256 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:08,256 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:08,257 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:08,257 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 5 > 2014-11-05 23:39:08,702 > Thread-3-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680002 after 0ms > 2014-11-05 23:39:09,211 > > pool-13-thread-2-SendThread(ip-172-31-25-198.us-west-1.compute.internal:2181) > DEBUG org.apache.zookeeper.ClientCnxn-759: Got ping response for sessionid: > 0x1498251e8680003 after 0ms > 2014-11-05 23:39:09,257 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 12 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:09,258 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:09,258 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:09,261 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:09,262 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:09,262 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:09,262 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:09,263 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 13 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:09,264 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:09,264 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:09,268 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:09,268 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:09,269 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:09,269 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:09,269 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 4 > 2014-11-05 23:39:10,270 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 14 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:10,271 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:10,271 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:10,275 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:10,275 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:10,275 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:10,276 pool-13-thread-1 DEBUG > kafka.producer.BrokerPartitionInfo-52: Getting broker partition info for > topic Test > 2014-11-05 23:39:10,276 pool-13-thread-1 INFO > kafka.client.ClientUtils$-68: Fetching metadata from broker > id:0,host:172.31.25.198,port:9092 with correlation id 15 for 1 topic(s) > Set(Test) > 2014-11-05 23:39:10,277 pool-13-thread-1 DEBUG > kafka.network.BlockingChannel-52: Created socket with SO_TIMEOUT = 10000 > (requested 10000), SO_RCVBUF = 530904 (requested -1), SO_SNDBUF = 102400 > (requested 102400). > 2014-11-05 23:39:10,277 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Connected to 172.31.25.198:9092 for > producing > 2014-11-05 23:39:10,280 pool-13-thread-1 INFO > kafka.producer.SyncProducer-68: Disconnecting from 172.31.25.198:9092 > 2014-11-05 23:39:10,280 pool-13-thread-1 DEBUG > kafka.client.ClientUtils$-52: Successfully fetched metadata for 1 topic(s) > Set(Test) > 2014-11-05 23:39:10,280 pool-13-thread-1 WARN > kafka.producer.BrokerPartitionInfo-83: Error while fetching metadata > [{TopicMetadata for topic Test -> > No partition metadata for topic Test due to > kafka.common.LeaderNotAvailableException}] for topic [Test]: class > kafka.common.LeaderNotAvailableException > 2014-11-05 23:39:10,280 pool-13-thread-1 ERROR > kafka.producer.async.DefaultEventHandler-97: Failed to collate messages by > topic, partition due to: Failed to fetch topic metadata for topic: Test > 2014-11-05 23:39:10,280 pool-13-thread-1 INFO > kafka.producer.async.DefaultEventHandler-68: Back off for 1000 ms before > retrying send. Remaining retries = 3 > > > Brokers Logs - > > [2014-11-05 23:39:02,983] INFO Topic creation > {"version":1,"partitions":{"1":[0],"0":[0]}} (kafka.admin.AdminUtils$) > [2014-11-05 23:39:02,988] INFO [KafkaApi-0] Auto creation of topic Test > with 2 partitions and replication factor 1 is successful! > (kafka.server.KafkaApis) > [2014-11-05 23:39:03,092] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:03,191] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:04,200] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:04,205] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:05,211] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:05,218] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:06,224] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:06,230] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:07,236] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > [2014-11-05 23:39:07,241] INFO Closing socket connection to /172.31.25.198 > . > (kafka.network.Processor) > > > > > On Wed, Nov 5, 2014 at 3:05 PM, Guozhang Wang <wangg...@gmail.com> wrote: > > > Sameer, > > > > Yes, this is the server log. But there seems no abnormal entries in it, > and > > it does not cover the same time range as the producer client throwing > > LeaderNotAvailableException > > (it was 10/24, 14:30). > > > > The reason that I want to check the server log at that same reason is > > that LeaderNotAvailableException > > is set by the brokers while handling requests, and its server log will > show > > what is the cause it set this error code. > > > > Guozhang > > > > On Tue, Nov 4, 2014 at 12:47 PM, Sameer Yami <sy...@ailive.net> wrote: > > > > > Hi Guozhang, > > > > > > This is the server.log - > > > > > > [2014-11-04 20:21:57,510] INFO Verifying properties > > > (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,545] INFO Property advertised.host.name is > > overridden > > > to x.x.x.x (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,545] INFO Property broker.id is overridden to 0 > > > (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,545] INFO Property controlled.shutdown.enable is > > > overridden to true (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,545] INFO Property host.name is overridden to > > > 172.31.25.198 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,545] INFO Property log.cleaner.enable is > overridden > > to > > > false (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,546] INFO Property log.dirs is overridden to > > > /tmp/kafka-logs (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,546] INFO Property > log.retention.check.interval.ms > > is > > > overridden to 60000 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,546] INFO Property log.retention.hours is > overridden > > > to 168 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,546] INFO Property log.segment.bytes is overridden > > to > > > 536870912 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,546] INFO Property num.io.threads is overridden > to 8 > > > (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,547] INFO Property num.network.threads is > overridden > > > to 2 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,547] INFO Property num.partitions is overridden > to 2 > > > (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,547] INFO Property port is overridden to 9092 > > > (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,547] INFO Property socket.receive.buffer.bytes is > > > overridden to 1048576 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,547] INFO Property socket.request.max.bytes is > > > overridden to 104857600 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,547] INFO Property socket.send.buffer.bytes is > > > overridden to 1048576 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,548] INFO Property zookeeper.connect is overridden > > to > > > localhost:2181 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,548] INFO Property > zookeeper.connection.timeout.ms > > is > > > overridden to 1000000 (kafka.utils.VerifiableProperties) > > > [2014-11-04 20:21:57,563] INFO [Kafka Server 0], starting > > > (kafka.server.KafkaServer) > > > [2014-11-04 20:21:57,565] INFO [Kafka Server 0], Connecting to > zookeeper > > on > > > localhost:2181 (kafka.server.KafkaServer) > > > [2014-11-04 20:21:57,738] INFO Log directory '/tmp/kafka-logs' not > found, > > > creating it. (kafka.log.LogManager) > > > [2014-11-04 20:21:57,748] INFO Starting log cleanup with a period of > > 60000 > > > ms. (kafka.log.LogManager) > > > [2014-11-04 20:21:57,752] INFO Starting log flusher with a default > period > > > of 9223372036854775807 ms. (kafka.log.LogManager) > > > [2014-11-04 20:21:57,783] INFO Awaiting socket connections on > > > ip-172-31-25-198.us-west-1.compute.internal:9092. > > (kafka.network.Acceptor) > > > [2014-11-04 20:21:57,784] INFO [Socket Server on Broker 0], Started > > > (kafka.network.SocketServer) > > > [2014-11-04 20:21:57,852] INFO Will not load MX4J, mx4j-tools.jar is > not > > in > > > the classpath (kafka.utils.Mx4jLoader$) > > > [2014-11-04 20:21:57,884] INFO 0 successfully elected as leader > > > (kafka.server.ZookeeperLeaderElector) > > > [2014-11-04 20:21:57,967] INFO Registered broker 0 at path > /brokers/ids/0 > > > with address x.x.x.x:9092. (kafka.utils.ZkUtils$) > > > [2014-11-04 20:21:57,981] INFO [Kafka Server 0], started > > > (kafka.server.KafkaServer) > > > [2014-11-04 20:21:58,050] INFO New leader is 0 > > > (kafka.server.ZookeeperLeaderElector$LeaderChangeListener) > > > [2014-11-04 20:22:01,809] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:22:11,812] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:29,084] INFO Topic creation > > > {"version":1,"partitions":{"1":[0],"0":[0]}} (kafka.admin.AdminUtils$) > > > [2014-11-04 20:30:29,088] INFO [KafkaApi-0] Auto creation of topic Test > > > with 2 partitions and replication factor 1 is successful! > > > (kafka.server.KafkaApis) > > > [2014-11-04 20:30:29,280] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:29,301] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:30,310] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:30,315] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:31,320] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:31,325] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:32,331] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:32,336] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:33,343] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:33,347] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:34,356] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:34,360] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:35,366] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:35,372] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:36,377] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:36,382] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:37,387] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:37,394] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:38,399] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:38,403] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:39,410] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:39,414] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:40,419] INFO Closing socket connection to / > > 172.31.25.198 > > > . > > > (kafka.network.Processor) > > > [2014-11-04 20:30:41,602] INFO Topic creation > > > {"version":1,"partitions":{"1":[0],"0":[0]}} (kafka.admin.AdminUtils$) > > > > > > > > > > > > thanks > > > > > > > > > On Fri, Oct 31, 2014 at 9:15 AM, Guozhang Wang <wangg...@gmail.com> > > wrote: > > > > > > > The server.log should be the broker logs. > > > > > > > > Guozhang > > > > > > > > On Thu, Oct 30, 2014 at 11:32 AM, Sameer Yami <sy...@ailive.net> > > wrote: > > > > > > > > > I do not see any other logs besides these. > > > > > I checked the log4j.properties and where the logs are getting > stored. > > > > > The only other logs (apart from the controller logs) in the > directory > > > are > > > > > zookeeper-gc.log,kafkaServer-gc.log, server.log and > state-change.log > > > > > > > > > > Thanks > > > > > > > > > > On Wed, Oct 29, 2014 at 4:13 PM, Guozhang Wang <wangg...@gmail.com > > > > > > wrote: > > > > > > > > > > > Sorry for getting late on this Sameer. > > > > > > > > > > > > The logs you showed above are from controller logs, do you see > > > brokers > > > > > logs > > > > > > besides that? > > > > > > > > > > > > Guozhang > > > > > > > > > > > > On Wed, Oct 29, 2014 at 3:40 PM, Sameer Yami <sy...@ailive.net> > > > wrote: > > > > > > > > > > > > > Hi Guozhang, > > > > > > > > > > > > > > Is there any clue in the above data as to what is wrong? > > > > > > > > > > > > > > thanks > > > > > > > > > > > > > > > > > > > > > On Tue, Oct 28, 2014 at 3:45 PM, Sameer Yami <sy...@ailive.net > > > > > > wrote: > > > > > > > > > > > > > > > This is the one from the file specified in log4j.properties - > > > > > > > > > > > > > > > > [2014-10-28 22:38:36,082] DEBUG [TopicChangeListener on > > > Controller > > > > > 0]: > > > > > > > > Topic change listener fired for path /brokers/topics with > > > children > > > > > Test > > > > > > > > (kafka.controller.PartitionStateMachine$TopicChangeListener) > > > > > > > > [2014-10-28 22:38:36,094] INFO [TopicChangeListener on > > Controller > > > > 0]: > > > > > > New > > > > > > > > topics: [Set(Test)], deleted topics: [Set()], new partition > > > replica > > > > > > > > assignment [Map([Test,0] -> List(0), [Test,1] -> List(0))] > > > > > > > > (kafka.controller.PartitionStateMachine$TopicChangeListener) > > > > > > > > [2014-10-28 22:38:36,094] INFO [Controller 0]: New topic > > creation > > > > > > > callback > > > > > > > > for [Test,0],[Test,1] (kafka.controller.KafkaController) > > > > > > > > [2014-10-28 22:38:36,095] INFO [Controller 0]: New partition > > > > creation > > > > > > > > callback for [Test,0],[Test,1] > > (kafka.controller.KafkaController) > > > > > > > > [2014-10-28 22:38:36,095] INFO [Partition state machine on > > > > Controller > > > > > > 0]: > > > > > > > > Invoking state change to NewPartition for partitions > > > > > [Test,0],[Test,1] > > > > > > > > (kafka.controller.PartitionStateMachine) > > > > > > > > [2014-10-28 22:38:36,109] INFO [Replica state machine on > > > controller > > > > > 0]: > > > > > > > > Invoking state change to NewReplica for replicas > > > > > > > > > > > > [Topic=Test,Partition=0,Replica=0],[Topic=Test,Partition=1,Replica=0] > > > > > > > > (kafka.controller.ReplicaStateMachine) > > > > > > > > [2014-10-28 22:38:36,111] INFO [Partition state machine on > > > > Controller > > > > > > 0]: > > > > > > > > Invoking state change to OnlinePartition for partitions > > > > > > [Test,0],[Test,1] > > > > > > > > (kafka.controller.PartitionStateMachine) > > > > > > > > [2014-10-28 22:38:36,111] DEBUG [Partition state machine on > > > > > Controller > > > > > > > 0]: > > > > > > > > Live assigned replicas for partition [Test,0] are: [List(0)] > > > > > > > > (kafka.controller.PartitionStateMachine) > > > > > > > > [2014-10-28 22:38:36,112] DEBUG [Partition state machine on > > > > > Controller > > > > > > > 0]: > > > > > > > > Initializing leader and isr for partition [Test,0] to > > > > > > > > (Leader:0,ISR:0,LeaderEpoch:0,ControllerEpoch:1) > > > > > > > > (kafka.controller.PartitionStateMachine) > > > > > > > > [2014-10-28 22:38:36,141] DEBUG [Partition state machine on > > > > > Controller > > > > > > > 0]: > > > > > > > > Live assigned replicas for partition [Test,1] are: [List(0)] > > > > > > > > (kafka.controller.PartitionStateMachine) > > > > > > > > [2014-10-28 22:38:36,142] DEBUG [Partition state machine on > > > > > Controller > > > > > > > 0]: > > > > > > > > Initializing leader and isr for partition [Test,1] to > > > > > > > > (Leader:0,ISR:0,LeaderEpoch:0,ControllerEpoch:1) > > > > > > > > (kafka.controller.PartitionStateMachine) > > > > > > > > [2014-10-28 22:38:36,150] INFO [Replica state machine on > > > controller > > > > > 0]: > > > > > > > > Invoking state change to OnlineReplica for replicas > > > > > > > > > > > > [Topic=Test,Partition=0,Replica=0],[Topic=Test,Partition=1,Replica=0] > > > > > > > > (kafka.controller.ReplicaStateMachine) > > > > > > > > [2014-10-28 22:39:28,160] ERROR > > > > > [Controller-0-to-broker-0-send-thread], > > > > > > > > Controller 0's connection to broker > id:0,host:x.x.x.x,port:9092 > > > was > > > > > > > > unsuccessful (kafka.controller.RequestSendThread) > > > > > > > > java.net.ConnectException: Connection timed out > > > > > > > > at sun.nio.ch.Net.connect0(Native Method) > > > > > > > > at sun.nio.ch.Net.connect(Net.java:457) > > > > > > > > at sun.nio.ch.Net.connect(Net.java:449) > > > > > > > > at > > > > > sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:647) > > > > > > > > at > > > > > kafka.network.BlockingChannel.connect(BlockingChannel.scala:57) > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > kafka.controller.RequestSendThread.connectToBroker(ControllerChannelManager.scala:173) > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > kafka.controller.RequestSendThread.liftedTree1$1(ControllerChannelManager.scala:140) > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:131) > > > > > > > > at > > > > > kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:51) > > > > > > > > [2014-10-28 22:39:28,460] ERROR > > > > > [Controller-0-to-broker-0-send-thread], > > > > > > > > Controller 0 epoch 1 failed to send LeaderAndIsr request with > > > > > > correlation > > > > > > > > id 7 to broker id:0,host:x.x.x.x,port:9092. Reconnecting to > > > broker. > > > > > > > > (kafka.controller.RequestSendThread) > > > > > > > > java.nio.channels.ClosedChannelException > > > > > > > > at > > > kafka.network.BlockingChannel.send(BlockingChannel.scala:89) > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > kafka.controller.RequestSendThread.liftedTree1$1(ControllerChannelManager.scala:132) > > > > > > > > at > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:131) > > > > > > > > at > > > > > kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:51) > > > > > > > > > > > > > > > > On Tue, Oct 28, 2014 at 3:09 PM, Guozhang Wang < > > > wangg...@gmail.com > > > > > > > > > > > > wrote: > > > > > > > > > > > > > > > >> Sameer, the one you sent me is from the producer logs, not > the > > > > > broker > > > > > > > >> logs. > > > > > > > >> And /tmp/kafka-logs actually store the message log (i.e. the > > > > "data") > > > > > > > >> instead of the server logs. Their locations should be > > specified > > > in > > > > > > your > > > > > > > >> log4j.properties file. > > > > > > > >> > > > > > > > >> On Tue, Oct 28, 2014 at 2:51 PM, Sameer Yami < > > sy...@ailive.net> > > > > > > wrote: > > > > > > > >> > > > > > > > >> > Is this what you are looking for - > > > > > > > >> > > > > > > > > >> > 2014-10-28 21:46:24,146 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Connected to > > > 172.31.16.31:9092 > > > > > for > > > > > > > >> > producing > > > > > > > >> > 2014-10-28 21:46:24,149 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Disconnecting from > > > > > > 172.31.16.31:9092 > > > > > > > >> > 2014-10-28 21:46:24,149 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.client.ClientUtils$-52: Successfully fetched > metadata > > > for > > > > 1 > > > > > > > >> topic(s) > > > > > > > >> > Set(Test) > > > > > > > >> > 2014-10-28 21:46:24,150 pool-13-thread-1 WARN > > > > > > > >> > kafka.producer.BrokerPartitionInfo-83: Error while > fetching > > > > > metadata > > > > > > > >> > [{TopicMetadata for topic Test -> > > > > > > > >> > No partition metadata for topic Test due to > > > > > > > >> > kafka.common.LeaderNotAvailableException}] for topic > [Test]: > > > > class > > > > > > > >> > kafka.common.LeaderNotAvailableException > > > > > > > >> > 2014-10-28 21:46:24,150 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.producer.BrokerPartitionInfo-52: Getting broker > > > partition > > > > > info > > > > > > > for > > > > > > > >> > topic Test > > > > > > > >> > 2014-10-28 21:46:24,151 pool-13-thread-1 INFO > > > > > > > >> > kafka.client.ClientUtils$-68: Fetching metadata from > broker > > > > > > > >> > id:0,host:172.31.16.31,port:9092 with correlation id 9 > for 1 > > > > > > topic(s) > > > > > > > >> > Set(Test) > > > > > > > >> > 2014-10-28 21:46:24,151 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.network.BlockingChannel-52: Created socket with > > > > SO_TIMEOUT = > > > > > > > 10000 > > > > > > > >> > (requested 10000), SO_RCVBUF = 530904 (requested -1), > > > SO_SNDBUF > > > > = > > > > > > > 102400 > > > > > > > >> > (requested 102400). > > > > > > > >> > 2014-10-28 21:46:24,152 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Connected to > > > 172.31.16.31:9092 > > > > > for > > > > > > > >> > producing > > > > > > > >> > 2014-10-28 21:46:24,154 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Disconnecting from > > > > > > 172.31.16.31:9092 > > > > > > > >> > 2014-10-28 21:46:24,155 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.client.ClientUtils$-52: Successfully fetched > metadata > > > for > > > > 1 > > > > > > > >> topic(s) > > > > > > > >> > Set(Test) > > > > > > > >> > 2014-10-28 21:46:24,155 pool-13-thread-1 WARN > > > > > > > >> > kafka.producer.BrokerPartitionInfo-83: Error while > fetching > > > > > metadata > > > > > > > >> > [{TopicMetadata for topic Test -> > > > > > > > >> > No partition metadata for topic Test due to > > > > > > > >> > kafka.common.LeaderNotAvailableException}] for topic > [Test]: > > > > class > > > > > > > >> > kafka.common.LeaderNotAvailableException > > > > > > > >> > 2014-10-28 21:46:24,155 pool-13-thread-1 ERROR > > > > > > > >> > kafka.producer.async.DefaultEventHandler-97: Failed to > > collate > > > > > > > messages > > > > > > > >> by > > > > > > > >> > topic, partition due to: Failed to fetch topic metadata > for > > > > topic: > > > > > > > Test > > > > > > > >> > 2014-10-28 21:46:24,156 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.async.DefaultEventHandler-68: Back off for > > 1000 > > > > ms > > > > > > > before > > > > > > > >> > retrying send. Remaining retries = 6 > > > > > > > >> > 2014-10-28 21:46:25,156 pool-13-thread-1 INFO > > > > > > > >> > kafka.client.ClientUtils$-68: Fetching metadata from > broker > > > > > > > >> > id:0,host:172.31.16.31,port:9092 with correlation id 10 > for > > 1 > > > > > > topic(s) > > > > > > > >> > Set(Test) > > > > > > > >> > 2014-10-28 21:46:25,157 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.network.BlockingChannel-52: Created socket with > > > > SO_TIMEOUT = > > > > > > > 10000 > > > > > > > >> > (requested 10000), SO_RCVBUF = 530904 (requested -1), > > > SO_SNDBUF > > > > = > > > > > > > 102400 > > > > > > > >> > (requested 102400). > > > > > > > >> > 2014-10-28 21:46:25,157 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Connected to > > > 172.31.16.31:9092 > > > > > for > > > > > > > >> > producing > > > > > > > >> > 2014-10-28 21:46:25,160 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Disconnecting from > > > > > > 172.31.16.31:9092 > > > > > > > >> > 2014-10-28 21:46:25,161 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.client.ClientUtils$-52: Successfully fetched > metadata > > > for > > > > 1 > > > > > > > >> topic(s) > > > > > > > >> > Set(Test) > > > > > > > >> > 2014-10-28 21:46:25,161 pool-13-thread-1 WARN > > > > > > > >> > kafka.producer.BrokerPartitionInfo-83: Error while > fetching > > > > > metadata > > > > > > > >> > [{TopicMetadata for topic Test -> > > > > > > > >> > No partition metadata for topic Test due to > > > > > > > >> > kafka.common.LeaderNotAvailableException}] for topic > [Test]: > > > > class > > > > > > > >> > kafka.common.LeaderNotAvailableException > > > > > > > >> > 2014-10-28 21:46:25,161 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.producer.BrokerPartitionInfo-52: Getting broker > > > partition > > > > > info > > > > > > > for > > > > > > > >> > topic Test > > > > > > > >> > 2014-10-28 21:46:25,162 pool-13-thread-1 INFO > > > > > > > >> > kafka.client.ClientUtils$-68: Fetching metadata from > broker > > > > > > > >> > id:0,host:172.31.16.31,port:9092 with correlation id 11 > for > > 1 > > > > > > topic(s) > > > > > > > >> > Set(Test) > > > > > > > >> > 2014-10-28 21:46:25,162 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.network.BlockingChannel-52: Created socket with > > > > SO_TIMEOUT = > > > > > > > 10000 > > > > > > > >> > (requested 10000), SO_RCVBUF = 530904 (requested -1), > > > SO_SNDBUF > > > > = > > > > > > > 102400 > > > > > > > >> > (requested 102400). > > > > > > > >> > 2014-10-28 21:46:25,163 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Connected to > > > 172.31.16.31:9092 > > > > > for > > > > > > > >> > producing > > > > > > > >> > 2014-10-28 21:46:25,166 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.SyncProducer-68: Disconnecting from > > > > > > 172.31.16.31:9092 > > > > > > > >> > 2014-10-28 21:46:25,166 pool-13-thread-1 DEBUG > > > > > > > >> > kafka.client.ClientUtils$-52: Successfully fetched > metadata > > > for > > > > 1 > > > > > > > >> topic(s) > > > > > > > >> > Set(Test) > > > > > > > >> > 2014-10-28 21:46:25,166 pool-13-thread-1 WARN > > > > > > > >> > kafka.producer.BrokerPartitionInfo-83: Error while > fetching > > > > > metadata > > > > > > > >> > [{TopicMetadata for topic Test -> > > > > > > > >> > No partition metadata for topic Test due to > > > > > > > >> > kafka.common.LeaderNotAvailableException}] for topic > [Test]: > > > > class > > > > > > > >> > kafka.common.LeaderNotAvailableException > > > > > > > >> > 2014-10-28 21:46:25,167 pool-13-thread-1 ERROR > > > > > > > >> > kafka.producer.async.DefaultEventHandler-97: Failed to > > collate > > > > > > > messages > > > > > > > >> by > > > > > > > >> > topic, partition due to: Failed to fetch topic metadata > for > > > > topic: > > > > > > > Test > > > > > > > >> > 2014-10-28 21:46:25,167 pool-13-thread-1 INFO > > > > > > > >> > kafka.producer.async.DefaultEventHandler-68: Back off for > > 1000 > > > > ms > > > > > > > before > > > > > > > >> > retrying send. Remaining retries = 5 > > > > > > > >> > > > > > > > > >> > As for /tmp/kafka-logs, I can see only these files - > > > > > > > >> > recovery-point-offset-checkpoint > > > replication-offset-checkpoint > > > > > > > >> > > > > > > > > >> > I do not see the usual Kafka log files here. > > > > > > > >> > > > > > > > > >> > thanks > > > > > > > >> > Sameer > > > > > > > >> > > > > > > > > >> > On Tue, Oct 28, 2014 at 1:23 PM, Guozhang Wang < > > > > > wangg...@gmail.com> > > > > > > > >> wrote: > > > > > > > >> > > > > > > > > >> > > Sameer, could you check broker logs and see if it has > > > similar > > > > > > > >> > > LeaderNotAvailable exceptions? > > > > > > > >> > > > > > > > > > >> > > Guozhang > > > > > > > >> > > > > > > > > > >> > > On Tue, Oct 28, 2014 at 10:32 AM, Sameer Yami < > > > > sy...@ailive.net > > > > > > > > > > > > > >> wrote: > > > > > > > >> > > > > > > > > > >> > > > Yes. I can telnet from outside using the public ip of > > the > > > > > > instance > > > > > > > >> and > > > > > > > >> > > port > > > > > > > >> > > > of 9092 > > > > > > > >> > > > > > > > > > > >> > > > On Tue, Oct 28, 2014 at 10:08 AM, Roger Hoover < > > > > > > > >> roger.hoo...@gmail.com > > > > > > > >> > > > > > > > > > >> > > > wrote: > > > > > > > >> > > > > > > > > > > >> > > > > Just a guess but could it be a firewall issue? Did > > you > > > > > enable > > > > > > > >> > > > connections > > > > > > > >> > > > > to port 9092 from outside EC2 in a security group? > > Can > > > > you > > > > > > > >> telnet to > > > > > > > >> > > > each > > > > > > > >> > > > > broker IP and port? > > > > > > > >> > > > > > > > > > > > >> > > > > On Tue, Oct 28, 2014 at 10:01 AM, Sameer Yami < > > > > > > sy...@ailive.net > > > > > > > > > > > > > > > >> > > wrote: > > > > > > > >> > > > > > > > > > > > >> > > > > > There was a typo earlier. > > > > > > > >> > > > > > > > > > > > > >> > > > > > This is the output - > > > > > > > >> > > > > > > > > > > > > >> > > > > > Topic:Test PartitionCount:2 ReplicationFactor:1 > > > > > > Configs: > > > > > > > >> > > > > > Topic: Test Partition: 0 Leader: 0 > > > > > > Replicas: > > > > > > > 0 > > > > > > > >> > > > Isr: 0 > > > > > > > >> > > > > > Topic: Test Partition: 1 Leader: 0 > > > > > > Replicas: > > > > > > > 0 > > > > > > > >> > > > Isr: 0 > > > > > > > >> > > > > > > > > > > > > >> > > > > > thanks > > > > > > > >> > > > > > Sameer > > > > > > > >> > > > > > > > > > > > > >> > > > > > > > > > > > > >> > > > > > > > > > > > > >> > > > > > > > > > > > > >> > > > > > On Tue, Oct 28, 2014 at 9:40 AM, Guozhang Wang < > > > > > > > >> wangg...@gmail.com > > > > > > > >> > > > > > > > > > >> > > > > wrote: > > > > > > > >> > > > > > > > > > > > > >> > > > > > > Sameer, > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > The topic name is not consistent from your > > describe > > > > > > outputs. > > > > > > > >> > > Normally > > > > > > > >> > > > > > they > > > > > > > >> > > > > > > should be either > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > Topic:*Test* PartitionCount:2 > > > > ReplicationFactor:1 > > > > > > > >> > > Configs: > > > > > > > >> > > > > > > Topic: *Test* Partition: 0 > Leader: 0 > > > > > > > >> Replicas: 0 > > > > > > > >> > > > > > Isr: 0 > > > > > > > >> > > > > > > Topic: *Test* Partition: 1 > Leader: 0 > > > > > > > >> Replicas: 0 > > > > > > > >> > > > > > Isr: 0 > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > Or > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > Topic:*Heartbeat* PartitionCount:2 > > > > > > > ReplicationFactor:1 > > > > > > > >> > > > > Configs: > > > > > > > >> > > > > > > Topic: *Heartbeat* Partition: 0 > > > Leader: > > > > 0 > > > > > > > >> > > Replicas: > > > > > > > >> > > > 0 > > > > > > > >> > > > > > > Isr: 0 > > > > > > > >> > > > > > > Topic: *Heartbeat* Partition: 1 > > > Leader: > > > > 0 > > > > > > > >> > > Replicas: > > > > > > > >> > > > 0 > > > > > > > >> > > > > > > Isr: 0 > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > Did you manually modify the topic name in ZK? > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > Guozhang > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > On Tue, Oct 28, 2014 at 8:53 AM, Sameer Yami < > > > > > > > >> sy...@ailive.net> > > > > > > > >> > > > wrote: > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > > Hi Guozhang, > > > > > > > >> > > > > > > > > > > > > > > >> > > > > > > > I was wondering if there is anything wrong in > > the > > > > > above > > > > > > > >> > > --describe > > > > > > > >> > > > > > data. > > > > > > > >> > > > > > > > > > > > > > > >> > > > > > > > thanks > > > > > > > >> > > > > > > > > > > > > > > >> > > > > > > > > > > > > > > >> > > > > > > > On Mon, Oct 27, 2014 at 2:56 PM, Sameer Yami < > > > > > > > >> sy...@ailive.net > > > > > > > >> > > > > > > > > > >> > > > > wrote: > > > > > > > >> > > > > > > > > > > > > > > >> > > > > > > > > This is what I get - > > > > > > > >> > > > > > > > > bin/kafka-topics.sh --zookeeper > > localhost:2181 > > > > > > > --describe > > > > > > > >> > > > > > > > > Topic:Heartbeat PartitionCount:2 > > > > > > > >> ReplicationFactor:1 > > > > > > > >> > > > > > Configs: > > > > > > > >> > > > > > > > > Topic: Test Partition: 0 > > Leader: 0 > > > > > > > >> > Replicas: 0 > > > > > > > >> > > > > > > Isr: 0 > > > > > > > >> > > > > > > > > Topic: Test Partition: 1 > > Leader: 0 > > > > > > > >> > Replicas: 0 > > > > > > > >> > > > > > > Isr: 0 > > > > > > > >> > > > > > > > > > > > > > > > >> > > > > > > > > The topics are being created at run-time. > > > > > > > >> > > > > > > > > > > > > > > > >> > > > > > > > > thanks > > > > > > > >> > > > > > > > > > > > > > > > >> > > > > > > > > > > > > > > > >> > > > > > > > > On Sun, Oct 26, 2014 at 4:49 PM, Guozhang > > Wang < > > > > > > > >> > > > wangg...@gmail.com > > > > > > > >> > > > > > > > > > > > > >> > > > > > > > wrote: > > > > > > > >> > > > > > > > > > > > > > > > >> > > > > > > > >> Could you use the topic tools "--describe" > to > > > > check > > > > > > if > > > > > > > >> the > > > > > > > >> > > topic > > > > > > > >> > > > > > > Test's > > > > > > > >> > > > > > > > >> partitions leaders are available? > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > http://kafka.apache.org/documentation.html#basic_ops_add_topic > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> Guozhang > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> On Fri, Oct 24, 2014 at 2:43 PM, Sameer > Yami > > < > > > > > > > >> > > sy...@ailive.net> > > > > > > > >> > > > > > > wrote: > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> > That is not the case. > > > > > > > >> > > > > > > > >> > This detailed error is below. Due to this > > > > error , > > > > > > the > > > > > > > >> > > producer > > > > > > > >> > > > > is > > > > > > > >> > > > > > > not > > > > > > > >> > > > > > > > >> able > > > > > > > >> > > > > > > > >> > to send messages > > > > > > > >> > > > > > > > >> > > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,209 main DEBUG > > > > > > > >> > > > > > > > >> kafka.producer.BrokerPartitionInfo-52: > > > > > > > >> > > > > > > > >> > Getting broker partition info for topic > > Test > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,209 main INFO > > > > > > > >> > > > > kafka.client.ClientUtils$-68: > > > > > > > >> > > > > > > > >> Fetching > > > > > > > >> > > > > > > > >> > metadata from broker > > > > > > > id:0,host:54.215.200.61,port:9092 > > > > > > > >> > with > > > > > > > >> > > > > > > > correlation > > > > > > > >> > > > > > > > >> id > > > > > > > >> > > > > > > > >> > 1 for 1 topic(s) Set(Test) > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,230 main DEBUG > > > > > > > >> > > > > > > kafka.network.BlockingChannel-52: > > > > > > > >> > > > > > > > >> > Created socket with SO_TIMEOUT = 10000 > > > > (requested > > > > > > > >> 10000), > > > > > > > >> > > > > > SO_RCVBUF > > > > > > > >> > > > > > > = > > > > > > > >> > > > > > > > >> > 187200 (requested -1), SO_SNDBUF = 102400 > > > > > > (requested > > > > > > > >> > > 102400). > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,231 main INFO > > > > > > > >> > > > > > kafka.producer.SyncProducer-68: > > > > > > > >> > > > > > > > >> > Connected to 54.215.200.61:9092 for > > > producing > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,256 main INFO > > > > > > > >> > > > > > kafka.producer.SyncProducer-68: > > > > > > > >> > > > > > > > >> > Disconnecting from 54.215.200.61:9092 > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,256 main DEBUG > > > > > > > >> > > > > kafka.client.ClientUtils$-52: > > > > > > > >> > > > > > > > >> > Successfully fetched metadata for 1 > > topic(s) > > > > > > > Set(Test) > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,257 main WARN > > > > > > > >> > > > > > > > >> kafka.producer.BrokerPartitionInfo-83: > > > > > > > >> > > > > > > > >> > Error while fetching metadata > > [{TopicMetadata > > > > for > > > > > > > topic > > > > > > > >> > Test > > > > > > > >> > > > -> > > > > > > > >> > > > > > > > >> > No partition metadata for topic Test due > to > > > > > > > >> > > > > > > > >> > > kafka.common.LeaderNotAvailableException}] > > > for > > > > > > topic > > > > > > > >> > [Test]: > > > > > > > >> > > > > class > > > > > > > >> > > > > > > > >> > kafka.common.LeaderNotAvailableException > > > > > > > >> > > > > > > > >> > 2014-10-24 14:31:47,258 main ERROR > > > > > > > >> > > > > > > > >> > > > kafka.producer.async.DefaultEventHandler-97: > > > > > Failed > > > > > > > to > > > > > > > >> > > collate > > > > > > > >> > > > > > > > messages > > > > > > > >> > > > > > > > >> by > > > > > > > >> > > > > > > > >> > topic, partition due to: Failed to fetch > > > topic > > > > > > > metadata > > > > > > > >> > for > > > > > > > >> > > > > topic: > > > > > > > >> > > > > > > > Test > > > > > > > >> > > > > > > > >> > > > > > > > > >> > > > > > > > >> > On Fri, Oct 24, 2014 at 1:11 PM, Guozhang > > > Wang > > > > < > > > > > > > >> > > > > > wangg...@gmail.com> > > > > > > > >> > > > > > > > >> wrote: > > > > > > > >> > > > > > > > >> > > > > > > > > >> > > > > > > > >> > > Could you see if this is the case: > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > > > > > > > >> > > > > > > > > > > > >> > > > > > > > > > > >> > > > > > > > > > >> > > > > > > > > >> > > > > > > > > > > > > > > > > > > > > > > > > > > > > https://cwiki.apache.org/confluence/display/KAFKA/FAQ#FAQ-Whycan%27tmyconsumers/producersconnecttothebrokers > > > > > > > >> > > > > > > > >> > > ? > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > On Fri, Oct 24, 2014 at 11:35 AM, > Sameer > > > > Yami < > > > > > > > >> > > > > sy...@ailive.net > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > > >> wrote: > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > > Hi, > > > > > > > >> > > > > > > > >> > > > > > > > > > > >> > > > > > > > >> > > > We have a Kafka / Zookeeper test > setup > > > on a > > > > > > > single > > > > > > > >> EC2 > > > > > > > >> > > > > > machine. > > > > > > > >> > > > > > > > The > > > > > > > >> > > > > > > > >> > > > host.name is the private ip address > > and > > > > the > > > > > > > >> > > > > > > advertised.host.name > > > > > > > >> > > > > > > > is > > > > > > > >> > > > > > > > >> > the > > > > > > > >> > > > > > > > >> > > > public address in server.properties. > > > > > > > >> > > > > > > > >> > > > > > > > > > > >> > > > > > > > >> > > > We are trying to publish from outside > > EC2 > > > > > using > > > > > > > the > > > > > > > >> > > public > > > > > > > >> > > > > ip > > > > > > > >> > > > > > of > > > > > > > >> > > > > > > > the > > > > > > > >> > > > > > > > >> > EC2 > > > > > > > >> > > > > > > > >> > > > machine but get this error on the > > client > > > > > side - > > > > > > > >> > > > > > > > >> > > > No partition metadata for topic test > > due > > > to > > > > > > > >> > > > > > > > >> > > > > > > kafka.common.LeaderNotAvailableException}] > > > > > for > > > > > > > >> topic > > > > > > > >> > > > [test]: > > > > > > > >> > > > > > > class > > > > > > > >> > > > > > > > >> > > > > > kafka.common.LeaderNotAvailableException > > > > > > > >> > > > > > > > >> > > > > > > > > > > >> > > > > > > > >> > > > The zookeeper has the public ip > stored > > in > > > > > > > >> > > /brokers/ids/0. > > > > > > > >> > > > > > > > >> > > > We have tried multiple combinations > but > > > it > > > > > > works > > > > > > > >> ONLY > > > > > > > >> > > when > > > > > > > >> > > > > the > > > > > > > >> > > > > > > > >> > advertised > > > > > > > >> > > > > > > > >> > > > host name is not used and the client > is > > > > > > internal > > > > > > > to > > > > > > > >> > EC2. > > > > > > > >> > > > > > > > >> > > > > > > > > > > >> > > > > > > > >> > > > Please let me know what the problem > > could > > > > be. > > > > > > > >> > > > > > > > >> > > > > > > > > > > >> > > > > > > > >> > > > thanks > > > > > > > >> > > > > > > > >> > > > Sameer > > > > > > > >> > > > > > > > >> > > > > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > -- > > > > > > > >> > > > > > > > >> > > -- Guozhang > > > > > > > >> > > > > > > > >> > > > > > > > > > >> > > > > > > > >> > > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> -- > > > > > > > >> > > > > > > > >> -- Guozhang > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > > > > > > > > > >> > > > > > > > > > > > > > > > >> > > > > > > > > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > -- > > > > > > > >> > > > > > > -- Guozhang > > > > > > > >> > > > > > > > > > > > > > >> > > > > > > > > > > > > >> > > > > > > > > > > > >> > > > > > > > > > > >> > > > > > > > > > >> > > > > > > > > > >> > > > > > > > > > >> > > -- > > > > > > > >> > > -- Guozhang > > > > > > > >> > > > > > > > > > >> > > > > > > > > >> > > > > > > > >> > > > > > > > >> > > > > > > > >> -- > > > > > > > >> -- Guozhang > > > > > > > >> > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > -- > > > > > > -- Guozhang > > > > > > > > > > > > > > > > > > > > > > > > > > > -- > > > > -- Guozhang > > > > > > > > > > > > > > > -- > > -- Guozhang > > > -- -- Guozhang