Hello,
I had this morning the issue that a client offset got deleted from a
broker as it seems.
(Kafka 0.11.0.1 with patch for KAFKA-6030 on top)
It happened in a test environment and the pipeline stage got re-deployed
multiple times, during one restart, when the consumer reconnected, it
didn't get any offset and started from the beginning as per it's
configuration. The queue didn't receive any new events in the last 48h,
so any restart should not do anything.
Here the relevant consumer logs:
2017-10-31 17:15:08.453 Successfully joined group
events-inst-agg-stream.aggregation.v1 with generation 5
2017-11-01 14:29:46.554 Successfully joined group
events-inst-agg-stream.aggregation.v1 with generation 7
2017-11-01 14:51:14.639 Successfully joined group
events-inst-agg-stream.aggregation.v1 with generation 9
2017-11-01 14:51:19.068 Committing
Map(GroupTopicPartition(events-inst-agg-stream.aggregation.v1,events.lg,0)
-> 3830)
2017-11-01 14:51:24.083 Committing
Map(GroupTopicPartition(events-inst-agg-stream.aggregation.v1,events.lg,0)
-> 11339)
You can see the restarts at 17:15 yesterday and 14:29 today were normal.
Then the restart at 14:51 started reading from the beginning (we log
committed offsets).
The relevant leading broker did some "stuff" that was different between
14:29 and 14:51. The full logs are below.
From what I can see it deleted a segment from the consumer offsets log,
and the next time the consumer connected it got no offset.
I can provide the logs of the other kafka nodes if it is useful. I also
attached screenshots from the log viewer in case it's easier to read.
I found https://issues.apache.org/jira/browse/KAFKA-5600 which looked
related, but it's fixed in 0.11.0.1.
Any other ideas what the issue could be?
[2017-11-01 14:09:46,805] INFO [Group Metadata Manager on Broker 1]:
Removed 0 expired offsets in 1 milliseconds.
(kafka.coordinator.group.GroupMetadataManager)
[2017-11-01 14:19:46,805] INFO [Group Metadata Manager on Broker 1]:
Removed 0 expired offsets in 1 milliseconds.
(kafka.coordinator.group.GroupMetadataManager)
[2017-11-01 14:24:23,627] INFO [GroupCoordinator 1]: Preparing to
rebalance group events-inst-agg-stream.aggregation.v1 with old
generation 5 (__consumer_offsets-8)
(kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:24:23,627] INFO [GroupCoordinator 1]: Group
events-inst-agg-stream.aggregation.v1 with generation 6 is now empty
(__consumer_offsets-8) (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:29:46,540] INFO [GroupCoordinator 1]: Preparing to
rebalance group events-inst-agg-stream.aggregation.v1 with old
generation 6 (__consumer_offsets-8)
(kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:29:46,546] INFO [GroupCoordinator 1]: Stabilized group
events-inst-agg-stream.aggregation.v1 generation 7
(__consumer_offsets-8) (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:29:46,551] INFO [GroupCoordinator 1]: Assignment received
from leader for group events-inst-agg-stream.aggregation.v1 for
generation 7 (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:29:46,832] INFO Rolled new log segment for
'__consumer_offsets-5' in 26 ms. (kafka.log.Log)
[2017-11-01 14:29:46,833] INFO [Group Metadata Manager on Broker 1]:
Removed 3 expired offsets in 29 milliseconds.
(kafka.coordinator.group.GroupMetadataManager)
[2017-11-01 14:30:23,642] INFO [GroupCoordinator 1]: Preparing to
rebalance group key-stats-kafka-stream.stats.v1 with old generation 11
(__consumer_offsets-5) (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:30:23,644] INFO [GroupCoordinator 1]: Group
key-stats-kafka-stream.stats.v1 with generation 12 is now empty
(__consumer_offsets-5) (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:30:54,731] INFO Deleting segment 0 from log
__consumer_offsets-5. (kafka.log.Log)
[2017-11-01 14:30:54,767] INFO Deleting index
/var/lib/kafka/data/topics/__consumer_offsets-5/00000000000000000000.index.deleted
(kafka.log.OffsetIndex)
[2017-11-01 14:30:54,767] INFO Deleting index
/var/lib/kafka/data/topics/__consumer_offsets-5/00000000000000000000.timeindex.deleted
(kafka.log.TimeIndex)
[2017-11-01 14:36:15,590] INFO [GroupCoordinator 1]: Preparing to
rebalance group key-stats-kafka-stream.stats.v1 with old generation 12
(__consumer_offsets-5) (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:36:15,594] INFO [GroupCoordinator 1]: Stabilized group
key-stats-kafka-stream.stats.v1 generation 13 (__consumer_offsets-5)
(kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:36:15,612] INFO [GroupCoordinator 1]: Assignment received
from leader for group key-stats-kafka-stream.stats.v1 for generation 13
(kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:39:46,805] INFO [Group Metadata Manager on Broker 1]:
Removed 0 expired offsets in 1 milliseconds.
(kafka.coordinator.group.GroupMetadataManager)
[2017-11-01 14:49:46,804] INFO [Group Metadata Manager on Broker 1]:
Removed 0 expired offsets in 0 milliseconds.
(kafka.coordinator.group.GroupMetadataManager)
[2017-11-01 14:50:45,546] INFO [GroupCoordinator 1]: Preparing to
rebalance group events-inst-agg-stream.aggregation.v1 with old
generation 7 (__consumer_offsets-8)
(kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:50:45,546] INFO [GroupCoordinator 1]: Group
events-inst-agg-stream.aggregation.v1 with generation 8 is now empty
(__consumer_offsets-8) (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:51:14,625] INFO [GroupCoordinator 1]: Preparing to
rebalance group events-inst-agg-stream.aggregation.v1 with old
generation 8 (__consumer_offsets-8)
(kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:51:14,627] INFO [GroupCoordinator 1]: Stabilized group
events-inst-agg-stream.aggregation.v1 generation 9
(__consumer_offsets-8) (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:51:14,635] INFO [GroupCoordinator 1]: Assignment received
from leader for group events-inst-agg-stream.aggregation.v1 for
generation 9 (kafka.coordinator.group.GroupCoordinator)
[2017-11-01 14:52:50,193] INFO Rolled new log segment for
'events.lg.aggregated-0' in 5 ms. (kafka.log.Log)
