Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

auto.offset.reset to largest not working #607

Closed
jose9r opened this issue Apr 12, 2016 · 26 comments
Closed

auto.offset.reset to largest not working #607

jose9r opened this issue Apr 12, 2016 · 26 comments

Comments

@jose9r
Copy link

jose9r commented Apr 12, 2016

Hi, im using kafka with this library and php-rdkafka from https://github.com/arnaud-lb/php-rdkafka/ , and when i create a KafkaConsumer with a new group with setDefaultTopicConf including auto.offset.reset to largest, and i cant consume new messages, there is an error with commit i supose (auto.commit is enable). The debug output with topic,fetch options is here:

%7|1460457919.173|TOPIC|rdkafka#consumer-1| New local topic: queueTest
%7|1460457919.173|DESP|rdkafka#consumer-1| Adding desired topic queueTest [0]
%7|1460457919.173|FETCHSTART|rdkafka#consumer-1| List with 1 partition(s):
%7|1460457919.173|FETCHSTART|rdkafka#consumer-1| queueTest [0] offset INVALID
%7|1460457919.173|OFFSET|rdkafka#consumer-1| 10.0.0.203:9092/1: OffsetFetchRequest(v1) for 1/1 partition(s)
%7|1460457919.273|OFFSETFETCH|rdkafka#consumer-1| List with 1 partition(s):
%7|1460457919.273|OFFSETFETCH|rdkafka#consumer-1| queueTest [0] offset INVALID
%7|1460457919.273|OFFSET|rdkafka#consumer-1| Topic queueTest [0]: setting default offset INVALID
%7|1460457919.273|OFFSETFETCH|rdkafka#consumer-1| 10.0.0.203:9092/1: OffsetFetchResponse: queueTest [0] offset -1
%7|1460457919.273|OFFFETCH|rdkafka#consumer-1| 10.0.0.203:9092/1: OffsetFetch for 1/1 partition(s) returned Success
%7|1460457919.273|FETCHSTART|rdkafka#consumer-1| List with 1 partition(s):
%7|1460457919.273|FETCHSTART|rdkafka#consumer-1| queueTest [0] offset INVALID
%7|1460457919.273|FETCH|rdkafka#consumer-1| Start fetch for queueTest [0] in state none at offset INVALID (v2)
%7|1460457919.273|PARTSTATE|rdkafka#consumer-1| Partition queueTest [0] changed fetch state none -> offset-query
%7|1460457919.273|OFFSET|rdkafka#consumer-1| queueTest [0]: offset reset (at offset INVALID) to END: no previously committed offset available: Local: No offset stored
%7|1460457919.273|OFFSET|rdkafka#consumer-1| queueTest [0]: no current leader for partition, starting offset query timer for offset END
%7|1460457919.773|OFFSET|rdkafka#consumer-1| Topic queueTest [0]: timed offset query for END in state offset-query
%7|1460457919.773|OFFSET|rdkafka#consumer-1| queueTest [0]: no current leader for partition, starting offset query timer for offset END
%7|1460457919.957|STATE|rdkafka#consumer-1| Topic queueTest changed state unknown -> exists
%7|1460457919.957|PARTCNT|rdkafka#consumer-1| Topic queueTest partition count changed from 0 to 1
%7|1460457919.957|BRKDELGT|rdkafka#consumer-1| Broker 10.0.0.203:9092/1 is now leader for topic queueTest [0] with 0 messages (0 bytes) queued
%7|1460457919.957|BRKMIGR|rdkafka#consumer-1| Migrating topic queueTest [0] from (none) to 10.0.0.203:9092/1
%7|1460457919.957|METADATA|rdkafka#consumer-1| 10.0.0.203:9092/1: Requested topic queueTest seen in metadata
%7|1460457920.057|TOPBRK|rdkafka#consumer-1| 10.0.0.203:9092/1: Topic queueTest [0]: joining broker
%7|1460457920.273|OFFSET|rdkafka#consumer-1| Topic queueTest [0]: timed offset query for END in state offset-query
%7|1460457920.273|OFFREQ|rdkafka#consumer-1| 10.0.0.203:9092/1: Partition queueTest [0]: querying for logical offset END (opv 2)
%7|1460457920.273|OFFSET|rdkafka#consumer-1| 10.0.0.203:9092/1: OffsetRequest (1 offsets) for topic queueTest 0
%7|1460457920.273|PARTSTATE|rdkafka#consumer-1| Partition queueTest [0] changed fetch state offset-query -> offset-wait
%7|1460457920.360|OFFSET|rdkafka#consumer-1| Offset END request for queueTest [0] returned offset 4 (4)
%7|1460457920.360|PARTSTATE|rdkafka#consumer-1| Partition queueTest [0] changed fetch state offset-wait -> active
%7|1460457920.460|FETCHDEC|rdkafka#consumer-1| Topic queueTest [0]: fetch decide: updating to version 3 (was 0) at offset 4 (was 0)
%7|1460457920.460|FETCH|rdkafka#consumer-1| 10.0.0.203:9092/1: Topic queueTest [0] at offset 4 (0/100000 msgs, 0/1000000 kb queued) is fetchable:
%7|1460457920.460|FETCHADD|rdkafka#consumer-1| 10.0.0.203:9092/1: Added queueTest [0] to fetch list (1 entries, opv 3)
%7|1460457920.460|FETCH|rdkafka#consumer-1| 10.0.0.203:9092/1: Fetch topic queueTest [0] at offset 4 (v3)
%7|1460457920.460|FETCH|rdkafka#consumer-1| 10.0.0.203:9092/1: Fetch 1/1/1 toppar(s)
%7|1460457920.660|PAUSE|rdkafka#consumer-1| Library pausing 1 partition(s)
%7|1460457920.660|PAUSE|rdkafka#consumer-1| Pause queueTest [0]: at offset INVALID
%7|1460457920.660|OFFSET|rdkafka#consumer-1| Topic queueTest [0]: stored off -1001, committted off -1001
%7|1460457920.660|OFFSET|rdkafka#consumer-1| Topic queueTest [0]:

teamcity[testFinishedsetting offset INVALID for commit

%7|1460457920.660|FETCH|rdkafka#consumer-1| Stopping fetch for queueTest [0] in state active (v5)
%7|1460457920.660|PARTSTATE|rdkafka#consumer-1| Partition queueTest [0] changed fetch state active -> stopping
%7|1460457920.660|PARTSTATE|rdkafka#consumer-1| Partition queueTest [0] changed fetch state stopping -> stopped
%7|1460457920.660|DESP|rdkafka#consumer-1| Removing (un)desired topic queueTest [0]
%7|1460457920.660|RESUME|rdkafka#consumer-1| Library resuming 1 partition(s)
%7|1460457920.660|RESUME|rdkafka#consumer-1| Resume queueTest [0]: at offset INVALID
%7|1460457920.660|CONSUMER|rdkafka#consumer-1| Seek queueTest [0] to offset INVALID
%7|1460457920.660|DESTROY|rdkafka#consumer-1| Terminating instance
%7|1460457920.660|OP|rdkafka#consumer-1| queueTest [0] received op SEEK (v0) in fetch-state stopped
%7|1460457920.660|FETCH|rdkafka#consumer-1| Seek queueTest [0] to offset INVALID in state stopped (v7)
%7|1460457920.660|DESTROY|rdkafka#consumer-1| Destroy internal
%7|1460457920.660|DESTROY|rdkafka#consumer-1| Remove all topics
%7|1460457920.660|PARTCNT|rdkafka#consumer-1| Topic queueTest partition count changed from 1 to 0
%7|1460457920.660|BRKDELGT|rdkafka#consumer-1| Broker 10.0.0.203:9092/1 no longer leader for topic queueTest [0]
%7|1460457920.660|BRKDELGT|rdkafka#consumer-1| No broker is leader for topic queueTest [0]
%7|1460457920.660|BRKMIGR|rdkafka#consumer-1| Migrating topic queueTest [0] from 10.0.0.203:9092/1 to (none)
%7|1460457920.660|TOPPARREMOVE|rdkafka#consumer-1| Removing toppar queueTest [-1]
%7|1460457920.661|FETCH|rdkafka#consumer-1| 10.0.0.203:9092/1: Topic queueTest [0] at offset INVALID (0/100000 msgs, 0/1000000 kb queued) is not fetchable: not in active fetch state
%7|1460457920.661|FETCHADD|rdkafka#consumer-1| 10.0.0.203:9092/1: Removed queueTest [0] from fetch list (0 entries, opv 3)
%7|1460457920.661|TOPBRK|rdkafka#consumer-1| 10.0.0.203:9092/1: Topic queueTest [0]: leaving broker (next leader (none))
%7|1460457920.661|TOPPARREMOVE|rdkafka#consumer-1| Removing toppar queueTest [0]

@edenhill
Copy link
Contributor

Can you paste your setup code? (config and creating the consumer)

@jose9r
Copy link
Author

jose9r commented Apr 13, 2016

   $conf = new Conf();
    $conf->set("group.id", "groupTest");
    $conf->set("offset.store.method", "broker");
    $conf->set("metadata.broker.list", "10.0.0.203:9092");
    $conf->set("debug", "topic,fetch");
    $topicConf = new TopicConf();
    $topicConf->set("auto.offset.reset", "largest");
    $conf->setDefaultTopicConf($topicConf);
    $consumer = new KafkaConsumer($conf);
    $consumer->subscribe(["queueTest"]);
    $msg = $consumer->consume(3600e3);

@edenhill
Copy link
Contributor

You have 4 messages in queueTest 0 and the consumer starts reading at the end (since you have auto.offset.reset=largest) so you will not see any messages.
You will need to produce new messages to the topic to see new messages.

@jose9r
Copy link
Author

jose9r commented Apr 13, 2016

I produce new messages, but its the same problem because last commited offset for the first time is invalid and when i try to consume these messages and fetch for the offset is invalid, and finally set committted offset to -1001 and setting offset INVALID for commit, like the first time.

@arnaud-lb
Copy link
Contributor

@jose9r You may want to try to publish messages while the script is running. That way, you will receive the messages, and also save a valid offset. Alternatively, auto.offset.reset=smallest would allow to consume messages from the beginning when you haven't consumed any message from the topic, and to start from the saved offset the next time.

@edenhill
Copy link
Contributor

@jose9r Any luck with this?

@jose9r
Copy link
Author

jose9r commented Apr 15, 2016

@edenhill no, the problem with the offset continues

@edenhill
Copy link
Contributor

So even though you are producing new messages for the given partitions while the consumer is running no new messages are showing up in the consumer?

@jose9r
Copy link
Author

jose9r commented Apr 15, 2016

@edenhill exactly!

@edenhill
Copy link
Contributor

Okay, can you run your program with debug=topic,fetch and provide the logs, commenting where in the logs you are starting to produce new messages?
Thanks

@edenhill
Copy link
Contributor

Which librdkafka version are you on? You should be using latest master

@jose9r
Copy link
Author

jose9r commented Apr 15, 2016

I have commit version e32127b (7 April). I'm going to test with latest master.

@jose9r
Copy link
Author

jose9r commented Apr 15, 2016

With latest master, executing with a breakpoint on consume, and meanwhile producing new message:
%7|1460708505.875|TOPIC|rdkafka#consumer-2| New local topic: queueTest
%7|1460708505.875|DESP|rdkafka#consumer-2| Adding desired topic queueTest [0]
%7|1460708505.875|FETCHSTART|rdkafka#consumer-2| List with 1 partition(s):
%7|1460708505.876|FETCHSTART|rdkafka#consumer-2| queueTest [0] offset INVALID
%7|1460708505.876|OFFSET|rdkafka#consumer-2| 10.0.0.208:9092/2: OffsetFetchRequest(v1) for 1/1 partition(s)
%7|1460708505.976|OFFSETFETCH|rdkafka#consumer-2| List with 1 partition(s):
%7|1460708505.976|OFFSETFETCH|rdkafka#consumer-2| queueTest [0] offset INVALID
%7|1460708505.976|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: setting default offset INVALID
%7|1460708505.976|OFFSETFETCH|rdkafka#consumer-2| 10.0.0.208:9092/2: OffsetFetchResponse: queueTest [0] offset -1
%7|1460708505.976|OFFFETCH|rdkafka#consumer-2| 10.0.0.208:9092/2: OffsetFetch for 1/1 partition(s) returned Success
%7|1460708505.976|FETCHSTART|rdkafka#consumer-2| List with 1 partition(s):
%7|1460708505.976|FETCHSTART|rdkafka#consumer-2| queueTest [0] offset INVALID
%7|1460708505.976|FETCH|rdkafka#consumer-2| Start fetch for queueTest [0] in state none at offset INVALID (v2)
%7|1460708505.976|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state none -> offset-query
%7|1460708505.976|OFFSET|rdkafka#consumer-2| queueTest [0]: offset reset (at offset INVALID) to END: no previously committed offset available: Local: No offset stored
%7|1460708505.976|OFFSET|rdkafka#consumer-2| queueTest [0]: no current leader for partition, starting offset query timer for offset END
%7|1460708506.275|STATE|rdkafka#consumer-2| Topic queueTest changed state unknown -> exists
%7|1460708506.275|PARTCNT|rdkafka#consumer-2| Topic queueTest partition count changed from 0 to 1
%7|1460708506.275|BRKDELGT|rdkafka#consumer-2| Broker 10.0.0.209:9092/3 is now leader for topic queueTest [0] with 0 messages (0 bytes) queued
%7|1460708506.275|BRKMIGR|rdkafka#consumer-2| Migrating topic queueTest [0] from (none) to 10.0.0.209:9092/3
%7|1460708506.275|METADATA|rdkafka#consumer-2| 10.0.0.203:9092/1: Requested topic queueTest seen in metadata
%7|1460708506.276|TOPBRK|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0]: joining broker
%7|1460708506.476|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: timed offset query for END in state offset-query
%7|1460708506.476|OFFREQ|rdkafka#consumer-2| 10.0.0.209:9092/3: Partition queueTest [0]: querying for logical offset END (opv 2)
%7|1460708506.476|OFFSET|rdkafka#consumer-2| 10.0.0.209:9092/3: OffsetRequest (1 offsets) for topic queueTest 0
%7|1460708506.476|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state offset-query -> offset-wait
%7|1460708506.477|OFFSET|rdkafka#consumer-2| Offset END request for queueTest [0] returned offset 9 (9)
%7|1460708506.477|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state offset-wait -> active
%7|1460708506.577|FETCHDEC|rdkafka#consumer-2| Topic queueTest [0]: fetch decide: updating to version 3 (was 0) at offset 9 (was 0)
%7|1460708506.577|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0] at offset 9 (0/100000 msgs, 0/1000000 kb queued) is fetchable:
%7|1460708506.577|FETCHADD|rdkafka#consumer-2| 10.0.0.209:9092/3: Added queueTest [0] to fetch list (1 entries, opv 3)
%7|1460708506.577|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708506.577|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.179|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.179|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.279|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.279|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.380|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.380|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.481|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.481|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.582|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.582|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.682|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.682|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.783|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.783|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.884|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.884|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708507.984|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708507.984|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.085|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.085|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.185|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.185|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.286|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.286|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.387|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.387|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.488|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.488|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.588|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.588|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.689|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.689|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.790|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.790|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.891|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.891|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708508.992|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708508.992|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.093|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.093|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.194|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.194|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.295|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.295|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.395|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.395|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.496|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.496|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.597|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.597|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.697|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.697|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.798|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.798|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708509.899|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708509.899|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.001|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.001|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.102|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.102|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.203|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.203|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.230|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: stored off -1001, committted off -1001
%7|1460708510.230|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: setting offset INVALID for commit
%7|1460708510.304|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.304|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.405|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.405|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.506|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.506|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.607|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.607|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.708|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.708|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.809|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.809|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708510.910|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708510.910|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.010|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.010|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.111|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.111|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.212|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.212|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.313|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.313|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.413|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.413|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.514|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.514|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.615|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.615|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.716|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.716|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.816|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.816|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708511.917|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708511.917|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.018|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.018|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.119|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.119|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.220|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.220|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.320|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.320|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.420|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.420|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.521|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.521|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.622|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.622|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.722|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.722|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.822|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.822|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708512.923|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708512.923|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708513.024|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708513.024|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708513.125|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708513.125|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708513.226|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708513.226|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708513.327|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708513.327|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708513.428|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 9 (v3)
%7|1460708513.428|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708513.439|CONSUME|rdkafka#consumer-2| 10.0.0.209:9092/3: Enqueue 1 messages on queueTest [0] fetch queue (qlen 1, v3)
%7|1460708513.439|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708513.439|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.039|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.039|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.140|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.140|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.240|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.240|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.341|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.341|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.443|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.443|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.544|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.544|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.645|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.645|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.744|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.744|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.845|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.845|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708514.946|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708514.946|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.047|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.047|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.147|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.147|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.230|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: stored off -1001, committted off -1001
%7|1460708515.230|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: setting offset INVALID for commit
%7|1460708515.248|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.248|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.348|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.348|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.449|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.449|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.549|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.549|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.650|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.650|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.751|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.751|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.852|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.852|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708515.953|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708515.953|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.054|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.054|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.154|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.154|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.255|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.255|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.355|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.355|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.456|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.456|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.557|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.557|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.658|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.658|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.759|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.759|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.860|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.860|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708516.961|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708516.961|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.061|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.061|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.162|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.162|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.262|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.262|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.363|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.363|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.464|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.464|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.565|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.565|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.666|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.666|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.767|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.767|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.868|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.868|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708517.969|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708517.969|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.070|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.070|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.171|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.171|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.272|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.272|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
DESTRUCT
%7|1460708518.373|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.373|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.473|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.473|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.573|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.573|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.673|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.673|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.774|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.774|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.874|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.874|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708518.975|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708518.975|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.076|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.076|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.177|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.177|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.279|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.279|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.380|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.380|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.481|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.481|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.582|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.582|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.683|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.683|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.784|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.784|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.885|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.885|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708519.986|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708519.986|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708520.086|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708520.086|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708520.187|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708520.187|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708520.230|PAUSE|rdkafka#consumer-2| Library pausing 1 partition(s)
%7|1460708520.230|PAUSE|rdkafka#consumer-2| Pause queueTest [0]: at offset INVALID
%7|1460708520.230|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: stored off -1001, committted off -1001
%7|1460708520.230|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: setting offset INVALID for commit
%7|1460708520.230|FETCH|rdkafka#consumer-2| Stopping fetch for queueTest [0] in state active (v5)
%7|1460708520.230|PARTSTATE|rd
##teamcity[testFinishedkafka#consumer-2| Partition queueTest [0] changed fetch state active -> stopping
%7|1460708520.230|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state stopping -> stopped
%7|1460708520.230|DESP|rdkafka#consumer-2| Removing (un)desired topic queueTest [0]
%7|1460708520.230|RESUME|rdkafka#consumer-2| Library resuming 1 partition(s)
%7|1460708520.230|RESUME|rdkafka#consumer-2| Resume queueTest [0]: at offset INVALID
%7|1460708520.230|CONSUMER|rdkafka#consumer-2| Seek queueTest [0] to offset INVALID
%7|1460708520.230|DESTROY|rdkafka#consumer-2| Terminating instance
%7|1460708520.230|OP|rdkafka#consumer-2| queueTest [0] received op SEEK (v0) in fetch-state stopped
%7|1460708520.230|FETCH|rdkafka#consumer-2| Seek queueTest [0] to offset INVALID in state stopped (v7)
%7|1460708520.230|DESTROY|rdkafka#consumer-2| Destroy internal
%7|1460708520.230|DESTROY|rdkafka#consumer-2| Remove all topics
%7|1460708520.230|PARTCNT|rdkafka#consumer-2| Topic queueTest partition count changed from 1 to 0
%7|1460708520.230|BRKDELGT|rdkafka#consumer-2| Broker 10.0.0.209:9092/3 no longer leader for topic queueTest [0]
%7|1460708520.230|BRKDELGT|rdkafka#consumer-2| No broker is leader for topic queueTest [0]
%7|1460708520.230|BRKMIGR|rdkafka#consumer-2| Migrating topic queueTest [0] from 10.0.0.209:9092/3 to (none)
%7|1460708520.230|TOPPARREMOVE|rdkafka#consumer-2| Removing toppar queueTest [-1]
%7|1460708520.287|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0] at offset INVALID (0/100000 msgs, 0/1000000 kb queued) is not fetchable: not in active fetch state
%7|1460708520.287|FETCHADD|rdkafka#consumer-2| 10.0.0.209:9092/3: Removed queueTest [0] from fetch list (0 entries, opv 3)
%7|1460708520.287|TOPBRK|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0]: leaving broker (next leader (none))
%7|1460708520.288|UNKTOPIC|rdkafka#consumer-2| 10.0.0.209:9092/3: Received Fetch response (error 0) for unknown topic queueTest [0]: ignoring
%7|1460708520.288|TOPPARREMOVE|rdkafka#consumer-2| Removing toppar queueTest [0]

And next execution:

%7|1460708776.919|TOPIC|rdkafka#consumer-2| New local topic: queueTest
%7|1460708776.919|DESP|rdkafka#consumer-2| Adding desired topic queueTest [0]
%7|1460708776.919|FETCHSTART|rdkafka#consumer-2| List with 1 partition(s):
%7|1460708776.919|FETCHSTART|rdkafka#consumer-2| queueTest [0] offset INVALID
%7|1460708776.919|OFFSET|rdkafka#consumer-2| 10.0.0.208:9092/2: OffsetFetchRequest(v1) for 1/1 partition(s)
%7|1460708777.019|OFFSETFETCH|rdkafka#consumer-2| List with 1 partition(s):
%7|1460708777.019|OFFSETFETCH|rdkafka#consumer-2| queueTest [0] offset INVALID
%7|1460708777.019|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: setting default offset INVALID
%7|1460708777.019|OFFSETFETCH|rdkafka#consumer-2| 10.0.0.208:9092/2: OffsetFetchResponse: queueTest [0] offset -1
%7|1460708777.019|OFFFETCH|rdkafka#consumer-2| 10.0.0.208:9092/2: OffsetFetch for 1/1 partition(s) returned Success
%7|1460708777.019|FETCHSTART|rdkafka#consumer-2| List with 1 partition(s):
%7|1460708777.019|FETCHSTART|rdkafka#consumer-2| queueTest [0] offset INVALID
%7|1460708777.019|FETCH|rdkafka#consumer-2| Start fetch for queueTest [0] in state none at offset INVALID (v2)
%7|1460708777.019|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state none -> offset-query
%7|1460708777.019|OFFSET|rdkafka#consumer-2| queueTest [0]: offset reset (at offset INVALID) to END: no previously committed offset available: Local: No offset stored
%7|1460708777.019|OFFSET|rdkafka#consumer-2| queueTest [0]: no current leader for partition, starting offset query timer for offset END
%7|1460708777.323|STATE|rdkafka#consumer-2| Topic queueTest changed state unknown -> exists
%7|1460708777.323|PARTCNT|rdkafka#consumer-2| Topic queueTest partition count changed from 0 to 1
%7|1460708777.323|BRKDELGT|rdkafka#consumer-2| Broker 10.0.0.209:9092/3 is now leader for topic queueTest [0] with 0 messages (0 bytes) queued
%7|1460708777.323|BRKMIGR|rdkafka#consumer-2| Migrating topic queueTest [0] from (none) to 10.0.0.209:9092/3
%7|1460708777.323|METADATA|rdkafka#consumer-2| 10.0.0.203:9092/1: Requested topic queueTest seen in metadata
%7|1460708777.419|TOPBRK|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0]: joining broker
%7|1460708777.519|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: timed offset query for END in state offset-query
%7|1460708777.520|OFFREQ|rdkafka#consumer-2| 10.0.0.209:9092/3: Partition queueTest [0]: querying for logical offset END (opv 2)
%7|1460708777.520|OFFSET|rdkafka#consumer-2| 10.0.0.209:9092/3: OffsetRequest (1 offsets) for topic queueTest 0
%7|1460708777.520|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state offset-query -> offset-wait
%7|1460708777.620|OFFSET|rdkafka#consumer-2| Offset END request for queueTest [0] returned offset 10 (10)
%7|1460708777.620|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state offset-wait -> active
%7|1460708777.720|FETCHDEC|rdkafka#consumer-2| Topic queueTest [0]: fetch decide: updating to version 3 (was 0) at offset 10 (was 0)
%7|1460708777.720|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0] at offset 10 (0/100000 msgs, 0/1000000 kb queued) is fetchable:
%7|1460708777.720|FETCHADD|rdkafka#consumer-2| 10.0.0.209:9092/3: Added queueTest [0] to fetch list (1 entries, opv 3)
%7|1460708777.721|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch topic queueTest [0] at offset 10 (v3)
%7|1460708777.721|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Fetch 1/1/1 toppar(s)
%7|1460708777.921|PAUSE|rdkafka#consumer-2| Library pausing 1 partition(s)
%7|1460708777.921|PAUSE|rdkafka#consumer-2| Pause queueTest [0]: at offset INVALID
%7|1460708777.921|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: stored off -1001, committted off -1001
%7|1460708777.921|OFFSET|rdkafka#consumer-2| Topic queueTest [0]: setting offset INVALID for commit
%7|1460708777.921|FETCH|rdkafka#consumer-2| Stopping fetch for queueTest [0] in state active (v5)
%7|1460708777.921|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state active -> stopping
%7|
##teamcity[testFinished1460708777.921|PARTSTATE|rdkafka#consumer-2| Partition queueTest [0] changed fetch state stopping -> stopped
%7|1460708777.921|DESP|rdkafka#consumer-2| Removing (un)desired topic queueTest [0]
%7|1460708777.921|RESUME|rdkafka#consumer-2| Library resuming 1 partition(s)
%7|1460708777.921|RESUME|rdkafka#consumer-2| Resume queueTest [0]: at offset INVALID
%7|1460708777.921|CONSUMER|rdkafka#consumer-2| Seek queueTest [0] to offset INVALID
%7|1460708777.921|DESTROY|rdkafka#consumer-2| Terminating instance
%7|1460708777.921|OP|rdkafka#consumer-2| queueTest [0] received op SEEK (v0) in fetch-state stopped
%7|1460708777.921|FETCH|rdkafka#consumer-2| Seek queueTest [0] to offset INVALID in state stopped (v7)
%7|1460708777.921|DESTROY|rdkafka#consumer-2| Destroy internal
%7|1460708777.921|DESTROY|rdkafka#consumer-2| Remove all topics
%7|1460708777.921|PARTCNT|rdkafka#consumer-2| Topic queueTest partition count changed from 1 to 0
%7|1460708777.921|BRKDELGT|rdkafka#consumer-2| Broker 10.0.0.209:9092/3 no longer leader for topic queueTest [0]
%7|1460708777.921|BRKDELGT|rdkafka#consumer-2| No broker is leader for topic queueTest [0]
%7|1460708777.921|BRKMIGR|rdkafka#consumer-2| Migrating topic queueTest [0] from 10.0.0.209:9092/3 to (none)
%7|1460708777.921|TOPPARREMOVE|rdkafka#consumer-2| Removing toppar queueTest [-1]
%7|1460708777.922|FETCH|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0] at offset INVALID (0/100000 msgs, 0/1000000 kb queued) is not fetchable: not in active fetch state
%7|1460708777.922|FETCHADD|rdkafka#consumer-2| 10.0.0.209:9092/3: Removed queueTest [0] from fetch list (0 entries, opv 3)
%7|1460708777.922|TOPBRK|rdkafka#consumer-2| 10.0.0.209:9092/3: Topic queueTest [0]: leaving broker (next leader (none))
%7|1460708777.922|TOPPARREMOVE|rdkafka#consumer-2| Removing toppar queueTest [0]

@edenhill
Copy link
Contributor

It looks like it doesnt commit your consumed offsets.
Can you show your complete source code?

@jose9r
Copy link
Author

jose9r commented Apr 15, 2016

$conf = new Conf();
$conf->set("group.id", "group15");
$conf->set("offset.store.method", "broker");

    $conf->set("metadata.broker.list", "10.0.0.203:9092,10.0.0.208:9092,10.0.0.209:9092");
    $conf->set("debug", "topic,fetch");
    $topicConf = new TopicConf();
    $topicConf->set("auto.offset.reset", "largest");
    $conf->setDefaultTopicConf($topicConf);
    $consumer = new KafkaConsumer($conf);
    $consumer->subscribe(["queueTest"]);

    $read = false;
    $msg = "msg";
    while ($msg != null) {
        $msg = $consumer->consume(3600e3);
        //$msg2 = $consumer2->consume(3600e3);
        switch ($msg->err) {
            case RD_KAFKA_RESP_ERR_NO_ERROR:
                $read = true;
                echo "offset: " . $msg->offset, "\n";
                echo "message: ".$msg->payload, "\n";
                break;
            case RD_KAFKA_RESP_ERR__PARTITION_EOF:
                $read = true;
                echo "key: " . $msg->key, "\n";
                echo "offset: " . $msg->offset, "\n";
                $msg = "";
                echo "No more messages; will wait for more\n";
                break;
            case RD_KAFKA_RESP_ERR__TIMED_OUT:
                $read = true;
                echo "Timedout\n";
                break;
            default:
                throw new \Exception($msg->errstr(), $msg->err);
                break;
        }
    }

@edenhill
Copy link
Contributor

I'm not sure what exits that loop, but you will need to call $consumer->close() before terminating your program so that it can commit final offsets.

@jose9r
Copy link
Author

jose9r commented Apr 15, 2016

$consumer->close() doesnt exist, i think the problem is related with php-rdkafka library, @arnaud-lb can you read this topic please? thank you!!

@arnaud-lb
Copy link
Contributor

php-rdkafka calls close() when the KafkaConsumer object is destroyed (e.g. when the object is not referenced anymore). Note however that hitting CTRL-C or killing the program may not let PHP properly destroy objects.

I think that tuning auto.commit.interval.ms will also cause the offsets to be committed earlier.

@jose9r
Copy link
Author

jose9r commented Apr 15, 2016

i change auto.commit.interval.ms to 1000, but the problem continues. Another question is how can i see consumer groups created, because with kafka-consumer-groups.sh script from kafka i only see groups created by console, whose offset is stored in zookeeper, no in kafka __consumer_offsets. thanks

@edenhill
Copy link
Contributor

@jose9r Try setting auto.commit.interval.ms to 1000 and add a sleep(5) before exiting your program and see if that helps. If so it is a timing/destructor issue, otherwise there's something else wrong.
Please note @arnaud-lb 's comment on Ctrl-C too.

@jose9r
Copy link
Author

jose9r commented Apr 18, 2016

I try with auto.commit.interval.ms and sleep and it doesnt work. Im using kafka-manager tool for monitoring, and when I run the program with auto.offset.reset to largest, the group doesn't appear . If I set auto.offset.reset to smallest, the group appears and I can see current offset and queue size.

@edenhill
Copy link
Contributor

That is an indication that there are no new messages coming in on the topic, librdkafka will only commit offsets for received messages, so if you start a new group to read at the end of the partition ("latest") and no new messages are produced it will just idle at the end, without committing.

@edenhill
Copy link
Contributor

Is this still an issue?

@jose9r
Copy link
Author

jose9r commented Apr 22, 2016

Yes, the problem continues.

@edenhill
Copy link
Contributor

Can you comment on my comment from 4 days ago about not producing new messages?

@charlessoft
Copy link

charlessoft commented Apr 29, 2016

i have same program, i want to receive least message.
i use C++ code

RdKafka::Conf *conf = RdKafka::Conf::create(RdKafka::Conf::CONF_GLOBAL);
RdKafka::Conf *tconf = RdKafka::Conf::create(RdKafka::Conf::CONF_TOPIC);
conf->set("bootstrap.servers", brokers, errstr);
conf->set("group.id", group1, errstr);
tconf->set("auto.offset.reset", "latest", errstr);
tconf->set("enable.auto.commit", "true", errstr);
tconf->set("auto.commit.interval.ms", "1000", errstr);
tconf->set("session.timeout.ms", "30000", errstr);
while (run) {
    RdKafka::Message *msg = consumer->consume(topic, partition, 1000);
    msg_consume(msg, NULL);
    delete msg;
    consumer->poll(0);
}

recive all the message 。

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants