kafka-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Simon Cooper <simon.coo...@featurespace.co.uk>
Subject SimpleConsumer long poll test case randomly times out
Date Wed, 07 May 2014 14:30:11 GMT
I've got a very strange bug doing a long poll using SimpleConsumer on 0.8.1.1. The test app
I've got (attached) uses a thread to do a long poll of a topic, and then sends single messages
to that queue, one at a time, waiting for the poll to return the message before sending the
next one.

The problem is that when a message is sent to the queue, the long poll returns immediately,
but that does not contain the just-sent message. So the long poll restarts. Sometime this
second poll returns immediately with the sent message, but sometimes it waits for the poll
to timeout before returning the message. This second behaviour happens much more on a replicated
topic, but is also reproducible with the test VMs on https://github.com/stealthly/scala-kafka.

A sample log file is below. The long poll timeout is 5000ms. Messages 1 and 2 are delayed,
messages 0 and 2 aren't. Every message requires two polls to actually be received:

410 [pool-1-thread-1] INFO Making request from offset 110
1457 [main] INFO Sending 0
1553 [pool-1-thread-1] WARN Received no messages
1553 [pool-1-thread-1] INFO Making request from offset 110
1560 [pool-1-thread-1] INFO Received 0
1561 [pool-1-thread-1] INFO Making request from offset 111
1561 [main] INFO Got response for 0 in 20ms
1561 [main] INFO Sending 1
1565 [pool-1-thread-1] WARN Received no messages
1565 [pool-1-thread-1] INFO Making request from offset 111
6567 [pool-1-thread-1] INFO Received 1
6567 [pool-1-thread-1] INFO Making request from offset 112
6568 [main] INFO Got response for 1 in 5004ms
6568 [main] INFO Sending 2
6574 [pool-1-thread-1] WARN Received no messages
6574 [pool-1-thread-1] INFO Making request from offset 112
11577 [pool-1-thread-1] INFO Received 2
11577 [pool-1-thread-1] INFO Making request from offset 113
11578 [main] INFO Got response for 2 in 5006ms
11578 [main] INFO Sending 3
11584 [pool-1-thread-1] WARN Received no messages
11584 [pool-1-thread-1] INFO Making request from offset 113
11585 [pool-1-thread-1] INFO Received 3
11586 [pool-1-thread-1] INFO Making request from offset 114
11586 [main] INFO Got response for 3 in 5ms

Ideally, the message sent would be returned immediately by the first long poll. But the obvious
bug is the artificial delay introduced by the message not being returned until the long poll
times out, when it should return immediately (as the minimum message size is 1 byte, and there's
a 4 byte message available).

This looks like a bug in kafka, but I may be using the consumer API incorrectly...

Thanks,
SimonC
Mime
  • Unnamed multipart/mixed (inline, None, 0 bytes)
View raw message