kafka-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Rob Withers" <reefed...@gmail.com>
Subject [0.8] exception running on windows when attempting to send to an uncreated topic
Date Thu, 09 May 2013 06:03:43 GMT
I am running on windows.  I am programmatically (no scripts) starting a zk,
2 brokers, 2 consumers and a producer, in this order but the first 3 at
once, then the other 3 at once, all with a nonexistent topic.

 

Here's the pertinent log for the producer (with other stuff mixed in, no
doubt):

 

start production: com.dish.des.msgs.notifications.StartProduction@d27b1b3

{2013-05-08 23:53:07,187}  INFO [local-vat] (Logging.scala:67) - Fetching
metadata with correlation id 0 for 1 topic(s) Set(robert_v_2x0)

{2013-05-08 23:53:07,206} DEBUG [local-vat] (Logging.scala:51) - Created
socket with SO_TIMEOUT = 1500 (requested 1500), SO_RCVBUF = 8192 (requested
-1), SO_SNDBUF = 102400 (requested 102400).

{2013-05-08 23:53:07,207} DEBUG [kafka-acceptor] (Logging.scala:51) -
Accepted connection from /127.0.0.1 on /127.0.0.1:9092. sendBufferSize
[actual|requested]: [1048576|1048576] recvBufferSize [actual|requested]:
[1048576|1048576]

{2013-05-08 23:53:07,208} DEBUG [kafka-processor-9092-0] (Logging.scala:51)
- Processor 0 listening to new connection from /127.0.0.1:63245

{2013-05-08 23:53:07,209}  INFO [local-vat] (Logging.scala:67) - Connected
to localhost:9092 for producing

{2013-05-08 23:53:07,256} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87d872090002 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-08 23:53:07,256} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87d872090002 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-08 23:53:07,257} DEBUG [main-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87d872090002
after 2ms

{2013-05-08 23:53:07,279} DEBUG [kafka-request-handler-1] (Logging.scala:51)
- [Kafka Request Handler 1 on Broker 0], handles request
Request(0,sun.nio.ch.SelectionKeyImpl@1261db2b,null,1368078787227,/127.0.0.1
:63245)

{2013-05-08 23:53:07,290} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87d872090000 type:exists cxid:0x26 zxid:0xfffffffffffffffe
txntype:unknown reqpath:/brokers/topics/robert_v_2x0

{2013-05-08 23:53:07,291} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87d872090000 type:exists
cxid:0x26 zxid:0xfffffffffffffffe txntype:unknown
reqpath:/brokers/topics/robert_v_2x0

{2013-05-08 23:53:07,293} DEBUG [Thread-1-SendThread(localhost:2181)]
(ClientCnxn.java:838) - Reading reply sessionid:0x13e87d872090000, packet::
clientPath:null serverPath:null finished:false header:: 38,3  replyHeader::
38,955,-101  request:: '/brokers/topics/robert_v_2x0,F  response::  

{2013-05-08 23:53:07,373} ERROR [kafka-request-handler-1]
(Logging.scala:102) - [KafkaApi-0] Error while retrieving topic metadata

java.lang.NoClassDefFoundError: joptsimple/OptionSpec

       at
kafka.server.KafkaApis$$anonfun$handleTopicMetadataRequest$1.apply(KafkaApis
.scala:411)

       at
kafka.server.KafkaApis$$anonfun$handleTopicMetadataRequest$1.apply(KafkaApis
.scala:403)

       at scala.collection.immutable.Set$Set1.foreach(Set.scala:81)

       at
kafka.server.KafkaApis.handleTopicMetadataRequest(KafkaApis.scala:402)

       at kafka.server.KafkaApis.handle(KafkaApis.scala:63)

       at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:41)

       at java.lang.Thread.run(Thread.java:722)

Caused by: java.lang.ClassNotFoundException: joptsimple.OptionSpec

       at java.net.URLClassLoader$1.run(URLClassLoader.java:366)

       at java.net.URLClassLoader$1.run(URLClassLoader.java:355)

       at java.security.AccessController.doPrivileged(Native Method)

       at java.net.URLClassLoader.findClass(URLClassLoader.java:354)

       at java.lang.ClassLoader.loadClass(ClassLoader.java:423)

       at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)

       at java.lang.ClassLoader.loadClass(ClassLoader.java:356)

       ... 7 more

{2013-05-08 23:53:07,388} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87d872090003 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-08 23:53:07,393} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87d872090003 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-08 23:53:07,395} DEBUG [main-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87d872090003
after 8ms

{2013-05-08 23:53:07,557}  INFO [local-vat] (Logging.scala:67) -
Disconnecting from localhost:9092

{2013-05-08 23:53:07,570} DEBUG [local-vat] (Logging.scala:51) -
Successfully fetched metadata for 1 topic(s) Set(robert_v_2x0)

{2013-05-08 23:53:07,583} DEBUG [local-vat] (Logging.scala:51) - Getting
broker partition info for topic robert_v_2x0

{2013-05-08 23:53:07,600}  INFO [local-vat] (Logging.scala:67) - Fetching
metadata with correlation id 1 for 1 topic(s) Set(robert_v_2x0)

{2013-05-08 23:53:07,605} DEBUG [kafka-acceptor] (Logging.scala:51) -
Accepted connection from /127.0.0.1 on /127.0.0.1:9092. sendBufferSize
[actual|requested]: [1048576|1048576] recvBufferSize [actual|requested]:
[1048576|1048576]

{2013-05-08 23:53:07,606} DEBUG [kafka-processor-9092-1] (Logging.scala:51)
- Processor 1 listening to new connection from /127.0.0.1:63248

{2013-05-08 23:53:07,588}  INFO [kafka-processor-9092-0] (Logging.scala:67)
- Closing socket connection to /127.0.0.1.

{2013-05-08 23:53:07,609} DEBUG [kafka-processor-9092-0] (Logging.scala:51)
- Closing connection from /127.0.0.1:63245

{2013-05-08 23:53:07,606} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87d872090001 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-08 23:53:07,618} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87d872090001 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-08 23:53:07,606} DEBUG [local-vat] (Logging.scala:51) - Created
socket with SO_TIMEOUT = 1500 (requested 1500), SO_RCVBUF = 8192 (requested
-1), SO_SNDBUF = 102400 (requested 102400).

{2013-05-08 23:53:07,620}  INFO [local-vat] (Logging.scala:67) - Connected
to localhost:9092 for producing

{2013-05-08 23:53:07,622} DEBUG [Thread-2-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87d872090001
after 37ms

{2013-05-08 23:53:07,623} DEBUG [kafka-request-handler-0] (Logging.scala:51)
- [Kafka Request Handler 0 on Broker 0], handles request
Request(1,sun.nio.ch.SelectionKeyImpl@81331d5,null,1368078787622,/127.0.0.1:
63248)

{2013-05-08 23:53:07,626} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87d872090000 type:exists cxid:0x27 zxid:0xfffffffffffffffe
txntype:unknown reqpath:/brokers/topics/robert_v_2x0

{2013-05-08 23:53:07,626} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87d872090000 type:exists
cxid:0x27 zxid:0xfffffffffffffffe txntype:unknown
reqpath:/brokers/topics/robert_v_2x0

{2013-05-08 23:53:07,629} DEBUG [Thread-1-SendThread(localhost:2181)]
(ClientCnxn.java:838) - Reading reply sessionid:0x13e87d872090000, packet::
clientPath:null serverPath:null finished:false header:: 39,3  replyHeader::
39,955,-101  request:: '/brokers/topics/robert_v_2x0,F  response::  

{2013-05-08 23:53:07,632} ERROR [kafka-request-handler-0]
(Logging.scala:102) - [KafkaApi-0] Error while retrieving topic metadata

java.lang.NoClassDefFoundError: joptsimple/OptionSpec

       at
kafka.server.KafkaApis$$anonfun$handleTopicMetadataRequest$1.apply(KafkaApis
.scala:411)

       at
kafka.server.KafkaApis$$anonfun$handleTopicMetadataRequest$1.apply(KafkaApis
.scala:403)

       at scala.collection.immutable.Set$Set1.foreach(Set.scala:81)

       at
kafka.server.KafkaApis.handleTopicMetadataRequest(KafkaApis.scala:402)

       at kafka.server.KafkaApis.handle(KafkaApis.scala:63)

       at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:41)

       at java.lang.Thread.run(Thread.java:722)

Caused by: java.lang.ClassNotFoundException: joptsimple.OptionSpec

       at java.net.URLClassLoader$1.run(URLClassLoader.java:366)

       at java.net.URLClassLoader$1.run(URLClassLoader.java:355)

       at java.security.AccessController.doPrivileged(Native Method)

       at java.net.URLClassLoader.findClass(URLClassLoader.java:354)

       at java.lang.ClassLoader.loadClass(ClassLoader.java:423)

       at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)

       at java.lang.ClassLoader.loadClass(ClassLoader.java:356)

       ... 7 more

{2013-05-08 23:53:07,637}  INFO [local-vat] (Logging.scala:67) -
Disconnecting from localhost:9092

{2013-05-08 23:53:07,639} DEBUG [local-vat] (Logging.scala:51) -
Successfully fetched metadata for 1 topic(s) Set(robert_v_2x0)

{2013-05-08 23:53:07,639}  INFO [kafka-processor-9092-1] (Logging.scala:67)
- Closing socket connection to /127.0.0.1.

{2013-05-08 23:53:07,640} DEBUG [kafka-processor-9092-1] (Logging.scala:51)
- Closing connection from /127.0.0.1:63248

{2013-05-08 23:53:07,644} ERROR [local-vat] (Logging.scala:102) - Failed to
collate messages by topic, partition due to

kafka.common.KafkaException: Failed to fetch topic metadata for topic:
robert_v_2x0

       at
kafka.producer.BrokerPartitionInfo.getBrokerPartitionInfo(BrokerPartitionInf
o.scala:53)

       at
kafka.producer.async.DefaultEventHandler.kafka$producer$async$DefaultEventHa
ndler$$getPartitionListForTopic(DefaultEventHandler.scala:185)

       at
kafka.producer.async.DefaultEventHandler$$anonfun$partitionAndCollate$1.appl
y(DefaultEventHandler.scala:149)

       at
kafka.producer.async.DefaultEventHandler$$anonfun$partitionAndCollate$1.appl
y(DefaultEventHandler.scala:148)

       at
scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:5
7)

       at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:43)

       at
kafka.producer.async.DefaultEventHandler.partitionAndCollate(DefaultEventHan
dler.scala:148)

       at
kafka.producer.async.DefaultEventHandler.dispatchSerializedData(DefaultEvent
Handler.scala:94)

       at
kafka.producer.async.DefaultEventHandler.handle(DefaultEventHandler.scala:72
)

       at kafka.producer.Producer.send(Producer.scala:74)

       at kafka.javaapi.producer.Producer.send(Producer.scala:32)

       at
com.dish.des.kafka.KafkaTopicProducer.send(KafkaTopicProducer.java:32)

       at
com.dish.des.kafka.KafkaTopicProducer.publish(KafkaTopicProducer.java:27)

       at com.dish.des.system.TestRunProducer.send(TestRunProducer.java:48)

       at com.dish.des.system.TestRunProducer.run(TestRunProducer.java:41)

       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

       at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
)

       at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:43)

       at java.lang.reflect.Method.invoke(Method.java:601)

       at
org.reefedjib.murmur.lib.MessageSend$Sender.privateSendIt(MessageSend.java:2
59)

       at
org.reefedjib.murmur.lib.MessageSend$Sender.sendIt(MessageSend.java:245)

       at org.reefedjib.murmur.lib.MessageSend.sendIt(MessageSend.java:146)

       at org.reefedjib.murmur.lib.MessageSend.run(MessageSend.java:85)

       at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

       at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)

       at java.util.concurrent.FutureTask.run(FutureTask.java:166)

       at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$
201(ScheduledThreadPoolExecutor.java:178)

       at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Sch
eduledThreadPoolExecutor.java:292)

       at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:11
45)

       at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6
15)

       at java.lang.Thread.run(Thread.java:722)

java.lang.reflect.InvocationTargetException

       at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

       at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57
)

       at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl
.java:43)

       at java.lang.reflect.Method.invoke(Method.java:601)

       at
org.reefedjib.murmur.lib.MessageSend$Sender.privateSendIt(MessageSend.java:2
59)

       at
org.reefedjib.murmur.lib.MessageSend$Sender.sendIt(MessageSend.java:245)

       at org.reefedjib.murmur.lib.MessageSend.sendIt(MessageSend.java:146)

       at org.reefedjib.murmur.lib.MessageSend.run(MessageSend.java:85)

       at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

       at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)

       at java.util.concurrent.FutureTask.run(FutureTask.java:166)

       at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$
201(ScheduledThreadPoolExecutor.java:178)

       at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Sch
eduledThreadPoolExecutor.java:292)

       at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:11
45)

       at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:6
15)

       at java.lang.Thread.run(Thread.java:722)

Caused by: kafka.common.KafkaException: Failed to fetch topic metadata for
topic: robert_v_2x0

       at
kafka.producer.BrokerPartitionInfo.getBrokerPartitionInfo(BrokerPartitionInf
o.scala:53)

       at
kafka.producer.async.DefaultEventHandler.kafka$producer$async$DefaultEventHa
ndler$$getPartitionListForTopic(DefaultEventHandler.scala:185)

       at
kafka.producer.async.DefaultEventHandler$$anonfun$partitionAndCollate$1.appl
y(DefaultEventHandler.scala:149)

       at
kafka.producer.async.DefaultEventHandler$$anonfun$partitionAndCollate$1.appl
y(DefaultEventHandler.scala:148)

       at
scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:5
7)

       at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:43)

       at
kafka.producer.async.DefaultEventHandler.partitionAndCollate(DefaultEventHan
dler.scala:148)

       at
kafka.producer.async.DefaultEventHandler.dispatchSerializedData(DefaultEvent
Handler.scala:94)

       at
kafka.producer.async.DefaultEventHandler.handle(DefaultEventHandler.scala:72
)

       at kafka.producer.Producer.send(Producer.scala:74)

       at kafka.javaapi.producer.Producer.send(Producer.scala:32)

       at
com.dish.des.kafka.KafkaTopicProducer.send(KafkaTopicProducer.java:32)

       at
com.dish.des.kafka.KafkaTopicProducer.publish(KafkaTopicProducer.java:27)

       at com.dish.des.system.TestRunProducer.send(TestRunProducer.java:48)

       at com.dish.des.system.TestRunProducer.run(TestRunProducer.java:41)

       ... 16 more

 

 

This is followed by nothing but:

 

{2013-05-09 00:01:10,399} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87e0a6800001 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:10,399} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87e0a6800001 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:10,401} DEBUG [Thread-2-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87e0a6800001
after 2ms

{2013-05-09 00:01:10,838} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87e0a6800002 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:10,839} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87e0a6800002 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:10,842} DEBUG [main-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87e0a6800002
after 5ms

{2013-05-09 00:01:10,953} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87e0a6800003 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:10,956} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87e0a6800003 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:10,957} DEBUG [main-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87e0a6800003
after 8ms

{2013-05-09 00:01:11,288} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87e0a6800000 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:11,289} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87e0a6800000 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:11,289} DEBUG [Thread-1-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87e0a6800000
after 2ms

{2013-05-09 00:01:11,743} DEBUG [kafka-logflusher-1] (Logging.scala:51) -
[Log Manager on Broker 1] Checking for dirty logs to flush...

{2013-05-09 00:01:12,082} DEBUG [kafka-logflusher-1] (Logging.scala:51) -
[Log Manager on Broker 0] Checking for dirty logs to flush...

{2013-05-09 00:01:12,400} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87e0a6800001 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:12,400} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87e0a6800001 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:12,401} DEBUG [Thread-2-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87e0a6800001
after 2ms

{2013-05-09 00:01:12,838} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:78) - Processing request::
sessionid:0x13e87e0a6800002 type:ping cxid:0xfffffffffffffffe
zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:12,839} DEBUG [SyncThread:0]
(FinalRequestProcessor.java:160) - sessionid:0x13e87e0a6800002 type:ping
cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a

{2013-05-09 00:01:12,840} DEBUG [main-SendThread(localhost:2181)]
(ClientCnxn.java:758) - Got ping response for sessionid: 0x13e87e0a6800002
after 3ms

 

 

thanks,

rob


Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message