Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

producer can not produce message unless restarted after the broker restarted #3009

Closed
3 of 7 tasks
Lasuerte opened this issue Jul 24, 2020 · 4 comments
Closed
3 of 7 tasks

Comments

@Lasuerte
Copy link

Read the FAQ first: https://github.com/edenhill/librdkafka/wiki/FAQ

Description

I was testing broker pod restart, then found that after the broker restarted, my producer cannot produce message anymore, if I restart the producer, this problem disappeared. The producer debug log shows that after successfully reconnected to the broker, and when fetching the metadata of the topic, the broker returned "Unknown topic or partition", but this topic was existed, then the producer infinitely request metadata from broker and got response successfully with correct metadata, but the metadata was not actually updated because the leader is unchanged, and the topic was still inactivated. So how can I avoid this problem? Thanks very much.

How to reproduce

<your steps how to reproduce goes here, or remove section if not relevant>
we can simulate this problem by create a topic and delete it:

  1. create a topic
  2. produce message to this topic
  3. delete this topic so the producer change this topic state to notexist
  4. recreate this topic and then we can see producer infinitely request this topic's metadata

the key to reproduce this problem is that the producer already has one topic's metadata and then this topic is marked as inactive
then the producer request this topic's metadata.

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:

  • librdkafka version (release number or git tag): v1.4.0
  • Apache Kafka version: v2.2.1
  • librdkafka client configuration: ``
  • Operating system: Linux version 3.10.0-957.27.2.el7.x86_64
  • Provide logs (with debug=.. as necessary) from librdkafka
    %7|1595590812.019|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is down: re-query
    %7|1595590812.019|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is down: re-query
    %7|1595590812.019|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is down: re-query
    %7|1595590812.019|CONNECT|rdkafka#producer-1| [thrd:main]: Cluster connection already in progress: refresh unavailable topics
    %7|1595590812.019|CONNECT|rdkafka#producer-1| [thrd:main]: Not selecting any broker for cluster connection: still suppressed for 49ms: refresh unavailable topics
    %7|1595590812.019|METADATA|rdkafka#producer-1| [thrd:main]: Skipping metadata refresh of 1 topic(s): no usable brokers
    %7|1595590812.019|CONNECT|rdkafka#producer-1| [thrd:main]: Not selecting any broker for cluster connection: still suppressed for 49ms: no cluster connection
    %7|1595590812.057|CONNECT|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: broker in state TRY_CONNECT connecting
    %7|1595590812.057|STATE|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Broker changed state TRY_CONNECT -> CONNECT
    %7|1595590812.057|BROADCAST|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: Broadcasting state change
    %7|1595590812.058|CONNECT|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Connecting to ipv4#10.254.117.230:9093 (plaintext) with socket 7
    %7|1595590812.058|CONNECT|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Connected to ipv4#10.254.117.230:9093
    %7|1595590812.058|CONNECTED|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Connected (Program received signal SIGPIPE, Broken pipe. #2)
    %7|1595590812.058|STATE|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Broker changed state CONNECT -> APIVERSION_QUERY
    %7|1595590812.058|BROADCAST|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: Broadcasting state change
    %7|1595590812.058|SEND|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Sent ApiVersionRequest (v3, 40 bytes @ 0, CorrId 4)
    %7|1595590812.059|RECV|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Received ApiVersionResponse (v3, 6 bytes, CorrId 4, rtt 1.30ms)
    %7|1595590812.059|PROTOERR|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Protocol parse failure for ApiVersion v3 at 3/6 (rd_kafka_handle_ApiVersion:1909) (incorrect broker.version.fallback?)
    %7|1595590812.059|PROTOERR|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiArrayCnt -1 out of range
    %7|1595590812.059|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiVersionRequest v3 failed due to UNSUPPORTED_VERSION: retrying with v0
    %7|1595590812.060|SEND|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Sent ApiVersionRequest (v0, 21 bytes @ 0, CorrId 5)
    %7|1595590812.074|RECV|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Received ApiVersionResponse (v0, 270 bytes, CorrId 5, rtt 14.85ms)
    %7|1595590812.074|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Broker API support:
    %7|1595590812.074|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey Produce (0) Versions 0..7
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey Fetch (1) Versions 0..10
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey Offset (2) Versions 0..5
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey Metadata (3) Versions 0..7
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey LeaderAndIsr (4) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey StopReplica (5) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey UpdateMetadata (6) Versions 0..5
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey ControlledShutdown (7) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey OffsetCommit (8) Versions 0..6
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey OffsetFetch (9) Versions 0..5
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey FindCoordinator (10) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey JoinGroup (11) Versions 0..4
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey Heartbeat (12) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey LeaveGroup (13) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey SyncGroup (14) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DescribeGroups (15) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey ListGroups (16) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey SaslHandshake (17) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey ApiVersion (18) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey CreateTopics (19) Versions 0..3
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DeleteTopics (20) Versions 0..3
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DeleteRecords (21) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey InitProducerId (22) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey OffsetForLeaderEpoch (23) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey AddPartitionsToTxn (24) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey AddOffsetsToTxn (25) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey EndTxn (26) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey WriteTxnMarkers (27) Versions 0..0
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey TxnOffsetCommit (28) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DescribeAcls (29) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey CreateAcls (30) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DeleteAcls (31) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DescribeConfigs (32) Versions 0..2
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey AlterConfigs (33) Versions 0..1
    %7|1595590812.075|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey AlterReplicaLogDirs (34) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DescribeLogDirs (35) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey SaslAuthenticate (36) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey CreatePartitions (37) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey CreateDelegationToken (38) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey RenewDelegationToken (39) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey ExpireDelegationToken (40) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DescribeDelegationToken (41) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey DeleteGroups (42) Versions 0..1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: ApiKey Unknown-43? (43) Versions 0..0
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature MsgVer1: Produce (2..2) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature MsgVer1: Fetch (2..2) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature MsgVer1
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature MsgVer2: Produce (3..3) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature MsgVer2: Fetch (4..4) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature MsgVer2
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature ApiVersion: ApiVersion (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature ApiVersion
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerGroupCoordinator: FindCoordinator (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature BrokerGroupCoordinator
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerBalancedConsumer: FindCoordinator (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerBalancedConsumer: OffsetCommit (1..2) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerBalancedConsumer: OffsetFetch (1..1) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerBalancedConsumer: JoinGroup (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerBalancedConsumer: SyncGroup (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerBalancedConsumer: Heartbeat (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature BrokerBalancedConsumer: LeaveGroup (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature BrokerBalancedConsumer
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature ThrottleTime: Produce (1..2) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature ThrottleTime: Fetch (1..2) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature ThrottleTime
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature Sasl: JoinGroup (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature Sasl
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature SaslHandshake: SaslHandshake (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature SaslHandshake
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature LZ4: FindCoordinator (0..0) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature LZ4
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature OffsetTime: Offset (1..1) supported by broker
    %7|1595590812.076|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature OffsetTime
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature IdempotentProducer: InitProducerId (0..0) supported by broker
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature IdempotentProducer
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature ZSTD: Produce (7..7) supported by broker
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature ZSTD: Fetch (10..10) supported by broker
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature ZSTD
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature SaslAuthReq: SaslHandshake (1..1) supported by broker
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Feature SaslAuthReq: SaslAuthenticate (0..0) supported by broker
    %7|1595590812.077|APIVERSION|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Enabling feature SaslAuthReq
    %7|1595590812.077|STATE|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Broker changed state APIVERSION_QUERY -> UP
    %7|1595590812.077|BROADCAST|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: Broadcasting state change
    %7|1595590812.077|METADATA|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: Skipping metadata refresh of 1 topic(s): connected: already being requested
    %7|1595590813.019|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is down: re-query
    %7|1595590813.019|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is down: re-query
    %7|1595590813.019|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is down: re-query
    %7|1595590813.019|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
    %7|1595590813.019|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Request metadata for 1 topic(s): refresh unavailable topics
    %7|1595590813.020|SEND|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 6)
    %7|1595590813.020|RECV|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Received MetadataResponse (v2, 119 bytes, CorrId 6, rtt 0.69ms)
    %7|1595590813.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
    %7|1595590813.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590813.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1 brokers, 1 topics
    %7|1595590813.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590813.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590813.020|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590813.020|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state exists -> notexists
    %7|1595590813.020|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590813.020|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: no longer delegated to broker kafka-0.kafka-hs.default.svc.cluster.local:9093/0
    %7|1595590813.020|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegating to broker :0/internal for partition with 0 messages (0 bytes) queued
    %7|1595590813.020|BRKMIGR|rdkafka#producer-1| [thrd:main]: Migrating topic test_subscribe_topic [0] 0x7f2470001ca0 from kafka-0.kafka-hs.default.svc.cluster.local:9093/0 to :0/internal (sending PARTITION_LEAVE to kafka-0.kafka-hs.default.svc.cluster.local:9093/0)
    %7|1595590813.020|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590813.020|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: no longer delegated to broker kafka-0.kafka-hs.default.svc.cluster.local:9093/0
    %7|1595590813.020|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegating to broker :0/internal for partition with 0 messages (0 bytes) queued
    %7|1595590813.020|TOPBRK|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic test_subscribe_topic [0]: leaving broker (3 messages in xmitq, next broker :0/internal, rktp 0x7f2470001ca0)
    %7|1595590813.020|BRKMIGR|rdkafka#producer-1| [thrd:main]: Migrating topic test_subscribe_topic [1] 0x7f2470002200 from kafka-0.kafka-hs.default.svc.cluster.local:9093/0 to :0/internal (sending PARTITION_LEAVE to kafka-0.kafka-hs.default.svc.cluster.local:9093/0)
    %7|1595590813.020|FETCHADD|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Removed test_subscribe_topic [0] from active list (2 entries, opv 0): leaving
    %7|1595590813.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590813.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: no longer delegated to broker kafka-0.kafka-hs.default.svc.cluster.local:9093/0
    %7|1595590813.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegating to broker :0/internal for partition with 0 messages (0 bytes) queued
    %7|1595590813.021|BROADCAST|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Broadcasting state change
    %7|1595590813.021|BRKMIGR|rdkafka#producer-1| [thrd:main]: Migrating topic test_subscribe_topic [2] 0x7f2470002760 from kafka-0.kafka-hs.default.svc.cluster.local:9093/0 to :0/internal (sending PARTITION_LEAVE to kafka-0.kafka-hs.default.svc.cluster.local:9093/0)
    %7|1595590813.021|TOPBRK|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic test_subscribe_topic [1]: leaving broker (1 messages in xmitq, next broker :0/internal, rktp 0x7f2470002200)
    %7|1595590813.021|TOPBRK|rdkafka#producer-1| [thrd::0/internal]: :0/internal: Topic test_subscribe_topic [0]: joining broker (rktp 0x7f2470001ca0, 3 message(s) queued)
    %7|1595590813.021|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590813.021|FETCHADD|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Removed test_subscribe_topic [1] from active list (1 entries, opv 0): leaving
    %7|1595590813.021|FETCHADD|rdkafka#producer-1| [thrd::0/internal]: :0/internal: Added test_subscribe_topic [0] to active list (1 entries, opv 0, 3 messages queued): joining
    %7|1595590813.021|BROADCAST|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Broadcasting state change
    %7|1595590813.021|BROADCAST|rdkafka#producer-1| [thrd::0/internal]: Broadcasting state change
    %7|1595590813.021|TOPBRK|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic test_subscribe_topic [2]: leaving broker (0 messages in xmitq, next broker :0/internal, rktp 0x7f2470002760)
    %7|1595590813.021|TOPBRK|rdkafka#producer-1| [thrd::0/internal]: :0/internal: Topic test_subscribe_topic [1]: joining broker (rktp 0x7f2470002200, 1 message(s) queued)
    %7|1595590813.021|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590813.021|FETCHADD|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Removed test_subscribe_topic [2] from active list (0 entries, opv 0): leaving
    %7|1595590813.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1/1 requested topic(s) seen in metadata
    %7|1595590813.021|FETCHADD|rdkafka#producer-1| [thrd::0/internal]: :0/internal: Added test_subscribe_topic [1] to active list (2 entries, opv 0, 1 messages queued): joining
    %7|1595590813.021|BROADCAST|rdkafka#producer-1| [thrd::0/internal]: Broadcasting state change
    %7|1595590813.021|TOPBRK|rdkafka#producer-1| [thrd::0/internal]: :0/internal: Topic test_subscribe_topic [2]: joining broker (rktp 0x7f2470002760, 0 message(s) queued)
    %7|1595590813.021|FETCHADD|rdkafka#producer-1| [thrd::0/internal]: :0/internal: Added test_subscribe_topic [2] to active list (3 entries, opv 0, 0 messages queued): joining
    %7|1595590813.021|BROADCAST|rdkafka#producer-1| [thrd::0/internal]: Broadcasting state change
    %7|1595590813.021|BROADCAST|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Broadcasting state change
    severity:[3]: produce message failed, topic:[test_subscribe_topic], err:[Local: Unknown topic]
    %7|1595590814.019|NOINFO|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic metadata information timed out (999ms old)
    %7|1595590814.019|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state notexists -> unknown
    %7|1595590814.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
    %7|1595590814.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
    %7|1595590814.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
    %7|1595590814.020|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
    %7|1595590814.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Request metadata for 1 topic(s): refresh unavailable topics
    %7|1595590814.020|SEND|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 7)
    %7|1595590814.020|RECV|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Received MetadataResponse (v2, 119 bytes, CorrId 7, rtt 0.53ms)
    %7|1595590814.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
    %7|1595590814.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590814.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1 brokers, 1 topics
    %7|1595590814.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590814.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590814.021|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590814.021|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state unknown -> notexists
    %7|1595590814.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590814.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: not updating broker: already on correct broker :0/internal
    %7|1595590814.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590814.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: not updating broker: already on correct broker :0/internal
    %7|1595590814.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590814.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: not updating broker: already on correct broker :0/internal
    %7|1595590814.021|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590814.021|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590814.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1/1 requested topic(s) seen in metadata
    %7|1595590814.279|CONNECT|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: broker in state TRY_CONNECT connecting
    %7|1595590814.279|STATE|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker changed state TRY_CONNECT -> CONNECT
    %7|1595590814.279|BROADCAST|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Broadcasting state change
    %7|1595590814.280|CONNECT|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Connecting to ipv4#172.20.166.179:9093 (plaintext) with socket 10
    %7|1595590814.280|CONNECT|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Connected to ipv4#172.20.166.179:9093
    %7|1595590814.280|CONNECTED|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Connected (Program received signal SIGPIPE, Broken pipe. #2)
    %7|1595590814.280|STATE|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker changed state CONNECT -> APIVERSION_QUERY
    %7|1595590814.280|BROADCAST|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Broadcasting state change
    %7|1595590814.280|SEND|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Sent ApiVersionRequest (v3, 40 bytes @ 0, CorrId 7)
    %7|1595590814.282|RECV|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Received ApiVersionResponse (v3, 6 bytes, CorrId 7, rtt 1.74ms)
    %7|1595590814.282|PROTOERR|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Protocol parse failure for ApiVersion v3 at 3/6 (rd_kafka_handle_ApiVersion:1909) (incorrect broker.version.fallback?)
    %7|1595590814.282|PROTOERR|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiArrayCnt -1 out of range
    %7|1595590814.282|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiVersionRequest v3 failed due to UNSUPPORTED_VERSION: retrying with v0
    %7|1595590814.282|SEND|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Sent ApiVersionRequest (v0, 21 bytes @ 0, CorrId 8)
    %7|1595590814.283|RECV|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Received ApiVersionResponse (v0, 270 bytes, CorrId 8, rtt 0.72ms)
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker API support:
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey Produce (0) Versions 0..7
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey Fetch (1) Versions 0..10
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey Offset (2) Versions 0..5
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey Metadata (3) Versions 0..7
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey LeaderAndIsr (4) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey StopReplica (5) Versions 0..1
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey UpdateMetadata (6) Versions 0..5
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey ControlledShutdown (7) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey OffsetCommit (8) Versions 0..6
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey OffsetFetch (9) Versions 0..5
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey FindCoordinator (10) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey JoinGroup (11) Versions 0..4
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey Heartbeat (12) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey LeaveGroup (13) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey SyncGroup (14) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DescribeGroups (15) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey ListGroups (16) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey SaslHandshake (17) Versions 0..1
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey ApiVersion (18) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey CreateTopics (19) Versions 0..3
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DeleteTopics (20) Versions 0..3
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DeleteRecords (21) Versions 0..1
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey InitProducerId (22) Versions 0..1
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey OffsetForLeaderEpoch (23) Versions 0..2
    %7|1595590814.283|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey AddPartitionsToTxn (24) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey AddOffsetsToTxn (25) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey EndTxn (26) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey WriteTxnMarkers (27) Versions 0..0
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey TxnOffsetCommit (28) Versions 0..2
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DescribeAcls (29) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey CreateAcls (30) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DeleteAcls (31) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DescribeConfigs (32) Versions 0..2
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey AlterConfigs (33) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey AlterReplicaLogDirs (34) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DescribeLogDirs (35) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey SaslAuthenticate (36) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey CreatePartitions (37) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey CreateDelegationToken (38) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey RenewDelegationToken (39) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey ExpireDelegationToken (40) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DescribeDelegationToken (41) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey DeleteGroups (42) Versions 0..1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ApiKey Unknown-43? (43) Versions 0..0
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature MsgVer1: Produce (2..2) supported by broker
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature MsgVer1: Fetch (2..2) supported by broker
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature MsgVer1
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature MsgVer2: Produce (3..3) supported by broker
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature MsgVer2: Fetch (4..4) supported by broker
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature MsgVer2
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature ApiVersion: ApiVersion (0..0) supported by broker
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature ApiVersion
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerGroupCoordinator: FindCoordinator (0..0) supported by broker
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature BrokerGroupCoordinator
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerBalancedConsumer: FindCoordinator (0..0) supported by broker
    %7|1595590814.284|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerBalancedConsumer: OffsetCommit (1..2) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerBalancedConsumer: OffsetFetch (1..1) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerBalancedConsumer: JoinGroup (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerBalancedConsumer: SyncGroup (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerBalancedConsumer: Heartbeat (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature BrokerBalancedConsumer: LeaveGroup (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature BrokerBalancedConsumer
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature ThrottleTime: Produce (1..2) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature ThrottleTime: Fetch (1..2) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature ThrottleTime
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature Sasl: JoinGroup (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature Sasl
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature SaslHandshake: SaslHandshake (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature SaslHandshake
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature LZ4: FindCoordinator (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature LZ4
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature OffsetTime: Offset (1..1) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature OffsetTime
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature IdempotentProducer: InitProducerId (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature IdempotentProducer
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature ZSTD: Produce (7..7) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature ZSTD: Fetch (10..10) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature ZSTD
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature SaslAuthReq: SaslHandshake (1..1) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Feature SaslAuthReq: SaslAuthenticate (0..0) supported by broker
    %7|1595590814.285|APIVERSION|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Enabling feature SaslAuthReq
    %7|1595590814.285|STATE|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker changed state APIVERSION_QUERY -> UP
    %7|1595590814.285|BROADCAST|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Broadcasting state change
    %7|1595590814.285|METADATA|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Hinted cache of 1/1 topic(s) being queried
    %7|1595590814.285|METADATA|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: Requesting metadata for 1/1 topics: connected
    %7|1595590814.285|METADATA|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Request metadata for 1 topic(s): connected
    %7|1595590814.285|SEND|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 9)
    %7|1595590814.286|RECV|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Received MetadataResponse (v2, 119 bytes, CorrId 9, rtt 0.50ms)
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ===== Received metadata (for 1 requested topics): connected =====
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1 brokers, 1 topics
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590814.286|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590814.286|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: not updating broker: already on correct broker :0/internal
    %7|1595590814.286|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590814.286|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: not updating broker: already on correct broker :0/internal
    %7|1595590814.286|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590814.286|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: not updating broker: already on correct broker :0/internal
    %7|1595590814.286|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590814.286|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1/1 requested topic(s) seen in metadata
    %7|1595590814.286|METADATA|rdkafka#producer-1| [thrd:main]: Purged 1/1 cached topic hint(s)
    %7|1595590815.020|NOINFO|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic metadata information timed out (733ms old)
    %7|1595590815.020|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state notexists -> unknown
    %7|1595590815.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
    %7|1595590815.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
    %7|1595590815.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
    %7|1595590815.020|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
    %7|1595590815.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Request metadata for 1 topic(s): refresh unavailable topics
    %7|1595590815.020|SEND|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 10)
    %7|1595590815.021|RECV|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Received MetadataResponse (v2, 119 bytes, CorrId 10, rtt 1.23ms)
    %7|1595590815.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
    %7|1595590815.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590815.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1 brokers, 1 topics
    %7|1595590815.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590815.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590815.022|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590815.022|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state unknown -> notexists
    %7|1595590815.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590815.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: not updating broker: already on correct broker :0/internal
    %7|1595590815.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590815.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: not updating broker: already on correct broker :0/internal
    %7|1595590815.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590815.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: not updating broker: already on correct broker :0/internal
    %7|1595590815.022|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590815.022|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590815.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1/1 requested topic(s) seen in metadata
    %7|1595590816.020|NOINFO|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic metadata information timed out (998ms old)
    %7|1595590816.020|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state notexists -> unknown
    %7|1595590816.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
    %7|1595590816.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
    %7|1595590816.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
    %7|1595590816.020|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
    %7|1595590816.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Request metadata for 1 topic(s): refresh unavailable topics
    %7|1595590816.020|SEND|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 11)
    %7|1595590816.021|RECV|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Received MetadataResponse (v2, 119 bytes, CorrId 11, rtt 0.31ms)
    %7|1595590816.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
    %7|1595590816.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590816.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1 brokers, 1 topics
    %7|1595590816.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590816.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590816.021|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590816.021|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state unknown -> notexists
    %7|1595590816.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590816.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: not updating broker: already on correct broker :0/internal
    %7|1595590816.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590816.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: not updating broker: already on correct broker :0/internal
    %7|1595590816.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590816.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: not updating broker: already on correct broker :0/internal
    %7|1595590816.021|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590816.021|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590816.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1/1 requested topic(s) seen in metadata
    %7|1595590817.020|NOINFO|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic metadata information timed out (999ms old)
    %7|1595590817.020|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state notexists -> unknown
    %7|1595590817.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
    %7|1595590817.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
    %7|1595590817.020|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
    %7|1595590817.020|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
    %7|1595590817.020|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Request metadata for 1 topic(s): refresh unavailable topics
    %7|1595590817.021|SEND|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 12)
    %7|1595590817.021|RECV|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Received MetadataResponse (v2, 119 bytes, CorrId 12, rtt 0.39ms)
    %7|1595590817.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
    %7|1595590817.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590817.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1 brokers, 1 topics
    %7|1595590817.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590817.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590817.021|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590817.021|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state unknown -> notexists
    %7|1595590817.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590817.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: not updating broker: already on correct broker :0/internal
    %7|1595590817.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590817.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: not updating broker: already on correct broker :0/internal
    %7|1595590817.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590817.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: not updating broker: already on correct broker :0/internal
    %7|1595590817.022|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590817.022|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590817.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1/1 requested topic(s) seen in metadata
    %7|1595590818.021|NOINFO|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic metadata information timed out (999ms old)
    %7|1595590818.021|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state notexists -> unknown
    %7|1595590818.021|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
    %7|1595590818.021|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
    %7|1595590818.021|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Request metadata for 1 topic(s): refresh unavailable topics
    %7|1595590818.021|SEND|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 13)
    %7|1595590818.021|RECV|rdkafka#producer-1| [thrd:kafka-0.kafka-hs.default.svc.cluster.local:9093/0]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Received MetadataResponse (v2, 119 bytes, CorrId 13, rtt 0.27ms)
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1 brokers, 1 topics
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590818.021|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590818.021|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state unknown -> notexists
    %7|1595590818.021|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590818.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: not updating broker: already on correct broker :0/internal
    %7|1595590818.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590818.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: not updating broker: already on correct broker :0/internal
    %7|1595590818.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590818.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: not updating broker: already on correct broker :0/internal
    %7|1595590818.022|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590818.022|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590818.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1/1 requested topic(s) seen in metadata
    %7|1595590819.021|NOINFO|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic metadata information timed out (999ms old)
    %7|1595590819.021|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state notexists -> unknown
    %7|1595590819.021|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
    %7|1595590819.021|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
    %7|1595590819.021|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
    %7|1595590819.021|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
    %7|1595590819.021|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Request metadata for 1 topic(s): refresh unavailable topics
    %7|1595590819.021|SEND|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 8)
    %7|1595590819.022|RECV|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Received MetadataResponse (v2, 119 bytes, CorrId 8, rtt 0.42ms)
    %7|1595590819.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
    %7|1595590819.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
    %7|1595590819.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1 brokers, 1 topics
    %7|1595590819.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
    %7|1595590819.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Topic #0/1: test_subscribe_topic with 0 partitions: Broker: Unknown topic or partition
    %7|1595590819.022|METADATA|rdkafka#producer-1| [thrd:main]: Error in metadata reply for topic test_subscribe_topic (PartCnt 0): Broker: Unknown topic or partition
    %7|1595590819.022|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state unknown -> notexists
    %7|1595590819.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: delegate to broker (none) (rktp 0x7f2470001ca0, term 0, ref 2)
    %7|1595590819.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [0]: not updating broker: already on correct broker :0/internal
    %7|1595590819.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: delegate to broker (none) (rktp 0x7f2470002200, term 0, ref 2)
    %7|1595590819.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [1]: not updating broker: already on correct broker :0/internal
    %7|1595590819.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: delegate to broker (none) (rktp 0x7f2470002760, term 0, ref 2)
    %7|1595590819.022|BRKDELGT|rdkafka#producer-1| [thrd:main]: test_subscribe_topic [2]: not updating broker: already on correct broker :0/internal
    %7|1595590819.022|PARTCNT|rdkafka#producer-1| [thrd:main]: Partitioning 0 unassigned messages in topic test_subscribe_topic to 3 partitions
    %7|1595590819.022|UAS|rdkafka#producer-1| [thrd:main]: 0/0 messages were partitioned in topic test_subscribe_topic
    %7|1595590819.022|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1/1 requested topic(s) seen in metadata
    %7|1595590820.021|NOINFO|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic metadata information timed out (999ms old)
    %7|1595590820.021|STATE|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic changed state notexists -> unknown
  • Provide broker log excerpts
  • Critical issue
@Lasuerte
Copy link
Author

%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1 brokers, 1 topics
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: Topic #0/1: test_subscribe_topic with 3 partitions
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 0 Leader 0
%7|1595590830.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 1 Leader 0
%7|1595590830.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 2 Leader 0
%7|1595590830.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590830.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-0.kafka-hs.default.svc.cluster.local:9093/0: 1/1 requested topic(s) seen in metadata
%7|1595590831.024|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
%7|1595590831.024|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
%7|1595590831.024|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Request metadata for 1 topic(s): refresh unavailable topics
%7|1595590831.024|SEND|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 14)
%7|1595590831.024|RECV|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Received MetadataResponse (v2, 197 bytes, CorrId 14, rtt 0.41ms)
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1 brokers, 1 topics
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Topic #0/1: test_subscribe_topic with 3 partitions
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 0 Leader 0
%7|1595590831.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 1 Leader 0
%7|1595590831.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 2 Leader 0
%7|1595590831.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590831.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1/1 requested topic(s) seen in metadata
%7|1595590832.024|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: broker is internal: re-query
%7|1595590832.024|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: broker is internal: re-query
%7|1595590832.024|QRYLEADER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: broker is internal: re-query
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: Requesting metadata for 1/1 topics: refresh unavailable topics
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Request metadata for 1 topic(s): refresh unavailable topics
%7|1595590832.024|SEND|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Sent MetadataRequest (v2, 47 bytes @ 0, CorrId 15)
%7|1595590832.024|RECV|rdkafka#producer-1| [thrd:kafka-hs:9093/bootstrap]: kafka-hs:9093/bootstrap: Received MetadataResponse (v2, 197 bytes, CorrId 15, rtt 0.32ms)
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ===== Received metadata (for 1 requested topics): refresh unavailable topics =====
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: ClusterId: TGoKshWwRPenDzftpf0cJQ, ControllerId: 0
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1 brokers, 1 topics
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Broker #0/1: kafka-0.kafka-hs.default.svc.cluster.local:9093 NodeId 0
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: Topic #0/1: test_subscribe_topic with 3 partitions
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 0 Leader 0
%7|1595590832.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [0]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 1 Leader 0
%7|1595590832.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [1]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic partition 2 Leader 0
%7|1595590832.024|BROKER|rdkafka#producer-1| [thrd:main]: Topic test_subscribe_topic [2]: leader 0 unchanged, not migrating away from preferred replica 0
%7|1595590832.024|METADATA|rdkafka#producer-1| [thrd:main]: kafka-hs:9093/bootstrap: 1/1 requested topic(s) seen in metadata

@pauelm
Copy link

pauelm commented Aug 13, 2020

Lasuerte,

There could be an underlying defect with librdkafka on this specific issue, but I believe this is by design.

There could also be some other broker or topic configuration issues. However, those would be separate, yet compounding issues. Nevertheless, if your brokers are causing unexpected service disruptions, then you might want to investigate and try to resolve those first, if possible.

Now, on to the subject of your Kafka Producers:
One could argue that since it is essential that a Kafka Producer makes a successful connection with the Kafka cluster when it submits an event (not the other way around), and brokers obviously go down anytime they are restarted for any reason, then it is the responsibility of the producer to ensure it has an active connection to the broker. If a Kafka Producer errors out because it lost connection to the cluster, then the problem and fault with Producer-generated errors is with the producer (even if / when a cluster connection is lost because a problem with a Broker). This also explains why your producer runs just fine after it is restarted (after a broker experienced a restart or service disruption beforehand).

Develop your Kafka Producers, not with the potential for Brokers to go down, but with the explicit expectation that this is going to happen, and will happen again sooner or later. By the way, the same thing applies to Kafka Consumers. I develop my producers and consumers with this type of resiliency. As a result, when there is any type of service disruptions in the cluster, I can usually keep the investigation and troubleshooting focused on Zookeeper and Kafka Brokers, knowing my producers and consumers will automatically take care of themselves when Kafka Broker and / or Zookeeper issues are resolved. Moreover, with producers and consumers developed this way, you also do not have to worry about the order in which everything comes back online, unlike Zookeeper and the Kafka Brokers, due to their metadata dependencies.

This not only helps to minimize disruption times during unexpected broker issues, but also greatly simplifies and streamlines maintenance operations as well. In any scenario, developing your Kafka Producers and Consumers this way greatly enhances service operational performance and business continuity.

@edenhill
Copy link
Contributor

This is a bug introduced in v1.3.0 which is fixed in v1.4.2. Please upgrade to 1.5.0

@edenhill
Copy link
Contributor

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

No branches or pull requests

3 participants