Skip to content

Instantly share code, notes, and snippets.

@klippx
Created December 19, 2017 13:29
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save klippx/65c4ef06eb0e01cbde6d0640e3176f1f to your computer and use it in GitHub Desktop.
Save klippx/65c4ef06eb0e01cbde6d0640e3176f1f to your computer and use it in GitHub Desktop.
Issue with v0.5.1 of Ruby Kafka (incorrect offsets and eventual crash)
/** Receiving 1 message
# lag = 0
# fetched from offset = 772029
# first message offset = 772029
# last message offset = 772029
# highwater_mark_offset = 772030
# committed offset = 772030
*/
{"line":{"timestamp":"2017-12-19T00:21:45.780414Z","level":"DEBUG","logger":"RubyKafka","message":"Fetching batch from eu-live.kred.account-events/7 starting at offset 772029"}}
{"line":{"timestamp":"2017-12-19T00:21:55.296350Z","level":"INFO","logger":"Phobos","message":{"message":"Received batch on eu-live.kred.account-events/7","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","partition":7,"first_offset":772029,"last_offset":772029,"offset_lag":0,"highwater_mark_offset":772030,"message_count":1,"client_id":"phobos"}}}
{"line":{"timestamp":"2017-12-19T00:21:55.310164Z","level":"INFO","logger":"Phobos","message":{"message":"Committed offset","listener_id":"7d506e","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","handler":"AccountEventsConsumer","batch_size":1,"partition":7,"offset_lag":0}}}
{"line":{"timestamp":"2017-12-19T00:21:55.310558Z","level":"DEBUG","logger":"RubyKafka","message":"Marking eu-live.kred.account-events/7:772029 as processed"}}
{"line":{"timestamp":"2017-12-19T00:21:55.310777Z","level":"INFO","logger":"RubyKafka","message":"Committing offsets: eu-live.kred.account-events/7:772030, eu-live.kred.account-events/15:769872"}}
/** Receiving 0 messages
# lag = 0
# fetched from offset = 772030 (+1)
# committed offset = 772030
*/
{"line":{"timestamp":"2017-12-19T00:21:55.314419Z","level":"DEBUG","logger":"RubyKafka","message":"Fetching batch from eu-live.kred.account-events/7 starting at offset 772030"}}
{"line":{"timestamp":"2017-12-19T00:22:03.585454Z","level":"INFO","logger":"RubyKafka","message":"Sending heartbeat..."}}
{"line":{"timestamp":"2017-12-19T00:22:04.105472Z","level":"INFO","logger":"RubyKafka","message":"Committing offsets: eu-live.kred.account-events/7:772030, eu-live.kred.account-events/15:769872"}}
/** Receiving 3 messages
# lag = 0
# fetched from offset = 772030
# first message offset = 772030
# last message offset = 772032
# highwater_mark_offset = 772033
# committed offset = N/A ******** Not actually committed to Kafka
*/
{"line":{"timestamp":"2017-12-19T00:22:04.126474Z","level":"DEBUG","logger":"RubyKafka","message":"Fetching batch from eu-live.kred.account-events/7 starting at offset 772030"}}
{"line":{"timestamp":"2017-12-19T00:22:04.163378Z","level":"INFO","logger":"Phobos","message":{"message":"Received batch on eu-live.kred.account-events/7","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","partition":7,"first_offset":772030,"last_offset":772032,"offset_lag":0,"highwater_mark_offset":772033,"message_count":3,"client_id":"phobos"}}}
{"line":{"timestamp":"2017-12-19T00:22:04.211136Z","level":"INFO","logger":"Phobos","message":{"message":"Committed offset","listener_id":"7d506e","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","handler":"AccountEventsConsumer","batch_size":3,"partition":7,"offset_lag":0}}}
{"line":{"timestamp":"2017-12-19T00:22:04.211582Z","level":"DEBUG","logger":"RubyKafka","message":"Marking eu-live.kred.account-events/7:772032 as processed"}}
/** Receiving 1 messages
# lag = 0
# fetched from offset = 772033 (+3)
# first message offset = 772033
# last message offset = 772033
# highwater_mark_offset = 772034
# committed offset = N/A ******** Not actually committed to Kafka
*/
{"line":{"timestamp":"2017-12-19T00:22:04.239739Z","level":"DEBUG","logger":"RubyKafka","message":"Fetching batch from eu-live.kred.account-events/7 starting at offset 772033"}}
{"line":{"timestamp":"2017-12-19T00:22:05.302559Z","level":"INFO","logger":"Phobos","message":{"message":"Received batch on eu-live.kred.account-events/7","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","partition":7,"first_offset":772033,"last_offset":772033,"offset_lag":0,"highwater_mark_offset":772034,"message_count":1,"client_id":"phobos"}}}
{"line":{"timestamp":"2017-12-19T00:22:05.322252Z","level":"INFO","logger":"Phobos","message":{"message":"Committed offset","listener_id":"7d506e","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","handler":"AccountEventsConsumer","batch_size":1,"partition":7,"offset_lag":0}}}
{"line":{"timestamp":"2017-12-19T00:22:05.322684Z","level":"DEBUG","logger":"RubyKafka","message":"Marking eu-live.kred.account-events/7:772033 as processed"}}
/** Receiving 10 messages
# lag = -9
# fetched from offset = 772034 (+1)
# first message offset = 772043 (!?)
# last message offset = 772052 (!?)
# highwater_mark_offset = 772044
# committed offset = 772052 (!?)
*/
{"line":{"timestamp":"2017-12-19T00:22:05.343593Z","level":"DEBUG","logger":"RubyKafka","message":"Fetching batch from eu-live.kred.account-events/7 starting at offset 772034"}}
{"line":{"timestamp":"2017-12-19T00:22:05.361612Z","level":"INFO","logger":"Phobos","message":{"message":"Received batch on eu-live.kred.account-events/7","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","partition":7,"first_offset":772043,"last_offset":772052,"offset_lag":-9,"highwater_mark_offset":772044,"message_count":10,"client_id":"phobos"}}}
{"line":{"timestamp":"2017-12-19T00:22:05.578268Z","level":"INFO","logger":"Phobos","message":{"message":"Committed offset","listener_id":"7d506e","group_id":"account-overview-consumer-production-eu-kred.account-events_1","topic":"eu-live.kred.account-events","handler":"AccountEventsConsumer","batch_size":10,"partition":7,"offset_lag":-9}}}
{"line":{"timestamp":"2017-12-19T00:22:05.578679Z","level":"DEBUG","logger":"RubyKafka","message":"Marking eu-live.kred.account-events/7:772052 as processed"}}
/** Crashing...
# fetched from offset = 772053 (is invalid)
*/
{"line":{"timestamp":"2017-12-19T00:22:05.623357Z","level":"DEBUG","logger":"RubyKafka","message":"Fetching batch from eu-live.kred.account-events/7 starting at offset 772053"}}
{"line":{"timestamp":"2017-12-19T00:22:05.625029Z","level":"ERROR","logger":"RubyKafka","message":"Invalid offset for eu-live.kred.account-events/7, resetting to default offset"}}
/** Resetting...
# fetched from offset = 175703 (from beginning)
*/
{"line":{"timestamp":"2017-12-19T00:22:05.628103Z","level":"DEBUG","logger":"RubyKafka","message":"Fetching batch from eu-live.kred.account-events/7 starting at offset 175703"}}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment