You are missing the jopt-simple jar. Thanks,
Jun On Wed, May 8, 2013 at 11:03 PM, Rob Withers <reefed...@gmail.com> wrote: > 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 > >