Hang on rd_kafka_destroy() #3470
Comments
|
This typically happens when there is an outstanding librdkafka object reference, see https://github.com/edenhill/librdkafka/blob/master/INTRODUCTION.md#termination Also try to reproduce on latest master, thanks. |
|
From the test it does not seem like there is any object references besides For me it seems problem happens when broker tries to reconnect to shutting down client. |
|
@edenhill Should I open new issue for this? |
|
Could you try reproducing this on latest master with debug=all and provide the logs? Thanks |
|
No problem. |
|
So I was able to replicate this similar issue in k8s. It happened in a dev cluster during a failure test where the node was shutdown then brought back up. There were multiple apps with the same base image and using the same node-rdkafka (which uses librdkafka under the hood) and they all were in a stuck state trying to connect to the producer. The logs looked similar to the ones @pranasge showed. I was able to replicate this more than once so it's possible to get it in the state if you are trying. To replicate here are the steps to follow:
The app should be stuck in the producer connecting state and shouldn't really crash but it wouldn't do anything. A way to get it out is to just reboot the container and it should recover. Node version: v14.19.1 kind version: v0.12.0 go1.17.8 darwin/amd64 OS: Mac OS Big Sir Version 11.6 |
|
I believe I can reproduce in a rather simple scenraio. In case you want to jump on a session on my machine - I'll keep the setup and try to dig into it further. i modified the afterEach hook to look like this: afterEach(function(done) {
console.log('after each started');
var finished = 0;
var called = false;
function maybeDone(err) {
console.log('why err', err);
if (called) {
return;
}
finished++;
if (err) {
called = true;
return done(err);
}
if (finished === 2) {
done();
}
}
console.log('start disconnect');
producer.disconnect(function(err) {
maybeDone(err);
consumer.disconnect(function(err) {
maybeDone(err);
});
});
});the actual test: it('should be able to produce and consume messages: consumeLoop', function(done) {
console.log('start test');
var key = 'key';
crypto.randomBytes(4096, function(ex, buffer) {
console.log('rannd created');
producer.setPollInterval(10);
producer.once('delivery-report', function(err, report) {
if (!err) {
t.equal(topic, report.topic, 'invalid delivery-report topic');
t.equal(key, report.key, 'invalid delivery-report key');
t.ok(report.offset >= 0, 'invalid delivery-report offset');
}
});
consumer.on('data', function(message) {
console.log('on data');
t.equal(buffer.toString(), message.value.toString(), 'invalid message value');
t.equal(key, message.key, 'invalid message key');
t.equal(topic, message.topic, 'invalid message topic');
t.ok(message.offset >= 0, 'invalid message offset');
done();
});
consumer.subscribe([topic]);
consumer.consume();
setTimeout(function() {
console.log('PRODUCE - should be able to produce and consume messages: consumeLoop')
producer.produce(topic, null, buffer, key);
}, 2000);
});
});the debug logs: kafka-mocha#producer-17 connected to kafka server
rdkafka#consumer-16 connected to kafka server
start test
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey Heartbeat (12) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey LeaveGroup (13) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey SyncGroup (14) Versions 0..5
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DescribeGroups (15) Versions 0..5
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey ListGroups (16) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey SaslHandshake (17) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey ApiVersion (18) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey CreateTopics (19) Versions 0..7
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DeleteTopics (20) Versions 0..6
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DeleteRecords (21) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey InitProducerId (22) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey OffsetForLeaderEpoch (23) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AddPartitionsToTxn (24) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AddOffsetsToTxn (25) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey EndTxn (26) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey WriteTxnMarkers (27) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey TxnOffsetCommit (28) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DescribeAcls (29) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey CreateAcls (30) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DeleteAcls (31) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DescribeConfigs (32) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AlterConfigs (33) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AlterReplicaLogDirs (34) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DescribeLogDirs (35) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey SaslAuthenticate (36) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey CreatePartitions (37) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey CreateDelegationToken (38) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey RenewDelegationToken (39) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey ExpireDelegationToken (40) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DescribeDelegationToken (41) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DeleteGroups (42) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey ElectLeadersRequest (43) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey IncrementalAlterConfigsRequest (44) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AlterPartitionReassignmentsRequest (45) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey ListPartitionReassignmentsRequest (46) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey OffsetDeleteRequest (47) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DescribeClientQuotasRequest (48) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AlterClientQuotasRequest (49) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey DescribeUserScramCredentialsRequest (50) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AlterUserScramCredentialsRequest (51) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey AlterIsrRequest (56) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey UpdateFeaturesRequest (57) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey Unknown-60? (60) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey Unknown-61? (61) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey Unknown-65? (65) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey Unknown-66? (66) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: ApiKey Unknown-67? (67) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature MsgVer1: Produce (2..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature MsgVer1: Fetch (2..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature MsgVer1
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature MsgVer2: Produce (3..3) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature MsgVer2: Fetch (4..4) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature MsgVer2
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature ApiVersion: ApiVersion (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature ApiVersion
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerGroupCoordinator: FindCoordinator (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature BrokerGroupCoordinator
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerBalancedConsumer: FindCoordinator (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerBalancedConsumer: OffsetCommit (1..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerBalancedConsumer: OffsetFetch (1..1) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerBalancedConsumer: JoinGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerBalancedConsumer: SyncGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerBalancedConsumer: Heartbeat (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature BrokerBalancedConsumer: LeaveGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature BrokerBalancedConsumer
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature ThrottleTime: Produce (1..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature ThrottleTime: Fetch (1..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature ThrottleTime
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature Sasl: JoinGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature Sasl
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature SaslHandshake: SaslHandshake (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature SaslHandshake
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature LZ4: FindCoordinator (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature LZ4
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature OffsetTime: ListOffsets (1..1) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature OffsetTime
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature IdempotentProducer: InitProducerId (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature IdempotentProducer
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature ZSTD: Produce (7..7) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature ZSTD: Fetch (10..10) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature ZSTD
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature SaslAuthReq: SaslHandshake (1..1) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Feature SaslAuthReq: SaslAuthenticate (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Enabling feature SaslAuthReq
{ severity: 7, fac: 'FEATURE' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Updated enabled protocol features to MsgVer1,ApiVersion,BrokerBalancedConsumer,ThrottleTime,Sasl,SaslHandshake,BrokerGroupCoordinator,LZ4,OffsetTime,MsgVer2,IdempotentProducer,ZSTD,SaslAuthReq
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Broker changed state APIVERSION_QUERY -> UP
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'METADATA' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Request metadata for brokers only: connected
{ severity: 7, fac: 'METADATA' } [thrd:app]: localhost:9092/bootstrap: Request metadata for all topics: application requested
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Sent MetadataRequest (v4, 30 bytes @ 0, CorrId 2)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Sent MetadataRequest (v4, 30 bytes @ 0, CorrId 3)
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Received MetadataResponse (v4, 61 bytes, CorrId 2, rtt 2.89ms)
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: ===== Received metadata: connected =====
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: ClusterId: cP7EsIPWS4eZiKZcsK51kQ, ControllerId: 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: 1 brokers, 0 topics
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: Broker #0/1: localhost:9092 NodeId 1
{ severity: 7, fac: 'UPDATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: NodeId changed from -1 to 1
{ severity: 7, fac: 'UPDATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Name changed from localhost:9092/bootstrap to localhost:9092/1
{ severity: 7, fac: 'LEADER' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Mapped 0 partition(s) to broker
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker changed state UP -> UPDATE
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker changed state UPDATE -> UP
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'CLUSTERID' } [thrd:main]: localhost:9092/1: ClusterId update "" -> "cP7EsIPWS4eZiKZcsK51kQ"
{ severity: 7, fac: 'CONTROLLERID' } [thrd:main]: localhost:9092/1: ControllerId update -1 -> 1
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received MetadataResponse (v4, 15216 bytes, CorrId 3, rtt 3.85ms)
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: ===== Received metadata: application requested =====
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: ClusterId: cP7EsIPWS4eZiKZcsK51kQ, ControllerId: 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: 1 brokers, 67 topics
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Broker #0/1: localhost:9092 NodeId 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #0/67: admin-test-topic-newparts2-1657239017952 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #1/67: admin-test-topic-newparts-1657237453679 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #2/67: admin-test-topic-1657238382469 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #3/67: admin-test-topic-newparts-1657237059590 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #4/67: transaction_output_1657237453721_382 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #5/67: test4 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #6/67: admin-test-topic-newparts2-1657239474141 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #7/67: admin-test-topic-2bdeleted-1657237453679 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #8/67: test2 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #9/67: admin-test-topic-newparts2-1657238856833 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #10/67: admin-test-topic-1657238169695 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #11/67: test6 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #12/67: admin-test-topic-2bdeleted-1657239017952 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #13/67: admin-test-topic-newparts-1657239474141 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #14/67: test with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #15/67: transaction_input_1657237453721_382 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #16/67: admin-test-topic-2bdeleted-1657238031002 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #17/67: admin-test-topic-newparts-1657238169695 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #18/67: __transaction_state with 50 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #19/67: admin-test-topic-2bdeleted-1657238257447 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #20/67: admin-test-topic-newparts2-1657236691954 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #21/67: admin-test-topic-1657237059590 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #22/67: admin-test-topic-newparts-1657238382469 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #23/67: test3 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #24/67: admin-test-topic-newparts-1657237285122 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #25/67: admin-test-topic-1657237285122 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #26/67: admin-test-topic-2bdeleted-1657236826605 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #27/67: admin-test-topic-newparts2-1657238169695 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #28/67: admin-test-topic-newparts2-1657236826605 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #29/67: admin-test-topic-2bdeleted-1657237285122 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #30/67: admin-test-topic-2bdeleted-1657238169695 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #31/67: test7 with 2 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #32/67: admin-test-topic-newparts-1657238277180 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #33/67: admin-test-topic-newparts-1657236691954 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #34/67: admin-test-topic-newparts2-1657239533960 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #35/67: admin-test-topic-1657238856833 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #36/67: admin-test-topic-newparts2-1657237059590 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #37/67: admin-test-topic-1657239474141 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #38/67: __consumer_offsets with 50 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #39/67: admin-test-topic-1657238257447 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #40/67: admin-test-topic-1657237453679 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #41/67: admin-test-topic-1657236691954 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #42/67: admin-test-topic-newparts2-1657237285122 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #43/67: admin-test-topic-1657236826605 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #44/67: admin-test-topic-newparts-1657239533960 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #45/67: admin-test-topic-2bdeleted-1657238382469 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #46/67: admin-test-topic-2bdeleted-1657238277180 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #47/67: admin-test-topic-1657239017952 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #48/67: admin-test-topic-2bdeleted-1657238856833 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #49/67: admin-test-topic-2bdeleted-1657236691954 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #50/67: admin-test-topic-newparts-1657236826605 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #51/67: admin-test-topic-1657239533960 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #52/67: admin-test-topic-2bdeleted-1657239533960 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #53/67: admin-test-topic-newparts2-1657237453679 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #54/67: admin-test-topic-2bdeleted-1657237059590 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #55/67: admin-test-topic-newparts2-1657238031002 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #56/67: admin-test-topic-newparts2-1657238382469 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #57/67: test5 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #58/67: admin-test-topic-newparts2-1657238257447 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #59/67: admin-test-topic-1657238277180 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #60/67: admin-test-topic-newparts-1657238856833 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #61/67: admin-test-topic-1657238031002 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #62/67: admin-test-topic-newparts-1657238031002 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #63/67: admin-test-topic-2bdeleted-1657239474141 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #64/67: admin-test-topic-newparts-1657238257447 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #65/67: admin-test-topic-newparts-1657239017952 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #66/67: admin-test-topic-newparts2-1657238277180 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: Absolute update of metadata cache with 67 topic(s)
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Caching full metadata with 1 broker(s) and 67 topic(s): application requested
{ severity: 7, fac: 'CGRPQUERY' } [thrd:main]: localhost:9092/bootstrap: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": querying for coordinator: intervaled in state query-coord
{ severity: 7, fac: 'METADATA' } [thrd:app]: localhost:9092/bootstrap: Request metadata for all topics: application requested
{ severity: 7, fac: 'CGRPSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed state query-coord -> wait-coord (join-state init)
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Sent MetadataRequest (v4, 26 bytes @ 0, CorrId 2)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Sent MetadataRequest (v4, 26 bytes @ 0, CorrId 3)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Sent FindCoordinatorRequest (v2, 80 bytes @ 0, CorrId 4)
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: Received MetadataResponse (v4, 61 bytes, CorrId 2, rtt 2.73ms)
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: ===== Received metadata: connected =====
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: ClusterId: cP7EsIPWS4eZiKZcsK51kQ, ControllerId: 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: 1 brokers, 0 topics
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/bootstrap: Broker #0/1: localhost:9092 NodeId 1
{ severity: 7, fac: 'UPDATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/bootstrap: NodeId changed from -1 to 1
{ severity: 7, fac: 'UPDATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Name changed from localhost:9092/bootstrap to localhost:9092/1
{ severity: 7, fac: 'LEADER' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Mapped 0 partition(s) to broker
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker changed state UP -> UPDATE
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker changed state UPDATE -> UP
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'CLUSTERID' } [thrd:main]: localhost:9092/1: ClusterId update "" -> "cP7EsIPWS4eZiKZcsK51kQ"
{ severity: 7, fac: 'CONTROLLERID' } [thrd:main]: localhost:9092/1: ControllerId update -1 -> 1
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received MetadataResponse (v4, 15216 bytes, CorrId 3, rtt 4.26ms)
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: ===== Received metadata: application requested =====
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: ClusterId: cP7EsIPWS4eZiKZcsK51kQ, ControllerId: 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: 1 brokers, 67 topics
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Broker #0/1: localhost:9092 NodeId 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #0/67: admin-test-topic-newparts2-1657239017952 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #1/67: admin-test-topic-newparts-1657237453679 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #2/67: admin-test-topic-1657238382469 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #3/67: admin-test-topic-newparts-1657237059590 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #4/67: transaction_output_1657237453721_382 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #5/67: test4 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #6/67: admin-test-topic-newparts2-1657239474141 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #7/67: admin-test-topic-2bdeleted-1657237453679 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #8/67: test2 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #9/67: admin-test-topic-newparts2-1657238856833 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #10/67: admin-test-topic-1657238169695 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #11/67: test6 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #12/67: admin-test-topic-2bdeleted-1657239017952 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #13/67: admin-test-topic-newparts-1657239474141 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #14/67: test with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #15/67: transaction_input_1657237453721_382 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #16/67: admin-test-topic-2bdeleted-1657238031002 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #17/67: admin-test-topic-newparts-1657238169695 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #18/67: __transaction_state with 50 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #19/67: admin-test-topic-2bdeleted-1657238257447 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #20/67: admin-test-topic-newparts2-1657236691954 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #21/67: admin-test-topic-1657237059590 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #22/67: admin-test-topic-newparts-1657238382469 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #23/67: test3 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #24/67: admin-test-topic-newparts-1657237285122 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #25/67: admin-test-topic-1657237285122 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #26/67: admin-test-topic-2bdeleted-1657236826605 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #27/67: admin-test-topic-newparts2-1657238169695 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #28/67: admin-test-topic-newparts2-1657236826605 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #29/67: admin-test-topic-2bdeleted-1657237285122 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #30/67: admin-test-topic-2bdeleted-1657238169695 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #31/67: test7 with 2 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #32/67: admin-test-topic-newparts-1657238277180 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #33/67: admin-test-topic-newparts-1657236691954 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #34/67: admin-test-topic-newparts2-1657239533960 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #35/67: admin-test-topic-1657238856833 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #36/67: admin-test-topic-newparts2-1657237059590 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #37/67: admin-test-topic-1657239474141 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #38/67: __consumer_offsets with 50 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #39/67: admin-test-topic-1657238257447 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #40/67: admin-test-topic-1657237453679 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #41/67: admin-test-topic-1657236691954 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #42/67: admin-test-topic-newparts2-1657237285122 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #43/67: admin-test-topic-1657236826605 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #44/67: admin-test-topic-newparts-1657239533960 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #45/67: admin-test-topic-2bdeleted-1657238382469 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #46/67: admin-test-topic-2bdeleted-1657238277180 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #47/67: admin-test-topic-1657239017952 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #48/67: admin-test-topic-2bdeleted-1657238856833 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #49/67: admin-test-topic-2bdeleted-1657236691954 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #50/67: admin-test-topic-newparts-1657236826605 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #51/67: admin-test-topic-1657239533960 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #52/67: admin-test-topic-2bdeleted-1657239533960 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #53/67: admin-test-topic-newparts2-1657237453679 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #54/67: admin-test-topic-2bdeleted-1657237059590 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #55/67: admin-test-topic-newparts2-1657238031002 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #56/67: admin-test-topic-newparts2-1657238382469 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #57/67: test5 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #58/67: admin-test-topic-newparts2-1657238257447 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #59/67: admin-test-topic-1657238277180 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #60/67: admin-test-topic-newparts-1657238856833 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #61/67: admin-test-topic-1657238031002 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #62/67: admin-test-topic-newparts-1657238031002 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #63/67: admin-test-topic-2bdeleted-1657239474141 with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #64/67: admin-test-topic-newparts-1657238257447 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #65/67: admin-test-topic-newparts-1657239017952 with 20 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Topic #66/67: admin-test-topic-newparts2-1657238277180 with 4 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: Absolute update of metadata cache with 67 topic(s)
{ severity: 7, fac: 'METADATA' } [thrd:main]: localhost:9092/1: Caching full metadata with 1 broker(s) and 67 topic(s): application requested
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received FindCoordinatorResponse (v2, 31 bytes, CorrId 4, rtt 5.25ms)
{ severity: 7, fac: 'CGRPCOORD' } [thrd:main]: localhost:9092/1: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" coordinator is localhost:9092 id 1
{ severity: 7, fac: 'CGRPCOORD' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changing coordinator -1 -> 1
{ severity: 7, fac: 'COORDSET' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" coordinator set to broker localhost:9092/1
{ severity: 7, fac: 'CGRPSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed state wait-coord -> wait-broker-transport (join-state init)
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'NODENAME' } [thrd:main]: GroupCoordinator: Broker nodename changed from "" to "localhost:9092"
{ severity: 7, fac: 'NODEID' } [thrd:main]: GroupCoordinator: Broker nodeid changed from -1 to 1
{ severity: 7, fac: 'CGRPQUERY' } [thrd:main]: localhost:9092/1: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": querying for coordinator: intervaled in state wait-broker-transport
{ severity: 7, fac: 'CONNECT' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received CONNECT op
{ severity: 7, fac: 'STATE' } [thrd:GroupCoordinator]: GroupCoordinator: Broker changed state INIT -> TRY_CONNECT
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'CONNECT' } [thrd:GroupCoordinator]: GroupCoordinator/1: broker in state TRY_CONNECT connecting
{ severity: 7, fac: 'STATE' } [thrd:GroupCoordinator]: GroupCoordinator: Broker changed state TRY_CONNECT -> CONNECT
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Sent FindCoordinatorRequest (v2, 80 bytes @ 0, CorrId 5)
{ severity: 7, fac: 'CONNECT' } [thrd:GroupCoordinator]: GroupCoordinator/1: Connecting to ipv6#[::1]:9092 (plaintext) with socket 42
{ severity: 7, fac: 'CONNECT' } [thrd:GroupCoordinator]: GroupCoordinator/1: Connected to ipv6#[::1]:9092
{ severity: 7, fac: 'CONNECTED' } [thrd:GroupCoordinator]: GroupCoordinator/1: Connected (#1)
{ severity: 7, fac: 'FEATURE' } [thrd:GroupCoordinator]: GroupCoordinator/1: Updated enabled protocol features +ApiVersion to ApiVersion
{ severity: 7, fac: 'STATE' } [thrd:GroupCoordinator]: GroupCoordinator: Broker changed state CONNECT -> APIVERSION_QUERY
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent ApiVersionRequest (v3, 40 bytes @ 0, CorrId 1)
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received FindCoordinatorResponse (v2, 31 bytes, CorrId 5, rtt 2.15ms)
{ severity: 7, fac: 'CGRPCOORD' } [thrd:main]: localhost:9092/1: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" coordinator is localhost:9092 id 1
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received ApiVersionResponse (v3, 431 bytes, CorrId 1, rtt 2.97ms)
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Broker API support:
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Produce (0) Versions 0..9
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Fetch (1) Versions 0..13
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey ListOffsets (2) Versions 0..7
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Metadata (3) Versions 0..12
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey LeaderAndIsr (4) Versions 0..5
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey StopReplica (5) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey UpdateMetadata (6) Versions 0..7
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey ControlledShutdown (7) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey OffsetCommit (8) Versions 0..8
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey OffsetFetch (9) Versions 0..8
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey FindCoordinator (10) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey JoinGroup (11) Versions 0..7
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Heartbeat (12) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey LeaveGroup (13) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey SyncGroup (14) Versions 0..5
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DescribeGroups (15) Versions 0..5
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey ListGroups (16) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey SaslHandshake (17) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey ApiVersion (18) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey CreateTopics (19) Versions 0..7
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DeleteTopics (20) Versions 0..6
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DeleteRecords (21) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey InitProducerId (22) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey OffsetForLeaderEpoch (23) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AddPartitionsToTxn (24) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AddOffsetsToTxn (25) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey EndTxn (26) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey WriteTxnMarkers (27) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey TxnOffsetCommit (28) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DescribeAcls (29) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey CreateAcls (30) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DeleteAcls (31) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DescribeConfigs (32) Versions 0..4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AlterConfigs (33) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AlterReplicaLogDirs (34) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DescribeLogDirs (35) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey SaslAuthenticate (36) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey CreatePartitions (37) Versions 0..3
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey CreateDelegationToken (38) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey RenewDelegationToken (39) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey ExpireDelegationToken (40) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DescribeDelegationToken (41) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DeleteGroups (42) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey ElectLeadersRequest (43) Versions 0..2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey IncrementalAlterConfigsRequest (44) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AlterPartitionReassignmentsRequest (45) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey ListPartitionReassignmentsRequest (46) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey OffsetDeleteRequest (47) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DescribeClientQuotasRequest (48) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AlterClientQuotasRequest (49) Versions 0..1
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey DescribeUserScramCredentialsRequest (50) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AlterUserScramCredentialsRequest (51) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey AlterIsrRequest (56) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey UpdateFeaturesRequest (57) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Unknown-60? (60) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Unknown-61? (61) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Unknown-65? (65) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Unknown-66? (66) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: ApiKey Unknown-67? (67) Versions 0..0
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature MsgVer1: Produce (2..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature MsgVer1: Fetch (2..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature MsgVer1
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature MsgVer2: Produce (3..3) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature MsgVer2: Fetch (4..4) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature MsgVer2
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature ApiVersion: ApiVersion (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature ApiVersion
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerGroupCoordinator: FindCoordinator (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature BrokerGroupCoordinator
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerBalancedConsumer: FindCoordinator (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerBalancedConsumer: OffsetCommit (1..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerBalancedConsumer: OffsetFetch (1..1) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerBalancedConsumer: JoinGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerBalancedConsumer: SyncGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerBalancedConsumer: Heartbeat (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature BrokerBalancedConsumer: LeaveGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature BrokerBalancedConsumer
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature ThrottleTime: Produce (1..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature ThrottleTime: Fetch (1..2) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature ThrottleTime
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature Sasl: JoinGroup (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature Sasl
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature SaslHandshake: SaslHandshake (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature SaslHandshake
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature LZ4: FindCoordinator (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature LZ4
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature OffsetTime: ListOffsets (1..1) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature OffsetTime
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature IdempotentProducer: InitProducerId (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature IdempotentProducer
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature ZSTD: Produce (7..7) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature ZSTD: Fetch (10..10) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature ZSTD
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature SaslAuthReq: SaslHandshake (1..1) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Feature SaslAuthReq: SaslAuthenticate (0..0) supported by broker
{ severity: 7, fac: 'APIVERSION' } [thrd:GroupCoordinator]: GroupCoordinator/1: Enabling feature SaslAuthReq
{ severity: 7, fac: 'FEATURE' } [thrd:GroupCoordinator]: GroupCoordinator/1: Updated enabled protocol features to MsgVer1,ApiVersion,BrokerBalancedConsumer,ThrottleTime,Sasl,SaslHandshake,BrokerGroupCoordinator,LZ4,OffsetTime,MsgVer2,IdempotentProducer,ZSTD,SaslAuthReq
{ severity: 7, fac: 'STATE' } [thrd:GroupCoordinator]: GroupCoordinator: Broker changed state APIVERSION_QUERY -> UP
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'METADATA' } [thrd:GroupCoordinator]: GroupCoordinator/1: Request metadata for brokers only: connected
{ severity: 7, fac: 'CGRPSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed state wait-broker-transport -> up (join-state init)
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'DUMP' } [thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_QRY' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'ASSIGNDONE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": assignment operations done in join-state init (rebalance rejoin=false)
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent MetadataRequest (v4, 26 bytes @ 0, CorrId 2)
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received MetadataResponse (v4, 61 bytes, CorrId 2, rtt 2.13ms)
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: ===== Received metadata: connected =====
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: ClusterId: cP7EsIPWS4eZiKZcsK51kQ, ControllerId: 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: 1 brokers, 0 topics
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: Broker #0/1: localhost:9092 NodeId 1
rannd created
{ severity: 7, fac: 'CGRPOP' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" received op SUBSCRIBE in state up (join-state init)
{ severity: 7, fac: 'SUBSCRIBE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": subscribe to new subscription of 1 topics (join-state init)
{ severity: 7, fac: 'JOIN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": join with 0 subscribed topic(s)
{ severity: 7, fac: 'CGRPMETADATA' } [thrd:main]: consumer join: metadata for subscription is up to date (22ms old)
{ severity: 7, fac: 'SUBSCRIPTION' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": effective subscription list changed from 0 to 1 topic(s):
{ severity: 7, fac: 'SUBSCRIPTION' } [thrd:main]: Topic test with 1 partition(s)
{ severity: 7, fac: 'JOIN' } [thrd:main]: localhost:9092/1: Joining group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" with 1 subscribed topic(s) and member id ""
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state init -> wait-join (state up)
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent JoinGroupRequest (v5, 172 bytes @ 0, CorrId 3)
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received JoinGroupResponse (v5, 64 bytes, CorrId 3, rtt 2.56ms)
{ severity: 7, fac: 'JOINGROUP' } [thrd:main]: JoinGroup response: GenerationId -1, Protocol , LeaderId , my MemberId rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d, member metadata count 0: Broker: Group member needs a valid member ID
{ severity: 7, fac: 'REQERR' } [thrd:main]: GroupCoordinator/1: JoinGroupRequest failed: Broker: Group member needs a valid member ID: explicit actions Ignore
{ severity: 7, fac: 'MEMBERID' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": updating member id "" -> "rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d"
{ severity: 7, fac: 'REJOIN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": Rejoining group without an assignment: JoinGroup error: Broker: Group member needs a valid member ID
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state wait-join -> init (state up)
{ severity: 7, fac: 'JOIN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": join with 1 subscribed topic(s)
{ severity: 7, fac: 'CGRPMETADATA' } [thrd:main]: consumer join: metadata for subscription is up to date (25ms old)
{ severity: 7, fac: 'JOIN' } [thrd:main]: localhost:9092/1: Joining group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" with 1 subscribed topic(s) and member id "rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d"
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state init -> wait-join (state up)
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent JoinGroupRequest (v5, 216 bytes @ 0, CorrId 4)
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received JoinGroupResponse (v5, 185 bytes, CorrId 4, rtt 3.35ms)
{ severity: 7, fac: 'JOINGROUP' } [thrd:main]: JoinGroup response: GenerationId 1, Protocol range, LeaderId rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d (me), my MemberId rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d, member metadata count 1: (no error)
{ severity: 7, fac: 'JOINGROUP' } [thrd:main]: I am elected leader for group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" with 1 member(s)
{ severity: 7, fac: 'GRPLEADER' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": resetting group leader info: JoinGroup response clean-up
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state wait-join -> wait-metadata (state up)
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: Request metadata for 1 topic(s): partition assignor
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent MetadataRequest (v4, 32 bytes @ 0, CorrId 5)
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received MetadataResponse (v4, 100 bytes, CorrId 5, rtt 1.73ms)
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: ===== Received metadata (for 1 requested topics): partition assignor =====
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: ClusterId: cP7EsIPWS4eZiKZcsK51kQ, ControllerId: 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: 1 brokers, 1 topics
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: Broker #0/1: localhost:9092 NodeId 1
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: Topic #0/1: test with 1 partitions
{ severity: 7, fac: 'METADATA' } [thrd:main]: GroupCoordinator/1: 1/1 requested topic(s) seen in metadata
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" running range assignor for 1 member(s) and 1 eligible subscribed topic(s):
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: Member "rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d" (me) with 0 owned partition(s) and 1 subscribed topic(s):
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: test [-1]
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: range: Topic test with 1 partition(s) and 1 subscribing member(s)
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: range: Member "rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d": assigned topic test partitions 0..0
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" range assignment for 1 member(s) finished in 0.009ms:
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: Member "rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d" (me) assigned 1 partition(s):
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: test [0]
{ severity: 7, fac: 'ASSIGNOR' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": "range" assignor run for 1 member(s)
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state wait-metadata -> wait-sync (state up)
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent SyncGroupRequest (v3, 209 bytes @ 0, CorrId 6)
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received SyncGroupResponse (v3, 34 bytes, CorrId 6, rtt 3.42ms)
{ severity: 7, fac: 'SYNCGROUP' } [thrd:main]: SyncGroup response: Success (24 bytes of MemberState data)
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: List with 1 partition(s):
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: test [0] offset INVALID
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state wait-sync -> wait-assign-call (state up)
{ severity: 7, fac: 'ASSIGN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": new assignment of 1 partition(s) in join-state wait-assign-call
{ severity: 7, fac: 'CLEARASSIGN' } [thrd:main]: No current assignment to clear
{ severity: 7, fac: 'TOPIC' } [thrd:main]: New local topic: test
{ severity: 7, fac: 'TOPPARNEW' } [thrd:main]: NEW test [-1] 0x103807c60 refcnt 0x103807cf0 (at rd_kafka_topic_new0:465)
{ severity: 7, fac: 'STATE' } [thrd:main]: Topic test changed state unknown -> exists
{ severity: 7, fac: 'PARTCNT' } [thrd:main]: Topic test partition count changed from 0 to 1
{ severity: 7, fac: 'TOPPARNEW' } [thrd:main]: NEW test [0] 0x1038052d0 refcnt 0x103805360 (at rd_kafka_topic_partition_cnt_update:798)
{ severity: 7, fac: 'METADATA' } [thrd:main]: Topic test partition 0 Leader 1
{ severity: 7, fac: 'BRKDELGT' } [thrd:main]: test [0]: delegate to broker localhost:9092/1 (rktp 0x1038052d0, term 0, ref 2)
{ severity: 7, fac: 'BRKDELGT' } [thrd:main]: test [0]: delegating to broker localhost:9092/1 for partition with 0 messages (0 bytes) queued
{ severity: 7, fac: 'BRKMIGR' } [thrd:main]: Migrating topic test [0] 0x1038052d0 from (none) to localhost:9092/1 (sending PARTITION_JOIN to localhost:9092/1)
{ severity: 7, fac: 'CONF' } [thrd:main]: Topic "test" configuration (default_topic_conf):
{ severity: 7, fac: 'CONF' } [thrd:main]: auto.offset.reset = largest
{ severity: 7, fac: 'DESIRED' } [thrd:main]: test [0]: marking as DESIRED
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Added 1 partition(s) to assignment which now consists of 1 partition(s) where of 1 are in pending state and 0 are being queried
{ severity: 7, fac: 'PAUSE' } [thrd:main]: Resuming fetchers for 1 assigned partition(s): assign called
{ severity: 7, fac: 'RESUME' } [thrd:main]: Library resuming 1 partition(s)
{ severity: 7, fac: 'BARRIER' } [thrd:main]: test [0]: rd_kafka_toppar_op_pause_resume:2449: new version barrier v2
{ severity: 7, fac: 'RESUME' } [thrd:main]: Resume test [0] (v2)
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state wait-assign-call -> steady (state up)
{ severity: 7, fac: 'DUMP' } [thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: List with 1 partition(s):
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: test [0] offset STORED
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: List with 1 partition(s):
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: test [0] offset STORED
{ severity: 7, fac: 'DUMP_QRY' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'SRVPEND' } [thrd:main]: Querying committed offset for pending assigned partition test [0]
{ severity: 7, fac: 'OFFSETFETCH' } [thrd:main]: Fetching committed offsets for 1 pending partition(s) in assignment
{ severity: 7, fac: 'TOPBRK' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0]: joining broker (rktp 0x1038052d0, 0 message(s) queued)
{ severity: 7, fac: 'OFFSET' } [thrd:main]: GroupCoordinator/1: OffsetFetchRequest(v7) for 1/1 partition(s)
{ severity: 7, fac: 'OFFSET' } [thrd:main]: GroupCoordinator/1: Fetch committed offsets for 1/1 partition(s)
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Current assignment of 1 partition(s) with 1 pending adds, 1 offset queries, 0 partitions awaiting stop and 0 offset commits in progress
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": setting group assignment to 1 partition(s)
{ severity: 7, fac: 'GRPASSIGNMENT' } [thrd:main]: List with 1 partition(s):
{ severity: 7, fac: 'GRPASSIGNMENT' } [thrd:main]: test [0] offset STORED
{ severity: 7, fac: 'HEARTBEAT' } [thrd:main]: GroupCoordinator/1: Heartbeat for group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" generation id 1
{ severity: 7, fac: 'OP' } [thrd:main]: test [0] received op PAUSE (v2) in fetch-state none (opv1)
{ severity: 7, fac: 'RESUME' } [thrd:main]: Not resuming test [0]: partition is not paused by library
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent OffsetFetchRequest (v7, 93 bytes @ 0, CorrId 7)
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent HeartbeatRequest (v3, 131 bytes @ 0, CorrId 8)
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received OffsetFetchResponse (v7, 36 bytes, CorrId 7, rtt 2.02ms)
{ severity: 7, fac: 'OFFSETFETCH' } [thrd:main]: GroupCoordinator/1: OffsetFetchResponse: test [0] offset -1, metadata 0 byte(s): NO_ERROR
{ severity: 7, fac: 'OFFFETCH' } [thrd:main]: GroupCoordinator/1: OffsetFetch for 1/1 partition(s) (0 unstable partition(s)) returned Success
{ severity: 7, fac: 'OFFSETFETCH' } [thrd:main]: Adding test [0] back to pending list with offset INVALID
{ severity: 7, fac: 'DUMP' } [thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: List with 1 partition(s):
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: test [0] offset STORED
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: List with 1 partition(s):
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: test [0] offset INVALID
{ severity: 7, fac: 'DUMP_QRY' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'SRVPEND' } [thrd:main]: Starting pending assigned partition test [0] at offset INVALID
{ severity: 7, fac: 'BARRIER' } [thrd:main]: test [0]: rd_kafka_toppar_op_pause_resume:2449: new version barrier v3
{ severity: 7, fac: 'RESUME' } [thrd:main]: Resume test [0] (v3)
{ severity: 7, fac: 'BARRIER' } [thrd:main]: test [0]: rd_kafka_toppar_op_fetch_start:2363: new version barrier v4
{ severity: 7, fac: 'CONSUMER' } [thrd:main]: Start consuming test [0] at offset INVALID (v4)
{ severity: 7, fac: 'ASSIGNDONE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": assignment operations done in join-state steady (rebalance rejoin=false)
{ severity: 7, fac: 'OP' } [thrd:main]: test [0] received op PAUSE (v3) in fetch-state none (opv2)
{ severity: 7, fac: 'RESUME' } [thrd:main]: Not resuming test [0]: partition is not paused by library
{ severity: 7, fac: 'OP' } [thrd:main]: test [0] received op FETCH_START (v4) in fetch-state none (opv3)
{ severity: 7, fac: 'FETCH' } [thrd:main]: Start fetch for test [0] in state none at offset INVALID (v4)
{ severity: 7, fac: 'PARTSTATE' } [thrd:main]: Partition test [0] changed fetch state none -> offset-query
{ severity: 7, fac: 'OFFSET' } [thrd:main]: test [0]: offset reset (at offset INVALID) to END: no previously committed offset available: Local: No offset stored
{ severity: 7, fac: 'OFFSET' } [thrd:main]: test [0]: backoff: (re)starting offset query timer for offset END
{ severity: 7, fac: 'CGRPOP' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" received op PARTITION_JOIN in state up (join-state steady) for test [0]
{ severity: 7, fac: 'PARTADD' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": add test [0]
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received HeartbeatResponse (v3, 6 bytes, CorrId 8, rtt 2.56ms)
{ severity: 7, fac: 'OFFSET' } [thrd:main]: Topic test [0]: timed offset query for END in state offset-query
{ severity: 7, fac: 'OFFREQ' } [thrd:main]: localhost:9092/1: Partition test [0]: querying for logical offset END (opv 4)
{ severity: 7, fac: 'PARTSTATE' } [thrd:main]: Partition test [0] changed fetch state offset-query -> offset-wait
{ severity: 7, fac: 'OFFSET' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: ListOffsetsRequest (v2, opv 4) for 1 topic(s) and 1 partition(s)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Sent ListOffsetsRequest (v2, 52 bytes @ 0, CorrId 6)
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received ListOffsetsResponse (v2, 40 bytes, CorrId 6, rtt 2.03ms)
{ severity: 7, fac: 'OFFSET' } [thrd:main]: localhost:9092/1: Offset reply for topic test [0] (v4 vs v4)
{ severity: 7, fac: 'OFFSET' } [thrd:main]: Offset END request for test [0] returned offset 10138 (10138)
{ severity: 7, fac: 'PARTSTATE' } [thrd:main]: Partition test [0] changed fetch state offset-wait -> active
{ severity: 7, fac: 'FETCH' } [thrd:main]: Partition test [0] start fetching at offset 10138
{ severity: 7, fac: 'WAKEUP' } [thrd:main]: localhost:9092/1: Wake-up
{ severity: 7, fac: 'FETCHDEC' } [thrd:localhost:9092/bootstrap]: Topic test [0]: fetch decide: updating to version 4 (was 0) at offset 10138 (was 0)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0] in state active at offset 10138 (0/100000 msgs, 0/65536 kb queued, opv 4) is fetchable
{ severity: 7, fac: 'FETCHADD' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Added test [0] to fetch list (1 entries, opv 4, 0 messages queued): fetchable
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch topic test [0] at offset 10138 (v4)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch 1/1/1 toppar(s)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Sent FetchRequest (v11, 94 bytes @ 0, CorrId 7)
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received FetchResponse (v11, 66 bytes, CorrId 7, rtt 1002.05ms)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0] MessageSet size 0, error "Success", MaxOffset 10138, LSO 10138, Ver 4/4
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch topic test [0] at offset 10138 (v4)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch 1/1/1 toppar(s)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Sent FetchRequest (v11, 94 bytes @ 0, CorrId 8)
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
PRODUCE - should be able to produce and consume messages: consumeLoop
{ severity: 7, fac: 'TOPIC' } [thrd:app]: New local topic: test
{ severity: 7, fac: 'TOPPARNEW' } [thrd:app]: NEW test [-1] 0x102f1f5d0 refcnt 0x102f1f660 (at rd_kafka_topic_new0:465)
{ severity: 7, fac: 'STATE' } [thrd:app]: Topic test changed state unknown -> exists
{ severity: 7, fac: 'PARTCNT' } [thrd:app]: Topic test partition count changed from 0 to 1
{ severity: 7, fac: 'TOPPARNEW' } [thrd:app]: NEW test [0] 0x102f1fb40 refcnt 0x102f1fbd0 (at rd_kafka_topic_partition_cnt_update:798)
{ severity: 7, fac: 'METADATA' } [thrd:app]: Topic test partition 0 Leader 1
{ severity: 7, fac: 'BRKDELGT' } [thrd:app]: test [0]: delegate to broker localhost:9092/1 (rktp 0x102f1fb40, term 0, ref 2)
{ severity: 7, fac: 'BRKDELGT' } [thrd:app]: test [0]: delegating to broker localhost:9092/1 for partition with 0 messages (0 bytes) queued
{ severity: 7, fac: 'BRKMIGR' } [thrd:app]: Migrating topic test [0] 0x102f1fb40 from (none) to localhost:9092/1 (sending PARTITION_JOIN to localhost:9092/1)
{ severity: 7, fac: 'PARTCNT' } [thrd:app]: Partitioning 0 unassigned messages in topic test to 1 partitions
{ severity: 7, fac: 'UAS' } [thrd:app]: 0/0 messages were partitioned in topic test
{ severity: 7, fac: 'CONF' } [thrd:app]: Topic "test" configuration (default_topic_conf):
{ severity: 7, fac: 'CONF' } [thrd:app]: produce.offset.report = true
{ severity: 7, fac: 'TOPBRK' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0]: joining broker (rktp 0x102f1fb40, 0 message(s) queued)
{ severity: 7, fac: 'FETCHADD' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Added test [0] to active list (1 entries, opv 0, 0 messages queued): joining
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'TOPPAR' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: test [0] 1 message(s) in xmit queue (1 added from partition queue)
{ severity: 7, fac: 'TOPPAR' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: test [0] 1 message(s) in xmit queue (0 added from partition queue)
{ severity: 7, fac: 'TOPPAR' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: test [0] 1 message(s) in xmit queue (0 added from partition queue)
{ severity: 7, fac: 'PRODUCE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: test [0]: Produce MessageSet with 1 message(s) (4169 bytes, ApiVersion 7, MsgVersion 2, MsgId 0, BaseSeq -1, PID{Invalid}, uncompressed)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Sent ProduceRequest (v7, 4224 bytes @ 0, CorrId 4)
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received ProduceResponse (v7, 48 bytes, CorrId 4, rtt 3.04ms)
{ severity: 7, fac: 'MSGSET' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: test [0]: MessageSet with 1 message(s) (MsgId 0, BaseSeq -1) delivered
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received FetchResponse (v11, 4235 bytes, CorrId 8, rtt 890.97ms)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0] MessageSet size 4169, error "Success", MaxOffset 10139, LSO 10139, Ver 4/4
{ severity: 7, fac: 'CONSUME' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Enqueue 1 message(s) (4099 bytes, 1 ops) on test [0] fetch queue (qlen 0, v4, last_offset 10138, 0 ctrl msgs, uncompressed)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch topic test [0] at offset 10139 (v4)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch 1/1/1 toppar(s)
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Sent FetchRequest (v11, 94 bytes @ 0, CorrId 9)
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
on data
✓ should be able to produce and consume messages: consumeLoop (2029ms)
after each started
start disconnect
{ severity: 7, fac: 'WAKEUP' } [thrd:app]: localhost:9092/1: Wake-up
{ severity: 7, fac: 'DESTROY' } [thrd:app]: Terminating instance (destroy flags none (0x0))
{ severity: 7, fac: 'TERMINATE' } [thrd:app]: Interrupting timers
{ severity: 7, fac: 'TERMINATE' } [thrd:app]: Sending TERMINATE to internal main thread
{ severity: 7, fac: 'TERMINATE' } [thrd:app]: Joining internal main thread
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Internal main thread terminating
{ severity: 7, fac: 'DESTROY' } [thrd:main]: Destroy internal
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'DESTROY' } [thrd:main]: Removing all topics
{ severity: 7, fac: 'PARTCNT' } [thrd:main]: Topic test partition count changed from 1 to 0
{ severity: 7, fac: 'REMOVE' } [thrd:main]: test [0] no longer reported in metadata
{ severity: 7, fac: 'BRKMIGR' } [thrd:main]: test [0] 0x102f1fb40 sending final LEAVE for removal by localhost:9092/1
{ severity: 7, fac: 'TOPPARREMOVE' } [thrd:main]: Removing toppar test [-1] 0x102f1f5d0
{ severity: 7, fac: 'DESTROY' } [thrd:main]: test [-1]: 0x102f1f5d0 DESTROY_FINAL
{ severity: 7, fac: 'DESTROY' } [thrd:main]: Sending TERMINATE to localhost:9092/1
{ severity: 7, fac: 'TOPBRK' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0]: leaving broker (0 messages in xmitq, next broker (none), rktp 0x102f1fb40)
{ severity: 7, fac: 'FETCHADD' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Removed test [0] from active list (0 entries, opv 0): leaving
{ severity: 7, fac: 'TOPBRK' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0]: no next broker, failing 0 message(s) in partition queue
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'TOPPARREMOVE' } [thrd:localhost:9092/bootstrap]: Removing toppar test [0] 0x102f1fb40
{ severity: 7, fac: 'DESTROY' } [thrd:localhost:9092/bootstrap]: test [0]: 0x102f1fb40 DESTROY_FINAL
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Purging reply queue
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Decommissioning internal broker
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Join 2 broker thread(s)
{ severity: 7, fac: 'TERM' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received TERMINATE op in state UP: 2 refcnts, 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs
{ severity: 7, fac: 'TERM' } [thrd::0/internal]: :0/internal: Received TERMINATE op in state INIT: 2 refcnts, 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs
{ severity: 7, fac: 'FAIL' } [thrd::0/internal]: :0/internal: Client is terminating (after 2043ms in state INIT) (_DESTROY)
{ severity: 7, fac: 'STATE' } [thrd::0/internal]: :0/internal: Broker changed state INIT -> DOWN
{ severity: 7, fac: 'BROADCAST' } [thrd::0/internal]: Broadcasting state change
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Updating 0 buffers on connection reset
{ severity: 7, fac: 'BRKTERM' } [thrd::0/internal]: :0/internal: terminating: broker still has 2 refcnt(s), 0 buffer(s), 0 partition(s)
{ severity: 7, fac: 'TERMINATE' } [thrd::0/internal]: :0/internal: Handle is terminating in state DOWN: 1 refcnts (0x106016ba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'FAIL' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Client is terminating (after 2035ms in state UP) (_DESTROY)
{ severity: 7, fac: 'FAIL' } [thrd::0/internal]: :0/internal: Broker handle is terminating (after 0ms in state DOWN) (_DESTROY)
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker changed state UP -> DOWN
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Updating 0 buffers on connection reset
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Updating 0 buffers on connection reset
{ severity: 7, fac: 'BRKTERM' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: terminating: broker still has 2 refcnt(s), 0 buffer(s), 0 partition(s)
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state DOWN: 1 refcnts (0x1060179a0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'FAIL' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker handle is terminating (after 0ms in state DOWN) (_DESTROY)
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Updating 0 buffers on connection reset
why err null
{ severity: 7, fac: 'RECV' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received FetchResponse (v11, 66 bytes, CorrId 9, rtt 1001.84ms)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0] MessageSet size 0, error "Success", MaxOffset 10139, LSO 10139, Ver 4/4
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch topic test [0] at offset 10139 (v4)
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Fetch 1/1/1 toppar(s)
{ severity: 7, fac: 'CLOSE' } [thrd:app]: Closing consumer
{ severity: 7, fac: 'SEND' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Sent FetchRequest (v11, 94 bytes @ 0, CorrId 10)
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'CLOSE' } [thrd:app]: Waiting for close events
{ severity: 7, fac: 'CGRPOP' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" received op TERMINATE in state up (join-state steady)
{ severity: 7, fac: 'CGRPTERM' } [thrd:main]: Terminating group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" in state up with 1 partition(s)
{ severity: 7, fac: 'UNSUBSCRIBE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": unsubscribe from current subscription of size 1 (leave group=true, has joined=true, rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d, join-state steady)
{ severity: 7, fac: 'SUBSCRIPTION' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": clearing subscribed topics list (1)
{ severity: 7, fac: 'SUBSCRIPTION' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": effective subscription list changed from 1 to 0 topic(s):
{ severity: 7, fac: 'GRPLEADER' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": resetting group leader info: unsubscribe
{ severity: 7, fac: 'REBALANCE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" initiating rebalance (EAGER) in state up (join-state steady) with 1 assigned partition(s): unsubscribe
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state steady -> wait-unassign-call (state up)
{ severity: 7, fac: 'CLEARASSIGN' } [thrd:main]: Clearing current assignment of 1 partition(s)
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state wait-unassign-call -> wait-unassign-to-complete (state up)
{ severity: 7, fac: 'DUMP' } [thrd:main]: Assignment dump (started_cnt=1, wait_stop_cnt=0)
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_QRY' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: List with 1 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: test [0] offset STORED
{ severity: 7, fac: 'BARRIER' } [thrd:main]: test [0]: rd_kafka_toppar_op_fetch_stop:2390: new version barrier v5
{ severity: 7, fac: 'CONSUMER' } [thrd:main]: Stop consuming test [0] (v5)
{ severity: 7, fac: 'BARRIER' } [thrd:main]: test [0]: rd_kafka_toppar_op_pause_resume:2449: new version barrier v6
{ severity: 7, fac: 'RESUME' } [thrd:main]: Resume test [0] (v6)
{ severity: 7, fac: 'DESP' } [thrd:main]: Removing (un)desired topic test [0]
{ severity: 7, fac: 'REMOVE' } [thrd:main]: Removing test [0] from assignment (started=true, pending=false, queried=false, stored offset=10139)
{ severity: 7, fac: 'REMOVE' } [thrd:main]: Served 1 removed partition(s), with 1 offset(s) to commit
{ severity: 7, fac: 'COMMIT' } [thrd:main]: GroupCoordinator/1: Committing offsets for 1 partition(s) with generation-id 1 in join-state wait-unassign-to-complete: unassigned partitions
{ severity: 7, fac: 'OFFSET' } [thrd:main]: GroupCoordinator/1: Enqueue OffsetCommitRequest(v7, 1/1 partition(s))): unassigned partitions
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Current assignment of 0 partition(s) with 0 pending adds, 0 offset queries, 1 partitions awaiting stop and 1 offset commits in progress
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": clearing group assignment
{ severity: 7, fac: 'CLEARASSIGN' } [thrd:main]: No current assignment to clear
{ severity: 7, fac: 'DUMP' } [thrd:main]: Assignment dump (started_cnt=1, wait_stop_cnt=1)
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_QRY' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Current assignment of 0 partition(s) with 0 pending adds, 0 offset queries, 1 partitions awaiting stop and 1 offset commits in progress
{ severity: 7, fac: 'CGRPTERM' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": waiting for 1 toppar(s), assignment in progress, 1 commit(s) (state up, join-state wait-unassign-to-complete) before terminating
{ severity: 7, fac: 'CGRPTERM' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": waiting for 1 toppar(s), assignment in progress, 1 commit(s) (state up, join-state wait-unassign-to-complete) before terminating
{ severity: 7, fac: 'OP' } [thrd:main]: test [0] received op FETCH_STOP (v5) in fetch-state active (opv4)
{ severity: 7, fac: 'FETCH' } [thrd:main]: Stopping fetch for test [0] in state active (v5)
{ severity: 7, fac: 'PARTSTATE' } [thrd:main]: Partition test [0] changed fetch state active -> stopping
{ severity: 7, fac: 'STORETERM' } [thrd:main]: test [0]: offset store terminating
{ severity: 7, fac: 'PARTSTATE' } [thrd:main]: Partition test [0] changed fetch state stopping -> stopped
{ severity: 7, fac: 'OP' } [thrd:main]: test [0] received op PAUSE (v6) in fetch-state stopped (opv5)
{ severity: 7, fac: 'RESUME' } [thrd:main]: Not resuming test [0]: partition is not paused by library
{ severity: 7, fac: 'CGRPTERM' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": waiting for 1 toppar(s), assignment in progress, 1 commit(s) (state up, join-state wait-unassign-to-complete) before terminating
{ severity: 7, fac: 'CGRPOP' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" received op PARTITION_LEAVE in state up (join-state wait-unassign-to-complete) for test [0]
{ severity: 7, fac: 'PARTDEL' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": delete test [0]
{ severity: 7, fac: 'CGRPTERM' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": waiting for 0 toppar(s), assignment in progress, 1 commit(s) (state up, join-state wait-unassign-to-complete) before terminating
{ severity: 7, fac: 'STOPSERVE' } [thrd:main]: All partitions awaiting stop are now stopped: serving assignment
{ severity: 7, fac: 'DUMP' } [thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_QRY' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Current assignment of 0 partition(s) with 0 pending adds, 0 offset queries, 0 partitions awaiting stop and 1 offset commits in progress
{ severity: 7, fac: 'CGRPTERM' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": waiting for 0 toppar(s), assignment in progress, 1 commit(s) (state up, join-state wait-unassign-to-complete) before terminating
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent OffsetCommitRequest (v7, 163 bytes @ 0, CorrId 9)
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received OffsetCommitResponse (v7, 24 bytes, CorrId 9, rtt 3.21ms)
{ severity: 7, fac: 'COMMIT' } [thrd:main]: GroupCoordinator/1: OffsetCommit for 1 partition(s) in join-state wait-unassign-to-complete: unassigned partitions: returned: Success
{ severity: 7, fac: 'DUMP' } [thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)
{ severity: 7, fac: 'DUMP_ALL' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_PND' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_QRY' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'DUMP_REM' } [thrd:main]: List with 0 partition(s):
{ severity: 7, fac: 'ASSIGNDONE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": assignment operations done in join-state wait-unassign-to-complete (rebalance rejoin=false)
{ severity: 7, fac: 'UNASSIGN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": unassign done in state up (join-state wait-unassign-to-complete)
{ severity: 7, fac: 'MEMBERID' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": updating member id "rdkafka-af615a5e-0705-4a80-9166-4b3f9a0e351d" -> ""
{ severity: 7, fac: 'LEAVE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": leave (in state up)
{ severity: 7, fac: 'LEAVE' } [thrd:main]: localhost:9092/1: Leaving group
{ severity: 7, fac: 'NOREJOIN' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": Not rejoining group without an assignment: Unassignment done: no subscribed topics
{ severity: 7, fac: 'CGRPJOINSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed join state wait-unassign-to-complete -> init (state up)
{ severity: 7, fac: 'CGRPTERM' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": waiting for 0 toppar(s), 0 commit(s), wait-leave, (state up, join-state init) before terminating
{ severity: 7, fac: 'SEND' } [thrd:GroupCoordinator]: GroupCoordinator/1: Sent LeaveGroupRequest (v1, 125 bytes @ 0, CorrId 10)
{ severity: 7, fac: 'RECV' } [thrd:GroupCoordinator]: GroupCoordinator/1: Received LeaveGroupResponse (v1, 6 bytes, CorrId 10, rtt 4.18ms)
{ severity: 7, fac: 'LEAVEGROUP' } [thrd:main]: LeaveGroup response received in state up
{ severity: 7, fac: 'CGRPSTATE' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" changed state up -> term (join-state init)
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'ASSIGNMENT' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab": clearing group assignment
{ severity: 7, fac: 'COORDCLEAR' } [thrd:main]: Group "kafka-mocha-grp-f8688ddf734d7425174e36ee555df8fec180fbab" broker localhost:9092/1 is no longer coordinator
{ severity: 7, fac: 'NODENAME' } [thrd:main]: GroupCoordinator/1: Broker nodename changed from "localhost:9092" to ""
{ severity: 7, fac: 'NODEID' } [thrd:main]: GroupCoordinator/1: Broker nodeid changed from 1 to -1
{ severity: 7, fac: 'CLOSE' } [thrd:app]: Consumer closed
{ severity: 7, fac: 'DESTROY' } [thrd:app]: Terminating instance (destroy flags NoConsumerClose (0x8))
{ severity: 7, fac: 'TERMINATE' } [thrd:app]: Terminating consumer group handler
{ severity: 7, fac: 'CLOSE' } [thrd:app]: Closing consumer
{ severity: 7, fac: 'CLOSE' } [thrd:app]: Disabling and purging temporary queue to quench close events
{ severity: 7, fac: 'CLOSE' } [thrd:app]: Consumer closed
{ severity: 7, fac: 'TERMINATE' } [thrd:app]: Interrupting timers
{ severity: 7, fac: 'TERMINATE' } [thrd:app]: Sending TERMINATE to internal main thread
{ severity: 7, fac: 'TERMINATE' } [thrd:app]: Joining internal main thread
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Internal main thread terminating
{ severity: 7, fac: 'FAIL' } [thrd:GroupCoordinator]: GroupCoordinator: Closing connection due to nodename change (after 3037ms in state UP) (_TRANSPORT)
{ severity: 7, fac: 'DESTROY' } [thrd:main]: Destroy internal
{ severity: 7, fac: 'BROADCAST' } [thrd:main]: Broadcasting state change
{ severity: 7, fac: 'STATE' } [thrd:GroupCoordinator]: GroupCoordinator: Broker changed state UP -> DOWN
{ severity: 7, fac: 'DESTROY' } [thrd:main]: Removing all topics
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'PARTCNT' } [thrd:main]: Topic test partition count changed from 1 to 0
{ severity: 7, fac: 'REMOVE' } [thrd:main]: test [0] no longer reported in metadata
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Purging bufq with 0 buffers
{ severity: 7, fac: 'BRKMIGR' } [thrd:main]: test [0] 0x1038052d0 sending final LEAVE for removal by localhost:9092/1
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Updating 0 buffers on connection reset
{ severity: 7, fac: 'BRKTERM' } [thrd:GroupCoordinator]: GroupCoordinator: terminating: broker still has 3 refcnt(s), 0 buffer(s), 0 partition(s)
{ severity: 7, fac: 'METADATA' } [thrd:GroupCoordinator]: Requesting metadata for 1/1 topics: broker down
{ severity: 7, fac: 'METADATA' } [thrd:GroupCoordinator]: localhost:9092/1: Request metadata for 1 topic(s): broker down
{ severity: 7, fac: 'TOPPARREMOVE' } [thrd:main]: Removing toppar test [-1] 0x103807c60
{ severity: 7, fac: 'DESTROY' } [thrd:main]: test [-1]: 0x103807c60 DESTROY_FINAL
{ severity: 7, fac: 'TERMINATE' } [thrd:GroupCoordinator]: GroupCoordinator: Handle is terminating in state DOWN: 3 refcnts (0x10702afa0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'STATE' } [thrd:GroupCoordinator]: GroupCoordinator: Broker changed state DOWN -> INIT
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'DESTROY' } [thrd:main]: Sending TERMINATE to localhost:9092/1
{ severity: 7, fac: 'DESTROY' } [thrd:main]: Sending TERMINATE to GroupCoordinator
{ severity: 7, fac: 'FETCH' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0] in state stopped at offset 10138 (0/100000 msgs, 0/65536 kb queued, opv 4) is not fetchable: forced removal
{ severity: 7, fac: 'FETCHADD' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Removed test [0] from fetch list (0 entries, opv 4): forced removal
{ severity: 7, fac: 'TOPBRK' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0]: leaving broker (0 messages in xmitq, next broker (none), rktp 0x1038052d0)
{ severity: 7, fac: 'TOPBRK' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Topic test [0]: no next broker, failing 0 message(s) in partition queue
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'TERM' } [thrd:GroupCoordinator]: GroupCoordinator: Received TERMINATE op in state INIT: 2 refcnts, 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs
{ severity: 7, fac: 'TERM' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Received TERMINATE op in state UP: 5 refcnts, 0 toppar(s), 0 active toppar(s), 1 outbufs, 1 waitresps, 0 retrybufs
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Purging reply queue
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Decommissioning internal broker
{ severity: 7, fac: 'FAIL' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Client is terminating (after 3043ms in state UP) (_DESTROY)
{ severity: 7, fac: 'TERMINATE' } [thrd:main]: Join 3 broker thread(s)
{ severity: 7, fac: 'TERM' } [thrd::0/internal]: :0/internal: Received TERMINATE op in state INIT: 2 refcnts, 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs
{ severity: 7, fac: 'FAIL' } [thrd:GroupCoordinator]: GroupCoordinator: Client is terminating (after 0ms in state INIT) (_DESTROY)
{ severity: 7, fac: 'STATE' } [thrd:GroupCoordinator]: GroupCoordinator: Broker changed state INIT -> DOWN
{ severity: 7, fac: 'BROADCAST' } [thrd:GroupCoordinator]: Broadcasting state change
{ severity: 7, fac: 'FAIL' } [thrd::0/internal]: :0/internal: Client is terminating (after 3052ms in state INIT) (_DESTROY)
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Purging bufq with 0 buffers
{ severity: 7, fac: 'STATE' } [thrd::0/internal]: :0/internal: Broker changed state INIT -> DOWN
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Updating 0 buffers on connection reset
{ severity: 7, fac: 'BRKTERM' } [thrd:GroupCoordinator]: GroupCoordinator: terminating: broker still has 2 refcnt(s), 0 buffer(s), 0 partition(s)
{ severity: 7, fac: 'TERMINATE' } [thrd:GroupCoordinator]: GroupCoordinator: Handle is terminating in state DOWN: 1 refcnts (0x10702afa0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'FAIL' } [thrd:GroupCoordinator]: GroupCoordinator: Broker handle is terminating (after 0ms in state DOWN) (_DESTROY)
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd:GroupCoordinator]: GroupCoordinator: Updating 0 buffers on connection reset
{ severity: 7, fac: 'BROADCAST' } [thrd::0/internal]: Broadcasting state change
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker changed state UP -> DOWN
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Updating 0 buffers on connection reset
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Purging bufq with 1 buffers
{ severity: 7, fac: 'BRKTERM' } [thrd::0/internal]: :0/internal: terminating: broker still has 2 refcnt(s), 0 buffer(s), 0 partition(s)
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Purging bufq with 1 buffers
{ severity: 7, fac: 'TERMINATE' } [thrd::0/internal]: :0/internal: Handle is terminating in state DOWN: 1 refcnts (0x10702bda0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'BUFQ' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Updating 0 buffers on connection reset
{ severity: 7, fac: 'FAIL' } [thrd::0/internal]: :0/internal: Broker handle is terminating (after 0ms in state DOWN) (_DESTROY)
{ severity: 7, fac: 'BRKTERM' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: terminating: broker still has 3 refcnt(s), 0 buffer(s), 0 partition(s)
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Purging bufq with 0 buffers
{ severity: 7, fac: 'BUFQ' } [thrd::0/internal]: :0/internal: Updating 0 buffers on connection reset
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state DOWN: 2 refcnts (0x10702cba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'STATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Broker changed state DOWN -> INIT
{ severity: 7, fac: 'BROADCAST' } [thrd:localhost:9092/bootstrap]: Broadcasting state change
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state INIT: 2 refcnts (0x10702cba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state INIT: 2 refcnts (0x10702cba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state INIT: 2 refcnts (0x10702cba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state INIT: 2 refcnts (0x10702cba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state INIT: 2 refcnts (0x10702cba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf
{ severity: 7, fac: 'TERMINATE' } [thrd:localhost:9092/bootstrap]: localhost:9092/1: Handle is terminating in state INIT: 2 refcnts (0x10702cba0), 0 toppar(s), 0 active toppar(s), 0 outbufs, 0 waitresps, 0 retrybufs: failed 0 request(s) in retry+outbuf |
|
@robinfehr Have you figured anything out? I am only able to reproduce it in k8s. The producer gets stuck in connecting state and cannot get out with a restart. I would like to look at the issue with you to see if I can help. |
|
I have found that |
|
In my example you can see that |
|
So here is the line that I determined where it was failing. The other library that I'm using that uses librdkafka printed out in the logs that it failed to resolve the connecting to the brokers. https://github.com/edenhill/librdkafka/blob/a913c75e1e09ef87232e9c7b044d8ab3ec404417/src/rdkafka_broker.c#L991 Here is the errors that are logged for this particular issue. The error it throws in noderdkafka is related to librdkafka. Its getting back a broker transport failure. The brokers are fine and its able to connect to them if i restart the app manually. I replaced the below broker names with aliases JFYI. |
|
I should clarify the above happens when the node that the application is running on in k8s goes down and the pod changes its status from Active to Running. There is probably network disconnect since the node went down but the pod doesn't change to another node because by default its set to only transition after 5 minutes. The application stays in this state until the node comes up and then gets restarted. Once it starts up the above error is what shows. |
|
For more clarfication on what is happening read this about what happens when a node is restarted. It could be the reassigning of ips that causes the brokers to get in a weird state when they start back up. There is also an update of the ip tables which might have an effect on being able to find the brokers. |
|
One of new releases fixed this issue for me. |
|
@pranasge Can you tell me which version of this problem was resolved ? |
|
I upgraded from 1.9.0 to 1.9.2 first and after that i did not see this problem reproduced. But I used 1.9.2 only for month and now with 2.0.2 i haven't seen this problem since first update. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Description
I am using partition queues and kept seeing application hanging on destructors.
Seen similar issues #3007 and #3143 but i could reproduce on 1.7.0.
Then created minimal test. Issue is very "racy" as I needed to add sleeps and std::cout to reproduce.
How to reproduce
I run this test on loop
and restart brokers incrementally (1, 2, 3, 1, 2,...).
Callstack:
Logs:
IMPORTANT: Always try to reproduce the issue on the latest released version (see https://github.com/edenhill/librdkafka/releases), if it can't be reproduced on the latest version the issue has been fixed.
Checklist
IMPORTANT: We will close issues where the checklist has not been completed.
Please provide the following information:
REF 77a013b7a2611f7bdc091afa1e56b1a46d1c52f5 #v1.7.0docker.io/bitnami/kafka:2.7.0-debian-10-r35can be seen in testDebian GNU/Linux 10 (buster)debug=allas necessary) from librdkafkaThe text was updated successfully, but these errors were encountered: