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
>>
>
>
