Looks fine on the broker. The data is just not being returned from the call to SimpleConsumer.
[2013-07-19 11:22:09,426] DEBUG Processor 0 listening to new connection from /127.0.0.1:58809 (kafka.network.Processor) [2013-07-19 11:22:09,426] DEBUG Processor 1 listening to new connection from /127.0.0.1:58810 (kafka.network.Processor) [2013-07-19 11:22:09,462] TRACE Processor id 1 selection time = 36 ms (kafka.network.Processor) [2013-07-19 11:22:09,462] TRACE 26 bytes read from /127.0.0.1:58810(kafka.network.Processor) [2013-07-19 11:22:09,463] TRACE Processor id 0 selection time = 37 ms (kafka.network.Processor) [2013-07-19 11:22:09,464] TRACE 26 bytes read from /127.0.0.1:58809(kafka.network.Processor) [2013-07-19 11:22:09,470] TRACE Processor id 1 selection time = 5 ms (kafka.network.Processor) [2013-07-19 11:22:09,470] TRACE Socket server received response to send, registering for write: Response(1,Request(1,sun.nio.ch.SelectionKeyImpl@62d9f20a ,null,1374258129462,/127.0.0.1:58810 ),kafka.network.BoundedByteBufferSend@715fcf90) (kafka.network.Processor) [2013-07-19 11:22:09,470] TRACE Processor id 1 selection time = 0 ms (kafka.network.Processor) [2013-07-19 11:22:09,471] TRACE 106 bytes written to /127.0.0.1:58810 using key sun.nio.ch.SelectionKeyImpl@62d9f20a (kafka.network.Processor) [2013-07-19 11:22:09,471] TRACE Finished writing, registering for read on connection /127.0.0.1:58810 (kafka.network.Processor) [2013-07-19 11:22:09,474] TRACE Processor id 0 selection time = 1 ms (kafka.network.Processor) [2013-07-19 11:22:09,476] TRACE Socket server received response to send, registering for write: Response(0,Request(0,sun.nio.ch.SelectionKeyImpl@5f4b2eb1 ,null,1374258129464,/127.0.0.1:58809 ),kafka.network.BoundedByteBufferSend@49343116) (kafka.network.Processor) [2013-07-19 11:22:09,477] TRACE Processor id 0 selection time = 0 ms (kafka.network.Processor) [2013-07-19 11:22:09,477] TRACE 106 bytes written to /127.0.0.1:58809 using key sun.nio.ch.SelectionKeyImpl@5f4b2eb1 (kafka.network.Processor) [2013-07-19 11:22:09,478] TRACE Finished writing, registering for read on connection /127.0.0.1:58809 (kafka.network.Processor) [2013-07-19 11:22:09,496] TRACE Processor id 0 selection time = 18 ms (kafka.network.Processor) [2013-07-19 11:22:09,496] TRACE Processor id 1 selection time = 24 ms (kafka.network.Processor) [2013-07-19 11:22:09,496] INFO Closing socket connection to /127.0.0.1. (kafka.network.Processor) [2013-07-19 11:22:09,496] DEBUG Closing connection from /127.0.0.1:58809(kafka.network.Processor) [2013-07-19 11:22:09,497] INFO Closing socket connection to /127.0.0.1. (kafka.network.Processor) [2013-07-19 11:22:09,497] DEBUG Closing connection from /127.0.0.1:58810(kafka.network.Processor) On Jul 19, 2013 9:40 AM, "Jay Kreps" <jay.kr...@gmail.com> wrote: > Interesting. Could you try turning on trace level logging on the broker and > reproduce? Or, if you have a reproducible test case I can take a look. > > We haven't hit this yet in our production usage. > > -Jay > > > On Thu, Jul 18, 2013 at 10:00 PM, Benjamin Black <b...@b3k.us> wrote: > > > Using Kafka 0.8 (current as of a few hours ago), I am seeing metadata > > requests using SimpleConsumer hang. Log below, and the call never returns > > or times out. Broker is working and passing traffic for other clients. > > Anyone else seeing this? > > > > > DEBUG [2013-07-19 04:13:34,779] kafka.network.BlockingChannel: Created > > socket with SO_TIMEOUT = 5000 (requested 5000), SO_RCVBUF = 65328 > > (requested 65000), SO_SNDBUF = 81660 (requested -1). > > > TRACE [2013-07-19 04:13:34,790] kafka.network.BoundedByteBufferSend: 30 > > bytes written. > > > TRACE [2013-07-19 04:13:37,168] kafka.network.BoundedByteBufferReceive: > > 98 bytes read. > > > > > >
