After upgrading to latest version; I get random container crashes stating:

Rakiah commented 5 years ago

Description Hello everyone, I'm having random crashes since i've upgraded kafka from version 0.12.0 to version 1.2.0, I've also took care to update completely the code to match the new samples that you've produced since then, but I get the followings errors on a container after a few times

dotnet: ../nptl/pthread_mutex_lock.c:81: __pthread_mutex_cond_lock: Assertion `mutex->__data.__owner == 0' failed.

dotnet: malloc.c:2942: __libc_malloc: Assertion `!victim || chunk_is_mmapped (mem2chunk (victim)) || ar_ptr == arena_for_chunk (mem2chunk (victim))' failed.

and i'll put the last one here because it is WAY too long: https://pastebin.com/raw/zSNMKPGL

one of those errors happen and the container crash, however they never ALL happen at the same time

How to reproduce I don't really know as it happens very randomly, i'll post my code down and maybe you can find something obvious that I cannot see

Please provide the following information:

[x] Confluent.Kafka
```
1.2.0
```

[x] Apache Kafka version.

Docker image wurstmeister/kafka:2.12-2.3.0

[x] Client configuration.

"bootStrapServers": "kafka:9092",
"groupId": "alarms-microservices",
"autoCommitInterval": 5000,
"statisticsInterval": 60000,
"sessionTimeout": 6000,
"autoOffsetReset": "earliest"

[x] Operating system.
```
Docker image based on linux debian 9
```
Here is code attached that run the kafka producer: https://pastebin.com/LPvKKGAi

and here is my consumer code: https://pastebin.com/CrkPi0TD

Rakiah commented 5 years ago

I may have an idea,

If you watch in my BaseKafkaClient,

I actually Dispose the consumer (close/dispose) from another class, Is it possible that calling a Close/Dispose on a consumer and THEN calling consumer.Consume on it would do this crash ? or actually closing/disposing the consumer twice would do this crash ? because that could happen in my design, I will try and find a way to not do that and report If it works better

Rakiah commented 5 years ago

I'm really starting to think that this is the problem

Requesting for disconnection

Client was disconnected -> 7456ea5b-0b50-4a05-8b68-268e64ee5d76

Revoking assignment: [EventProceduresRejectedEntityCommand [[0]] @Unset [-1001]]

Error: 1/1 brokers are down

Revoking assignment: [EventProcedure [[0]] @Unset [-1001]]

Error: 1/1 brokers are down

Statistics: { "name": "rdkafka#consumer-2", "client_id": "rdkafka", "type": "consumer", "ts":1382723241574, "time":1571318232, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15168471195, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":1, "waitresp_msg_cnt":0, "tx":145690, "txbytes":11211711, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":145689, "rxbytes":9466753, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":318123, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":87, "avg":23, "sum":13859, "stddev": 5, "p50": 23, "p75": 24, "p90": 26, "p95": 32, "p99": 43, "p99_99": 87, "outofrange": 0, "hdrsize": 11376, "cnt":580 }, "rtt": { "min":50018, "max":143800, "avg":103460, "sum":60006892, "stddev": 4163, "p50": 102911, "p75": 104447, "p90": 107519, "p95": 109567, "p99": 116735, "p99_99": 144383, "outofrange": 0, "hdrsize": 15472, "cnt":580 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":579 }, "req": { "Fetch": 145347, "Offset": 253, "Metadata": 54, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 35, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventPassport-0": { "topic":"EventPassport", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15161090726, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5056, "txbytes":490320, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5056, "rxbytes":51070, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15166, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":41, "max":2791, "avg":192, "sum":3850, "stddev": 596, "p50": 56, "p75": 60, "p90": 69, "p95": 70, "p99": 2799, "p99_99": 2799, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":656, "max":60485, "avg":7282, "sum":145646, "stddev": 12657, "p50": 2959, "p75": 7199, "p90": 10239, "p95": 14335, "p99": 60671, "p99_99": 60671, "outofrange": 0, "hdrsize": 16496, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 1, "OffsetCommit": 0, "OffsetFetch": 1, "GroupCoordinator": 0, "JoinGroup": 1, "Heartbeat": 5051, "LeaveGroup": 0, "SyncGroup": 1, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventPassport": { "topic":"EventPassport", "metadata_age":180102, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":0, "lo_offset":0, "hi_offset":0, "ls_offset":0, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15161085, "join_state": "started", "rebalance_age": 15155487, "rebalance_cnt": 3, "rebalance_reason": "group rejoin", "assignment_size": 1 }, "tx":150746, "tx_bytes":11702031, "rx":150745, "rx_bytes":9517823, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":0, "rxmsg_bytes":0}

Statistics: { "name": "rdkafka#consumer-3", "client_id": "rdkafka", "type": "consumer", "ts":1382723859927, "time":1571318232, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15169136610, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":1, "waitresp_msg_cnt":0, "tx":146617, "txbytes":10843367, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":146616, "rxbytes":9151740, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":317874, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":506, "avg":25, "sum":14488, "stddev": 21, "p50": 23, "p75": 25, "p90": 27, "p95": 33, "p99": 44, "p99_99": 507, "outofrange": 0, "hdrsize": 11376, "cnt":578 }, "rtt": { "min":55402, "max":127844, "avg":103800, "sum":59996406, "stddev": 3815, "p50": 103423, "p75": 104959, "p90": 107519, "p95": 109567, "p99": 117247, "p99_99": 127999, "outofrange": 0, "hdrsize": 15472, "cnt":578 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":577 }, "req": { "Fetch": 146274, "Offset": 254, "Metadata": 54, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 34, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventAlarm-0": { "topic":"EventAlarm", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15162134174, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5089, "txbytes":494851, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5089, "rxbytes":52680, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15266, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":39, "max":74, "avg":56, "sum":1134, "stddev": 9, "p50": 55, "p75": 62, "p90": 70, "p95": 74, "p99": 74, "p99_99": 74, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":1013, "max":64329, "avg":8775, "sum":175510, "stddev": 13346, "p50": 5055, "p75": 6879, "p90": 11519, "p95": 18559, "p99": 64511, "p99_99": 64511, "outofrange": 0, "hdrsize": 14448, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 3, "OffsetCommit": 27, "OffsetFetch": 2, "GroupCoordinator": 0, "JoinGroup": 2, "Heartbeat": 5052, "LeaveGroup": 0, "SyncGroup": 2, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventAlarm": { "topic":"EventAlarm", "metadata_age":180084, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":41, "app_offset":41, "stored_offset":41, "commited_offset":41, "committed_offset":41, "eof_offset":41, "lo_offset":0, "hi_offset":41, "ls_offset":41, "consumer_lag":0, "txmsgs":0, "txbytes":0, "rxmsgs":41, "rxbytes":61753, "msgs": 41, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15162133, "join_state": "started", "rebalance_age": 15156106, "rebalance_cnt": 5, "rebalance_reason": "group is rebalancing", "assignment_size": 1 }, "tx":151706, "tx_bytes":11338218, "rx":151705, "rx_bytes":9204420, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":41, "rxmsg_bytes":61753}

Statistics: { "name": "rdkafka#consumer-2", "client_id": "rdkafka", "type": "consumer", "ts":1382783242036, "time":1571318292, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15228471657, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":1, "waitresp_msg_cnt":0, "tx":146274, "txbytes":11256666, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":146273, "rxbytes":9504697, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":319424, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":145, "avg":24, "sum":14245, "stddev": 7, "p50": 23, "p75": 25, "p90": 26, "p95": 33, "p99": 48, "p99_99": 145, "outofrange": 0, "hdrsize": 11376, "cnt":584 }, "rtt": { "min":52893, "max":141857, "avg":102940, "sum":60116964, "stddev": 3898, "p50": 102399, "p75": 103935, "p90": 105983, "p95": 107519, "p99": 114687, "p99_99": 142335, "outofrange": 0, "hdrsize": 15472, "cnt":584 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":583 }, "req": { "Fetch": 145930, "Offset": 254, "Metadata": 54, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 35, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventPassport-0": { "topic":"EventPassport", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15221091188, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5076, "txbytes":492260, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5076, "rxbytes":51270, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15226, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":42, "max":74, "avg":58, "sum":1178, "stddev": 10, "p50": 59, "p75": 67, "p90": 71, "p95": 72, "p99": 74, "p99_99": 74, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":1634, "max":17498, "avg":4953, "sum":99062, "stddev": 3485, "p50": 4351, "p75": 4991, "p90": 6047, "p95": 11263, "p99": 17535, "p99_99": 17535, "outofrange": 0, "hdrsize": 16496, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 1, "OffsetCommit": 0, "OffsetFetch": 1, "GroupCoordinator": 0, "JoinGroup": 1, "Heartbeat": 5071, "LeaveGroup": 0, "SyncGroup": 1, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventPassport": { "topic":"EventPassport", "metadata_age":240102, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":0, "lo_offset":0, "hi_offset":0, "ls_offset":0, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15221085, "join_state": "started", "rebalance_age": 15215488, "rebalance_cnt": 3, "rebalance_reason": "group rejoin", "assignment_size": 1 }, "tx":151350, "tx_bytes":11748926, "rx":151349, "rx_bytes":9555967, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":0, "rxmsg_bytes":0}

Statistics: { "name": "rdkafka#consumer-3", "client_id": "rdkafka", "type": "consumer", "ts":1382783860416, "time":1571318292, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15229137099, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":1, "waitresp_msg_cnt":0, "tx":147200, "txbytes":10886496, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":147199, "rxbytes":9187870, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":319139, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":896, "avg":26, "sum":15588, "stddev": 39, "p50": 23, "p75": 24, "p90": 27, "p95": 33, "p99": 69, "p99_99": 899, "outofrange": 0, "hdrsize": 11376, "cnt":583 }, "rtt": { "min":47922, "max":140538, "avg":103066, "sum":60087742, "stddev": 3680, "p50": 102911, "p75": 103935, "p90": 105983, "p95": 108543, "p99": 112639, "p99_99": 141311, "outofrange": 0, "hdrsize": 15472, "cnt":583 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":582 }, "req": { "Fetch": 146856, "Offset": 255, "Metadata": 54, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 34, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventAlarm-0": { "topic":"EventAlarm", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15222134663, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5109, "txbytes":496791, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5109, "rxbytes":52880, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15326, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":37, "max":252, "avg":73, "sum":1464, "stddev": 43, "p50": 61, "p75": 72, "p90": 85, "p95": 104, "p99": 252, "p99_99": 252, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":1098, "max":16424, "avg":4669, "sum":93397, "stddev": 3340, "p50": 3103, "p75": 5343, "p90": 8031, "p95": 8511, "p99": 16511, "p99_99": 16511, "outofrange": 0, "hdrsize": 14448, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 3, "OffsetCommit": 27, "OffsetFetch": 2, "GroupCoordinator": 0, "JoinGroup": 2, "Heartbeat": 5072, "LeaveGroup": 0, "SyncGroup": 2, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventAlarm": { "topic":"EventAlarm", "metadata_age":240084, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":41, "app_offset":41, "stored_offset":41, "commited_offset":41, "committed_offset":41, "eof_offset":41, "lo_offset":0, "hi_offset":41, "ls_offset":41, "consumer_lag":0, "txmsgs":0, "txbytes":0, "rxmsgs":41, "rxbytes":61753, "msgs": 41, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15222133, "join_state": "started", "rebalance_age": 15216106, "rebalance_cnt": 5, "rebalance_reason": "group is rebalancing", "assignment_size": 1 }, "tx":152309, "tx_bytes":11383287, "rx":152308, "rx_bytes":9240750, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":41, "rxmsg_bytes":61753}

Statistics: { "name": "rdkafka#consumer-2", "client_id": "rdkafka", "type": "consumer", "ts":1382843242465, "time":1571318352, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15288472086, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":1, "waitresp_msg_cnt":0, "tx":146855, "txbytes":11301353, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":146854, "rxbytes":9542490, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":320690, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":174, "avg":24, "sum":14451, "stddev": 10, "p50": 23, "p75": 25, "p90": 26, "p95": 34, "p99": 63, "p99_99": 174, "outofrange": 0, "hdrsize": 11376, "cnt":581 }, "rtt": { "min":8455, "max":150910, "avg":103140, "sum":59924551, "stddev": 6030, "p50": 102399, "p75": 103935, "p90": 107007, "p95": 110079, "p99": 119807, "p99_99": 151551, "outofrange": 0, "hdrsize": 15472, "cnt":581 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":579 }, "req": { "Fetch": 146509, "Offset": 255, "Metadata": 55, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 35, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventPassport-0": { "topic":"EventPassport", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15281091617, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5096, "txbytes":494200, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5096, "rxbytes":51470, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15286, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":35, "max":103, "avg":62, "sum":1247, "stddev": 13, "p50": 61, "p75": 65, "p90": 72, "p95": 82, "p99": 103, "p99_99": 103, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":646, "max":14161, "avg":5584, "sum":111692, "stddev": 3078, "p50": 5119, "p75": 6911, "p90": 9407, "p95": 9727, "p99": 14207, "p99_99": 14207, "outofrange": 0, "hdrsize": 16496, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 1, "OffsetCommit": 0, "OffsetFetch": 1, "GroupCoordinator": 0, "JoinGroup": 1, "Heartbeat": 5091, "LeaveGroup": 0, "SyncGroup": 1, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventPassport": { "topic":"EventPassport", "metadata_age":96, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":0, "lo_offset":0, "hi_offset":0, "ls_offset":0, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15281086, "join_state": "started", "rebalance_age": 15275488, "rebalance_cnt": 3, "rebalance_reason": "group rejoin", "assignment_size": 1 }, "tx":151951, "tx_bytes":11795553, "rx":151950, "rx_bytes":9593960, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":0, "rxmsg_bytes":0}

Statistics: { "name": "rdkafka#consumer-3", "client_id": "rdkafka", "type": "consumer", "ts":1382843860855, "time":1571318352, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15289137538, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":1, "waitresp_msg_cnt":0, "tx":147781, "txbytes":10929440, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":147780, "rxbytes":9223920, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":320438, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":325, "avg":25, "sum":14709, "stddev": 15, "p50": 23, "p75": 25, "p90": 28, "p95": 34, "p99": 62, "p99_99": 325, "outofrange": 0, "hdrsize": 11376, "cnt":581 }, "rtt": { "min":80414, "max":150539, "avg":103453, "sum":60106480, "stddev": 4212, "p50": 102399, "p75": 104447, "p90": 106495, "p95": 109055, "p99": 123391, "p99_99": 151551, "outofrange": 0, "hdrsize": 15472, "cnt":581 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":579 }, "req": { "Fetch": 147435, "Offset": 256, "Metadata": 55, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 34, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventAlarm-0": { "topic":"EventAlarm", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15282135102, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5129, "txbytes":498731, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5129, "rxbytes":53080, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15386, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":43, "max":82, "avg":60, "sum":1200, "stddev": 10, "p50": 60, "p75": 65, "p90": 72, "p95": 74, "p99": 82, "p99_99": 82, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":320, "max":19690, "avg":5346, "sum":106939, "stddev": 4238, "p50": 5183, "p75": 5887, "p90": 9983, "p95": 11455, "p99": 19711, "p99_99": 19711, "outofrange": 0, "hdrsize": 14448, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 3, "OffsetCommit": 27, "OffsetFetch": 2, "GroupCoordinator": 0, "JoinGroup": 2, "Heartbeat": 5092, "LeaveGroup": 0, "SyncGroup": 2, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventAlarm": { "topic":"EventAlarm", "metadata_age":56, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":41, "app_offset":41, "stored_offset":41, "commited_offset":41, "committed_offset":41, "eof_offset":41, "lo_offset":0, "hi_offset":41, "ls_offset":41, "consumer_lag":0, "txmsgs":0, "txbytes":0, "rxmsgs":41, "rxbytes":61753, "msgs": 41, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15282134, "join_state": "started", "rebalance_age": 15276106, "rebalance_cnt": 5, "rebalance_reason": "group is rebalancing", "assignment_size": 1 }, "tx":152910, "tx_bytes":11428171, "rx":152909, "rx_bytes":9277000, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":41, "rxmsg_bytes":61753}

Statistics: { "name": "rdkafka#consumer-2", "client_id": "rdkafka", "type": "consumer", "ts":1382903243145, "time":1571318412, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15348472766, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":1, "waitresp_msg_cnt":0, "tx":147437, "txbytes":11346154, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":147436, "rxbytes":9580304, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":321960, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":579, "avg":25, "sum":14627, "stddev": 23, "p50": 23, "p75": 25, "p90": 26, "p95": 31, "p99": 51, "p99_99": 579, "outofrange": 0, "hdrsize": 11376, "cnt":582 }, "rtt": { "min":91511, "max":158349, "avg":103339, "sum":60143414, "stddev": 4371, "p50": 102399, "p75": 103935, "p90": 107007, "p95": 109055, "p99": 123903, "p99_99": 158719, "outofrange": 0, "hdrsize": 15472, "cnt":582 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":581 }, "req": { "Fetch": 147090, "Offset": 256, "Metadata": 55, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 35, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventPassport-0": { "topic":"EventPassport", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15341092297, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5116, "txbytes":496140, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5116, "rxbytes":51670, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15346, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":43, "max":86, "avg":62, "sum":1252, "stddev": 11, "p50": 60, "p75": 64, "p90": 79, "p95": 86, "p99": 86, "p99_99": 86, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":322, "max":12274, "avg":3748, "sum":74960, "stddev": 3859, "p50": 1559, "p75": 6879, "p90": 8159, "p95": 12223, "p99": 12287, "p99_99": 12287, "outofrange": 0, "hdrsize": 16496, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 1, "OffsetCommit": 0, "OffsetFetch": 1, "GroupCoordinator": 0, "JoinGroup": 1, "Heartbeat": 5111, "LeaveGroup": 0, "SyncGroup": 1, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventPassport": { "topic":"EventPassport", "metadata_age":60096, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":0, "lo_offset":0, "hi_offset":0, "ls_offset":0, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15341086, "join_state": "started", "rebalance_age": 15335489, "rebalance_cnt": 3, "rebalance_reason": "group rejoin", "assignment_size": 1 }, "tx":152553, "tx_bytes":11842294, "rx":152552, "rx_bytes":9631974, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":0, "rxmsg_bytes":0}

Statistics: { "name": "rdkafka#consumer-3", "client_id": "rdkafka", "type": "consumer", "ts":1382903861283, "time":1571318412, "replyq":0, "msg_cnt":0, "msg_size":0, "msg_max":0, "msg_size_max":0, "simple_cnt":0, "metadata_cache_cnt":1, "brokers":{ "kafka:9092/42": { "name":"kafka:9092/42", "nodeid":42, "nodename":"kafka:9092", "source":"configured", "state":"UP", "stateage":15349137966, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":148361, "txbytes":10972347, "txerrs":0, "txretries":1, "req_timeouts":0, "rx":148361, "rxbytes":9259926, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":321750, "connects":7, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":19, "max":1032, "avg":27, "sum":15843, "stddev": 46, "p50": 23, "p75": 25, "p90": 27, "p95": 34, "p99": 68, "p99_99": 1039, "outofrange": 0, "hdrsize": 11376, "cnt":580 }, "rtt": { "min":23834, "max":137698, "avg":103341, "sum":60041225, "stddev": 5189, "p50": 102399, "p75": 104447, "p90": 106495, "p95": 109567, "p99": 121855, "p99_99": 138239, "outofrange": 0, "hdrsize": 15472, "cnt":581 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":580 }, "req": { "Fetch": 148014, "Offset": 257, "Metadata": 55, "OffsetCommit": 0, "OffsetFetch": 0, "GroupCoordinator": 34, "JoinGroup": 0, "Heartbeat": 0, "LeaveGroup": 0, "SyncGroup": 0, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ "EventAlarm-0": { "topic":"EventAlarm", "partition":0} } } , "GroupCoordinator": { "name":"GroupCoordinator", "nodeid":-1, "nodename":"kafka:9092", "source":"logical", "state":"UP", "stateage":15342135530, "outbuf_cnt":0, "outbuf_msg_cnt":0, "waitresp_cnt":0, "waitresp_msg_cnt":0, "tx":5149, "txbytes":500671, "txerrs":0, "txretries":0, "req_timeouts":0, "rx":5149, "rxbytes":53280, "rxerrs":0, "rxcorriderrs":0, "rxpartial":0, "zbuf_grow":0, "buf_grow":0, "wakeups":15446, "connects":1, "disconnects":0, "int_latency": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 11376, "cnt":0 }, "outbuf_latency": { "min":45, "max":263, "avg":77, "sum":1543, "stddev": 47, "p50": 63, "p75": 71, "p90": 116, "p95": 132, "p99": 263, "p99_99": 263, "outofrange": 0, "hdrsize": 11376, "cnt":20 }, "rtt": { "min":1214, "max":12665, "avg":5043, "sum":100869, "stddev": 3432, "p50": 3583, "p75": 6783, "p90": 10815, "p95": 11519, "p99": 12671, "p99_99": 12671, "outofrange": 0, "hdrsize": 14448, "cnt":20 }, "throttle": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 17520, "cnt":0 }, "req": { "Fetch": 0, "Offset": 0, "Metadata": 3, "OffsetCommit": 27, "OffsetFetch": 2, "GroupCoordinator": 0, "JoinGroup": 2, "Heartbeat": 5112, "LeaveGroup": 0, "SyncGroup": 2, "SaslHandshake": 0, "ApiVersion": 1 }, "toppars":{ } } }, "topics":{ "EventAlarm": { "topic":"EventAlarm", "metadata_age":60056, "batchsize": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 14448, "cnt":0 }, "batchcnt": { "min":0, "max":0, "avg":0, "sum":0, "stddev": 0, "p50": 0, "p75": 0, "p90": 0, "p95": 0, "p99": 0, "p99_99": 0, "outofrange": 0, "hdrsize": 8304, "cnt":0 }, "partitions":{ "0": { "partition":0, "leader":42, "desired":true, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"active", "query_offset":-2, "next_offset":41, "app_offset":41, "stored_offset":41, "commited_offset":41, "committed_offset":41, "eof_offset":41, "lo_offset":0, "hi_offset":41, "ls_offset":41, "consumer_lag":0, "txmsgs":0, "txbytes":0, "rxmsgs":41, "rxbytes":61753, "msgs": 41, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} , "-1": { "partition":-1, "leader":-1, "desired":false, "unknown":false, "msgq_cnt":0, "msgq_bytes":0, "xmit_msgq_cnt":0, "xmit_msgq_bytes":0, "fetchq_cnt":0, "fetchq_size":0, "fetch_state":"none", "query_offset":-1001, "next_offset":0, "app_offset":-1001, "stored_offset":-1001, "commited_offset":-1001, "committed_offset":-1001, "eof_offset":-1001, "lo_offset":-1001, "hi_offset":-1001, "ls_offset":-1001, "consumer_lag":-1, "txmsgs":0, "txbytes":0, "rxmsgs":0, "rxbytes":0, "msgs": 0, "rx_ver_drops": 0, "msgs_inflight": 0, "next_ack_seq": 0, "next_err_seq": 0, "acked_msgid": 0} } } } , "cgrp": { "state": "up", "stateage": 15342134, "join_state": "started", "rebalance_age": 15336107, "rebalance_cnt": 5, "rebalance_reason": "group is rebalancing", "assignment_size": 1 }, "tx":153510, "tx_bytes":11473018, "rx":153510, "rx_bytes":9313206, "txmsgs":0, "txmsg_bytes":0, "rxmsgs":41, "rxmsg_bytes":61753}

*** Error in `dotnet': corrupted double-linked list: 0x00007fca24010e00 ***

======= Backtrace: =========

/lib/x86_64-linux-gnu/libc.so.6(+0x70bfb)[0x7fcee43e1bfb]

/lib/x86_64-linux-gnu/libc.so.6(+0x76fc6)[0x7fcee43e7fc6]

/lib/x86_64-linux-gnu/libc.so.6(+0x7964c)[0x7fcee43ea64c]

/lib/x86_64-linux-gnu/libc.so.6(__libc_malloc+0x54)[0x7fcee43ebf64]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0xddddc)[0x7fca603d4ddc]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0xddf3f)[0x7fca603d4f3f]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0xde1a3)[0x7fca603d51a3]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0xde32a)[0x7fca603d532a]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0x7910e)[0x7fca6037010e]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0x8e5b9)[0x7fca603855b9]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0xb9cfd)[0x7fca603b0cfd]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0xba0f3)[0x7fca603b10f3]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0x49668)[0x7fca60340668]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0x72b5f)[0x7fca60369b5f]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0x50d17)[0x7fca60347d17]

/app/runtimes/linux-x64/native/debian9-librdkafka.so(+0xb3ac7)[0x7fca603aaac7]

/lib/x86_64-linux-gnu/libpthread.so.0(+0x74a4)[0x7fcee4fb44a4]

/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7fcee4459d0f]

======= Memory map: ========

00400000-00418000 r-xp 00000000 08:01 28327857                           /usr/share/dotnet/dotnet

00618000-00619000 r--p 00018000 08:01 28327857                           /usr/share/dotnet/dotnet

00619000-0061a000 rw-p 00019000 08:01 28327857                           /usr/share/dotnet/dotnet

011c3000-016b3000 rw-p 00000000 00:00 0                                  [heap]

as you can see there, it seems very related of when one of my client disconnect, which is what is calling the dispose/close

Rakiah commented 5 years ago

OK some more informations where we actually have a valid stackTrace:

Unhandled Exception: Confluent.Kafka.KafkaException: Local: Broker handle destroyed
   at Confluent.Kafka.Impl.SafeKafkaHandle.Assign(IEnumerable`1 partitions)
   at Confluent.Kafka.Consumer`2.Assign(IEnumerable`1 partitions)
   at Confluent.Kafka.Consumer`2.RebalanceCallback(IntPtr rk, ErrorCode err, IntPtr partitions, IntPtr opaque)
   at Confluent.Kafka.Impl.NativeMethods.NativeMethods_Debian9.rd_kafka_consumer_close(IntPtr rk)
   at Confluent.Kafka.Impl.SafeKafkaHandle.ConsumerClose()
   at Confluent.Kafka.Consumer`2.Close()
   at Constellation.Common.Kafka.BaseKafkaClient.Consume() in /src/Common/Common.Kafka/Common.Sources/Kafka/Clients/BaseKafkaClient.cs:line 129
   at Constellation.Common.Realtime.Events.RealtimeEventsEntityHandler`1.<RegisterHandler>b__8_1() in /src/Common/Common.Realtime.Events/Common.Sources/RealtimeEventsEntityHandler.cs:line 78
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
watch : Exited with error code 134

this seems to happen on the consumer.Close() method, it still makes my whole micro-service crash, i've reworked my code to make sure than I dont call Dispose twice or Consume after a Dispose

edenhill commented 5 years ago

That error indicates that you are calling Assign() on a Close()d or disposed consumer, that is not valid usage.

Rakiah commented 5 years ago

Thank you for your feedback, are you absolutely sure about that ? because the error actually throw on a consumer.Close() line

   at Confluent.Kafka.Consumer`2.Close()
   at Constellation.Common.Kafka.BaseKafkaClient.Consume() in /src/Common/Common.Kafka/Common.Sources/Kafka/Clients/BaseKafkaClient.cs:line 129

Basically BaseKafkaClient.cs at line 129 is consumer.Close()

I mean I would understand if the error was actually thrown on an consumer.Assign()

Rakiah commented 5 years ago

A bit more log, this one is a bit different, but it defintely show that the problem arise while trying to "Close" the kafka consumer


Unhandled Exception: Confluent.Kafka.KafkaException: Local: Broker handle destroyed
   at Confluent.Kafka.Impl.SafeKafkaHandle.Assign(IEnumerable`1 partitions)
   at Confluent.Kafka.Consumer`2.Assign(IEnumerable`1 partitions)
   at Confluent.Kafka.Consumer`2.RebalanceCallback(IntPtr rk, ErrorCode err, IntPtr partitions, IntPtr opaque)
   at Confluent.Kafka.Impl.NativeMethods.NativeMethods_Debian9.rd_kafka_consumer_close(IntPtr rk)
   at Confluent.Kafka.Impl.SafeKafkaHandle.ConsumerClose()
   at Confluent.Kafka.Consumer`2.Close()
   at Constellation.Common.Kafka.BaseKafkaClient.Consume() in /src/Common/Common.Kafka/Common.Sources/Kafka/Clients/BaseKafkaClient.cs:line 131
watch : Exited with error code 134

Yet i've tried to put this:

129:               try
130:               {
131:                   consumer.Close();
132:                   consumer.Dispose();
133:                }
134:                catch (Exception e)
135:                {
136:                    Console.WriteLine($"VERY BAD AND FATAL ERROR THAT HAPPENS DURING consumer.Close or consumer.Dispose: {e.Message} at {e.StackTrace}");
137:                }

but the log is never called, it just stop completely the application :x

Rakiah commented 5 years ago

As I saw from the actual code in consumer.cs of confluent-kafka-dotnet, there is no need to call both close and then dispose, as close will actually dispose, however the samples codes kind of point to the direction that it should be made this way, as there is both a Using statement, and a Close statement once OperationCanceledException was caught, i've tried removing the actual Dispose to only leave the Close part to see if it works better, I will report likely tomorrow If it help in any ways

Rakiah commented 5 years ago

After having removed the Dispose method and left only the Close statement, I still receive the following error

Unhandled Exception: Confluent.Kafka.KafkaException: Local: Broker handle destroyed

   at Confluent.Kafka.Impl.SafeKafkaHandle.Assign(IEnumerable`1 partitions)

   at Confluent.Kafka.Consumer`2.Assign(IEnumerable`1 partitions)

   at Confluent.Kafka.Consumer`2.RebalanceCallback(IntPtr rk, ErrorCode err, IntPtr partitions, IntPtr opaque)

   at Confluent.Kafka.Impl.NativeMethods.NativeMethods_Debian9.rd_kafka_consumer_close(IntPtr rk)

   at Confluent.Kafka.Impl.SafeKafkaHandle.ConsumerClose()

   at Confluent.Kafka.Consumer`2.Close()

   at Constellation.Common.Kafka.BaseKafkaClient.Consume() in /src/Common/Common.Kafka/Common.Sources/Kafka/Clients/BaseKafkaClient.cs:line 129

   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)

I feel like i've met a dead-end there and I cannot understand what's I am doing wrong here

edenhill commented 5 years ago

This error indicates that you're trying to close the same consumer multiple times, or trying to close an already disposed consumer

pranavrth commented 4 months ago

I think Magnus comment helped here. Closing the issue.

confluentinc / confluent-kafka-dotnet

After upgrading to latest version; I get random container crashes stating: #1088