search

confluentinc / librdkafka

The Apache Kafka C/C++ library
Other
207 stars 3.14k forks source link

rd_kafka_send_offsets_to_transaction hangs indefinitely #3013

Closed sanjay24 closed 3 years ago

sanjay24 commented 4 years ago

Description

Transactional producer hangs in call to rd_kafka_send_offsets_to_transaction (even with timeout_ms specified e.g.500ms).

How to reproduce

It is based on examples/transactions.c, and use case is pretty simple. There are multiple (around 600) input topics which are aggregated into a single output topic

Checklist

Please provide the following information:

sanjay24 commented 4 years ago 
22:37:20.652434061 [Debug ] [KAFKA_TX_PUBLISHER] [7] [WAKEUPFD] [thrd:app]: kafka-test-cluster:9092/bootstrap: Enabled low-latency ops queue wake-ups
22:37:20.653045434 [Debug ] [KAFKA_TX_PUBLISHER] [7] [BROKER] [thrd:app]: kafka-test-cluster:9092/bootstrap: Added new broker with NodeId -1
22:37:20.653108161 [Debug ] [KAFKA_TX_PUBLISHER] [7] [CONNECT] [thrd:app]: kafka-test-cluster:9092/bootstrap: Selected for cluster connection: bootstrap servers added (broker has 0 connection attempt(s))
22:37:20.652434346 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BRKMAIN] [thrd::0/internal]: :0/internal: Enter main broker thread
22:37:20.653154808 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BRKMAIN] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enter main broker thread
22:37:20.656495175 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Received CONNECT op
22:37:20.656603489 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Broker changed state INIT -> TRY_CONNECT
22:37:20.654760777 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUPFD] [thrd:main]: TxnCoordinator: Enabled low-latency ops queue wake-ups
22:37:20.656638086 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:kafka-test-cluster:9092/bootstrap]: Broadcasting state change
22:37:20.656663815 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: broker in state TRY_CONNECT connecting
22:37:20.656670210 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Broker changed state TRY_CONNECT -> CONNECT
22:37:20.656675251 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:kafka-test-cluster:9092/bootstrap]: Broadcasting state change
22:37:20.656734512 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROKER] [thrd:main]: TxnCoordinator: Added new broker with NodeId -1
22:37:20.657279746 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [INIT] [thrd:app]: librdkafka v1.4.2-1-g52e0a7 (0x10402ff) rdkafka#producer-1 initialized (builtin.features gzip,snappy,ssl,sasl,regex,lz4,sasl_plain,sasl_scram,plugins,sasl_oauthbearer, GCC GXX PKGCONFIG INSTALL GNULD LDS LIBDL PLUGINS ZLIB SSL HDRHISTOGRAM SYSLOG SNAPPY SOCKEM SASL_SCRAM SASL_OAUTHBEARER CRC32C_HW, debug 0xfffff)
22:37:20.657391345 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [TXNAPI] [thrd:app]: Transactional API called: init_transactions
22:37:20.658107464 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNSTATE] [thrd:main]: Transaction state change Init -> WaitPID
22:37:20.658236540 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [IDEMPSTATE] [thrd:main]: Idempotent producer state change Init -> RequestPID
22:37:20.658248152 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXN] [thrd:main]: Starting PID FSM timer (fire immediately): Starting idempotent producer
22:37:20.659419311 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:main]: Not selecting any broker for cluster connection: still suppressed for 43ms: acquire ProducerID
22:37:20.659431733 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [PIDBROKER] [thrd:main]: No brokers available for Transactions (2 broker(s) known)
22:37:20.659438217 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNCOORD] [thrd:main]: Unable to query for transaction coordinator: No brokers available for Transactions (2 broker(s) known)
22:37:20.656864466 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BRKMAIN] [thrd:TxnCoordinator]: TxnCoordinator: Enter main broker thread
22:37:20.660569591 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:TxnCoordinator]: TxnCoordinator: Broker changed state INIT -> TRY_CONNECT
22:37:20.660597006 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:TxnCoordinator]: Broadcasting state change
22:37:20.660603068 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:TxnCoordinator]: TxnCoordinator: broker in state TRY_CONNECT connecting
22:37:20.660608329 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:TxnCoordinator]: TxnCoordinator: broker has no address yet: postponing connect
22:37:20.661339822 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Connecting to ipv4#10.76.128.196:9092 (plaintext) with socket 10
22:37:20.662417990 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Connected to ipv4#10.76.128.196:9092
22:37:20.662434798 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECTED] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Connected (#1)
22:37:20.662442677 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [FEATURE] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Updated enabled protocol features +ApiVersion to ApiVersion
22:37:20.662448331 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Broker changed state CONNECT -> APIVERSION_QUERY
22:37:20.662453800 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:kafka-test-cluster:9092/bootstrap]: Broadcasting state change
22:37:20.662491823 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Sent ApiVersionRequest (v3, 50 bytes @ 0, CorrId 1)
22:37:20.663522263 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Received ApiVersionResponse (v3, 6 bytes, CorrId 1, rtt 1.03ms)
22:37:20.663542510 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [PROTOERR] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Protocol parse failure for ApiVersion v3 at 3/6 (rd_kafka_handle_ApiVersion:1915) (incorrect broker.version.fallback?)
22:37:20.663549673 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [PROTOERR] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: ApiArrayCnt -1 out of range
22:37:20.663557324 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: ApiVersionRequest v3 failed due to UNSUPPORTED_VERSION: retrying with v0
22:37:20.663581223 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Sent ApiVersionRequest (v0, 21 bytes @ 0, CorrId 2)
22:37:20.664553955 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Received ApiVersionResponse (v0, 264 bytes, CorrId 2, rtt 0.97ms)
22:37:20.664569903 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Broker API support:
22:37:20.664578475 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey Produce (0) Versions 0..7
22:37:20.664584087 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey Fetch (1) Versions 0..10
22:37:20.664589039 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey Offset (2) Versions 0..4
22:37:20.664593983 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey Metadata (3) Versions 0..7
22:37:20.664598831 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey LeaderAndIsr (4) Versions 0..1
22:37:20.664603863 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey StopReplica (5) Versions 0..0
22:37:20.664608726 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey UpdateMetadata (6) Versions 0..4
22:37:20.664613604 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey ControlledShutdown (7) Versions 0..1
22:37:20.664618508 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey OffsetCommit (8) Versions 0..6
22:37:20.664623489 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey OffsetFetch (9) Versions 0..5
22:37:20.664628331 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey FindCoordinator (10) Versions 0..2
22:37:20.664633361 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey JoinGroup (11) Versions 0..3
22:37:20.664638260 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey Heartbeat (12) Versions 0..2
22:37:20.664643217 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey LeaveGroup (13) Versions 0..2
22:37:20.664648157 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey SyncGroup (14) Versions 0..2
22:37:20.664653236 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DescribeGroups (15) Versions 0..2
22:37:20.664658205 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey ListGroups (16) Versions 0..2
22:37:20.664663070 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey SaslHandshake (17) Versions 0..1
22:37:20.664667991 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey ApiVersion (18) Versions 0..2
22:37:20.664677025 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey CreateTopics (19) Versions 0..3
22:37:20.664682376 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DeleteTopics (20) Versions 0..3
22:37:20.664687375 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DeleteRecords (21) Versions 0..1
22:37:20.664692208 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey InitProducerId (22) Versions 0..1
22:37:20.664697176 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey OffsetForLeaderEpoch (23) Versions 0..2
22:37:20.664702148 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey AddPartitionsToTxn (24) Versions 0..1
22:37:20.664707089 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey AddOffsetsToTxn (25) Versions 0..1
22:37:20.664711991 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey EndTxn (26) Versions 0..1
22:37:20.664716897 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey WriteTxnMarkers (27) Versions 0..0
22:37:20.664721806 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey TxnOffsetCommit (28) Versions 0..2
22:37:20.664726672 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DescribeAcls (29) Versions 0..1
22:37:20.664731512 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey CreateAcls (30) Versions 0..1
22:37:20.664736399 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DeleteAcls (31) Versions 0..1
22:37:20.664741214 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DescribeConfigs (32) Versions 0..2
22:37:20.664746074 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey AlterConfigs (33) Versions 0..1
22:37:20.664750961 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey AlterReplicaLogDirs (34) Versions 0..1
22:37:20.664755832 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DescribeLogDirs (35) Versions 0..1
22:37:20.664760690 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey SaslAuthenticate (36) Versions 0..0
22:37:20.664765635 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey CreatePartitions (37) Versions 0..1
22:37:20.664770560 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey CreateDelegationToken (38) Versions 0..1
22:37:20.664775447 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey RenewDelegationToken (39) Versions 0..1
22:37:20.664782176 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey ExpireDelegationToken (40) Versions 0..1
22:37:20.664787340 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DescribeDelegationToken (41) Versions 0..1
22:37:20.664792321 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:   ApiKey DeleteGroups (42) Versions 0..1
22:37:20.664802851 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature MsgVer1: Produce (2..2) supported by broker
22:37:20.664808698 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature MsgVer1: Fetch (2..2) supported by broker
22:37:20.664814005 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature MsgVer1
22:37:20.664819299 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature MsgVer2: Produce (3..3) supported by broker
22:37:20.664824482 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature MsgVer2: Fetch (4..4) supported by broker
22:37:20.664829491 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature MsgVer2
22:37:20.664836712 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature ApiVersion: ApiVersion (0..0) supported by broker
22:37:20.664842040 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature ApiVersion
22:37:20.664847515 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerGroupCoordinator: FindCoordinator (0..0) supported by broker
22:37:20.664852548 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature BrokerGroupCoordinator
22:37:20.664857713 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerBalancedConsumer: FindCoordinator (0..0) supported by broker
22:37:20.664863023 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerBalancedConsumer: OffsetCommit (1..2) supported by broker
22:37:20.664868262 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerBalancedConsumer: OffsetFetch (1..1) supported by broker
22:37:20.664873497 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerBalancedConsumer: JoinGroup (0..0) supported by broker
22:37:20.664905105 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerBalancedConsumer: SyncGroup (0..0) supported by broker
22:37:20.664912898 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerBalancedConsumer: Heartbeat (0..0) supported by broker
22:37:20.664918432 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature BrokerBalancedConsumer: LeaveGroup (0..0) supported by broker
22:37:20.664926559 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature BrokerBalancedConsumer
22:37:20.664932538 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature ThrottleTime: Produce (1..2) supported by broker
22:37:20.664950895 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature ThrottleTime: Fetch (1..2) supported by broker
22:37:20.664955955 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature ThrottleTime
22:37:20.664961193 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature Sasl: JoinGroup (0..0) supported by broker
22:37:20.664966285 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature Sasl
22:37:20.664971480 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature SaslHandshake: SaslHandshake (0..0) supported by broker
22:37:20.664976563 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature SaslHandshake
22:37:20.664981849 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature LZ4: FindCoordinator (0..0) supported by broker
22:37:20.664986865 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature LZ4
22:37:20.664992080 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature OffsetTime: Offset (1..1) supported by broker
22:37:20.664997125 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature OffsetTime
22:37:20.665002404 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature IdempotentProducer: InitProducerId (0..0) supported by broker
22:37:20.665007458 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature IdempotentProducer
22:37:20.665012597 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature ZSTD: Produce (7..7) supported by broker
22:37:20.665017843 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature ZSTD: Fetch (10..10) supported by broker
22:37:20.665022868 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature ZSTD
22:37:20.665028046 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature SaslAuthReq: SaslHandshake (1..1) supported by broker
22:37:20.665033564 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap:  Feature SaslAuthReq: SaslAuthenticate (0..0) supported by broker
22:37:20.665038608 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Enabling feature SaslAuthReq
22:37:20.665047345 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [FEATURE] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Updated enabled protocol features to MsgVer1,ApiVersion,BrokerBalancedConsumer,ThrottleTime,Sasl,SaslHandshake,BrokerGroupCoordinator,LZ4,OffsetTime,MsgVer2,IdempotentProducer,ZSTD,SaslAuthReq
22:37:20.665053351 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Broker changed state APIVERSION_QUERY -> UP
22:37:20.665079966 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:kafka-test-cluster:9092/bootstrap]: Broadcasting state change
22:37:20.665099829 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Request metadata for brokers only: connected
22:37:20.665121987 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Sent MetadataRequest (v2, 25 bytes @ 0, CorrId 3)
22:37:20.666059027 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Received MetadataResponse (v2, 108 bytes, CorrId 3, rtt 0.94ms)
22:37:20.666097455 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: kafka-test-cluster:9092/bootstrap: ===== Received metadata: connected =====
22:37:20.666116241 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: kafka-test-cluster:9092/bootstrap: ClusterId: ReoFt6AQTMO3BQ3AqAZrwQ, ControllerId: 1
22:37:20.666122557 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: kafka-test-cluster:9092/bootstrap: 3 brokers, 0 topics
22:37:20.666131100 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: kafka-test-cluster:9092/bootstrap:   Broker #0/3: host_1045:9092 NodeId 2
22:37:20.666153938 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUPFD] [thrd:main]: host_1045:9092/2: Enabled low-latency ops queue wake-ups
22:37:20.666216829 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROKER] [thrd:main]: host_1045:9092/2: Added new broker with NodeId 2
22:37:20.666228343 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: kafka-test-cluster:9092/bootstrap:   Broker #1/3: host_1168:9092 NodeId 3
22:37:20.666247803 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUPFD] [thrd:main]: host_1168:9092/3: Enabled low-latency ops queue wake-ups
22:37:20.666396053 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROKER] [thrd:main]: host_1168:9092/3: Added new broker with NodeId 3
22:37:20.666422250 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: kafka-test-cluster:9092/bootstrap:   Broker #2/3: host_1044:9092 NodeId 1
22:37:20.666442391 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUPFD] [thrd:main]: host_1044:9092/1: Enabled low-latency ops queue wake-ups
22:37:20.666802930 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROKER] [thrd:main]: host_1044:9092/1: Added new broker with NodeId 1
22:37:20.666819354 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CLUSTERID] [thrd:main]: kafka-test-cluster:9092/bootstrap: ClusterId update "" -> "ReoFt6AQTMO3BQ3AqAZrwQ"
22:37:20.666843239 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONTROLLERID] [thrd:main]: kafka-test-cluster:9092/bootstrap: ControllerId update -1 -> 1
22:37:20.666863805 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:main]: Broadcasting state change
22:37:20.667040576 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Sent FindCoordinatorRequest (v2, 53 bytes @ 0, CorrId 4)
22:37:20.668033815 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Received FindCoordinatorResponse (v2, 30 bytes, CorrId 4, rtt 0.99ms)
22:37:20.668277662 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNCOORD] [thrd:main]: kafka-test-cluster:9092/bootstrap: FindCoordinator response: Transaction coordinator is broker 2 (host_1045:9092)
22:37:20.668291850 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNCOORD] [thrd:main]: Transaction coordinator changed from (none) -> host_1045:9092/2: FindCoordinator response
22:37:20.668299006 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [NODENAME] [thrd:main]: TxnCoordinator: Broker nodename changed from "" to "host_1045:9092"
22:37:20.668321084 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [IDEMPSTATE] [thrd:main]: Idempotent producer state change RequestPID -> WaitTransport
22:37:20.668328490 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXN] [thrd:main]: Starting PID FSM timer: No broker available
22:37:20.668331737 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROKERFAIL] [thrd:TxnCoordinator]: TxnCoordinator: failed: err: Local: Broker transport failure: (errno: Success)
22:37:20.668347783 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [FAIL] [thrd:TxnCoordinator]: TxnCoordinator: Closing connection due to nodename change (after 7ms in state TRY_CONNECT)
22:37:20.668369338 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:TxnCoordinator]: TxnCoordinator: Broker changed state TRY_CONNECT -> DOWN
22:37:20.668379884 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:TxnCoordinator]: Broadcasting state change
22:37:20.668392912 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BUFQ] [thrd:TxnCoordinator]: TxnCoordinator/2: Purging bufq with 0 buffers
22:37:20.668402044 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BUFQ] [thrd:TxnCoordinator]: TxnCoordinator/2: Purging bufq with 0 buffers
22:37:20.668407836 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BUFQ] [thrd:TxnCoordinator]: TxnCoordinator/2: Updating 0 buffers on connection reset
22:37:20.668413926 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:TxnCoordinator]: TxnCoordinator: Broker changed state DOWN -> INIT
22:37:20.668419308 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:TxnCoordinator]: Broadcasting state change
22:37:20.668424439 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:TxnCoordinator]: TxnCoordinator: Broker changed state INIT -> TRY_CONNECT
22:37:20.668429157 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:TxnCoordinator]: Broadcasting state change
22:37:20.668434829 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:TxnCoordinator]: TxnCoordinator/2: broker in state TRY_CONNECT connecting
22:37:20.668440014 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:TxnCoordinator]: TxnCoordinator: Broker changed state TRY_CONNECT -> CONNECT
22:37:20.668444764 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:TxnCoordinator]: Broadcasting state change
22:37:20.666562109 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BRKMAIN] [thrd:host_1168:9092/3]: host_1168:9092/3: Enter main broker thread
22:37:20.667076877 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BRKMAIN] [thrd:host_1044:9092/1]: host_1044:9092/1: Enter main broker thread
22:37:20.666241360 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BRKMAIN] [thrd:host_1045:9092/2]: host_1045:9092/2: Enter main broker thread
22:37:21.159601014 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Sent FindCoordinatorRequest (v2, 53 bytes @ 0, CorrId 5)
22:37:21.160737605 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:kafka-test-cluster:9092/bootstrap]: kafka-test-cluster:9092/bootstrap: Received FindCoordinatorResponse (v2, 30 bytes, CorrId 5, rtt 1.14ms)
22:37:21.160851242 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNCOORD] [thrd:main]: kafka-test-cluster:9092/bootstrap: FindCoordinator response: Transaction coordinator is broker 2 (host_1045:9092)
22:37:21.168336213 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXN] [thrd:main]: Starting PID FSM timer: No broker available
22:37:21.668356304 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXN] [thrd:main]: Starting PID FSM timer: No broker available
22:37:22.168515488 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXN] [thrd:main]: Starting PID FSM timer: No broker available
22:37:22.668566425 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXN] [thrd:main]: Starting PID FSM timer: No broker available
22:37:22.671641176 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:TxnCoordinator]: TxnCoordinator/2: Connecting to ipv4#10.76.128.196:9092 (plaintext) with socket 17
22:37:22.672736230 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECT] [thrd:TxnCoordinator]: TxnCoordinator/2: Connected to ipv4#10.76.128.196:9092
22:37:22.672751588 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [CONNECTED] [thrd:TxnCoordinator]: TxnCoordinator/2: Connected (#1)
22:37:22.672759676 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [FEATURE] [thrd:TxnCoordinator]: TxnCoordinator/2: Updated enabled protocol features +ApiVersion to ApiVersion
22:37:22.672765404 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:TxnCoordinator]: TxnCoordinator: Broker changed state CONNECT -> APIVERSION_QUERY
22:37:22.672770729 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:TxnCoordinator]: Broadcasting state change
22:37:22.672796707 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:TxnCoordinator]: TxnCoordinator/2: Sent ApiVersionRequest (v3, 50 bytes @ 0, CorrId 1)
22:37:22.673972044 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:TxnCoordinator]: TxnCoordinator/2: Received ApiVersionResponse (v3, 6 bytes, CorrId 1, rtt 1.17ms)
22:37:22.673986435 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [PROTOERR] [thrd:TxnCoordinator]: TxnCoordinator/2: Protocol parse failure for ApiVersion v3 at 3/6 (rd_kafka_handle_ApiVersion:1915) (incorrect broker.version.fallback?)
22:37:22.673993460 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [PROTOERR] [thrd:TxnCoordinator]: TxnCoordinator/2: ApiArrayCnt -1 out of range
22:37:22.673999418 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: ApiVersionRequest v3 failed due to UNSUPPORTED_VERSION: retrying with v0
22:37:22.674018421 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:TxnCoordinator]: TxnCoordinator/2: Sent ApiVersionRequest (v0, 21 bytes @ 0, CorrId 2)
22:37:22.674928135 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:TxnCoordinator]: TxnCoordinator/2: Received ApiVersionResponse (v0, 264 bytes, CorrId 2, rtt 0.91ms)
22:37:22.674939040 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Broker API support:
22:37:22.674945654 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey Produce (0) Versions 0..7
22:37:22.674951360 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey Fetch (1) Versions 0..10
22:37:22.674956806 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey Offset (2) Versions 0..4
22:37:22.674962136 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey Metadata (3) Versions 0..7
22:37:22.674967469 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey LeaderAndIsr (4) Versions 0..1
22:37:22.674972873 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey StopReplica (5) Versions 0..0
22:37:22.674978276 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey UpdateMetadata (6) Versions 0..4
22:37:22.674987796 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey ControlledShutdown (7) Versions 0..1
22:37:22.674993618 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey OffsetCommit (8) Versions 0..6
22:37:22.674999010 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey OffsetFetch (9) Versions 0..5
22:37:22.675004354 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey FindCoordinator (10) Versions 0..2
22:37:22.675009703 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey JoinGroup (11) Versions 0..3
22:37:22.675015024 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey Heartbeat (12) Versions 0..2
22:37:22.675020297 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey LeaveGroup (13) Versions 0..2
22:37:22.675025605 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey SyncGroup (14) Versions 0..2
22:37:22.675030967 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DescribeGroups (15) Versions 0..2
22:37:22.675036267 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey ListGroups (16) Versions 0..2
22:37:22.675041581 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey SaslHandshake (17) Versions 0..1
22:37:22.675046845 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey ApiVersion (18) Versions 0..2
22:37:22.675052183 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey CreateTopics (19) Versions 0..3
22:37:22.675057560 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DeleteTopics (20) Versions 0..3
22:37:22.675062721 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DeleteRecords (21) Versions 0..1
22:37:22.675067771 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey InitProducerId (22) Versions 0..1
22:37:22.675072764 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey OffsetForLeaderEpoch (23) Versions 0..2
22:37:22.675077733 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey AddPartitionsToTxn (24) Versions 0..1
22:37:22.675082728 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey AddOffsetsToTxn (25) Versions 0..1
22:37:22.675087771 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey EndTxn (26) Versions 0..1
22:37:22.675092811 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey WriteTxnMarkers (27) Versions 0..0
22:37:22.675097805 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey TxnOffsetCommit (28) Versions 0..2
22:37:22.675102795 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DescribeAcls (29) Versions 0..1
22:37:22.675107846 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey CreateAcls (30) Versions 0..1
22:37:22.675112829 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DeleteAcls (31) Versions 0..1
22:37:22.675119596 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DescribeConfigs (32) Versions 0..2
22:37:22.675124952 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey AlterConfigs (33) Versions 0..1
22:37:22.675130028 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey AlterReplicaLogDirs (34) Versions 0..1
22:37:22.675135061 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DescribeLogDirs (35) Versions 0..1
22:37:22.675140054 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey SaslAuthenticate (36) Versions 0..0
22:37:22.675145099 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey CreatePartitions (37) Versions 0..1
22:37:22.675150114 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey CreateDelegationToken (38) Versions 0..1
22:37:22.675155188 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey RenewDelegationToken (39) Versions 0..1
22:37:22.675160275 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey ExpireDelegationToken (40) Versions 0..1
22:37:22.675165301 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DescribeDelegationToken (41) Versions 0..1
22:37:22.675170325 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:   ApiKey DeleteGroups (42) Versions 0..1
22:37:22.675178275 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature MsgVer1: Produce (2..2) supported by broker
22:37:22.675183783 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature MsgVer1: Fetch (2..2) supported by broker
22:37:22.675188967 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature MsgVer1
22:37:22.675194595 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature MsgVer2: Produce (3..3) supported by broker
22:37:22.675204235 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature MsgVer2: Fetch (4..4) supported by broker
22:37:22.675212864 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature MsgVer2
22:37:22.675218374 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature ApiVersion: ApiVersion (0..0) supported by broker
22:37:22.675223605 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature ApiVersion
22:37:22.675228935 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerGroupCoordinator: FindCoordinator (0..0) supported by broker
22:37:22.675234104 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature BrokerGroupCoordinator
22:37:22.675239286 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerBalancedConsumer: FindCoordinator (0..0) supported by broker
22:37:22.675244576 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerBalancedConsumer: OffsetCommit (1..2) supported by broker
22:37:22.675249867 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerBalancedConsumer: OffsetFetch (1..1) supported by broker
22:37:22.675267990 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerBalancedConsumer: JoinGroup (0..0) supported by broker
22:37:22.675276931 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerBalancedConsumer: SyncGroup (0..0) supported by broker
22:37:22.675282966 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerBalancedConsumer: Heartbeat (0..0) supported by broker
22:37:22.675288623 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature BrokerBalancedConsumer: LeaveGroup (0..0) supported by broker
22:37:22.675294133 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature BrokerBalancedConsumer
22:37:22.675299817 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature ThrottleTime: Produce (1..2) supported by broker
22:37:22.675305476 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature ThrottleTime: Fetch (1..2) supported by broker
22:37:22.675310880 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature ThrottleTime
22:37:22.675316474 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature Sasl: JoinGroup (0..0) supported by broker
22:37:22.675321855 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature Sasl
22:37:22.675327485 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature SaslHandshake: SaslHandshake (0..0) supported by broker
22:37:22.675332900 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature SaslHandshake
22:37:22.675338463 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature LZ4: FindCoordinator (0..0) supported by broker
22:37:22.675343753 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature LZ4
22:37:22.675349286 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature OffsetTime: Offset (1..1) supported by broker
22:37:22.675354610 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature OffsetTime
22:37:22.675415552 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature IdempotentProducer: InitProducerId (0..0) supported by broker
22:37:22.675431313 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature IdempotentProducer
22:37:22.675451994 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature ZSTD: Produce (7..7) supported by broker
22:37:22.675457488 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature ZSTD: Fetch (10..10) supported by broker
22:37:22.675462617 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature ZSTD
22:37:22.675468012 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature SaslAuthReq: SaslHandshake (1..1) supported by broker
22:37:22.675473325 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2:  Feature SaslAuthReq: SaslAuthenticate (0..0) supported by broker
22:37:22.675478461 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [APIVERSION] [thrd:TxnCoordinator]: TxnCoordinator/2: Enabling feature SaslAuthReq
22:37:22.675485427 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [FEATURE] [thrd:TxnCoordinator]: TxnCoordinator/2: Updated enabled protocol features to MsgVer1,ApiVersion,BrokerBalancedConsumer,ThrottleTime,Sasl,SaslHandshake,BrokerGroupCoordinator,LZ4,OffsetTime,MsgVer2,IdempotentProducer,ZSTD,SaslAuthReq
22:37:22.675493679 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [STATE] [thrd:TxnCoordinator]: TxnCoordinator: Broker changed state APIVERSION_QUERY -> UP
22:37:22.675520661 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [BROADCAST] [thrd:TxnCoordinator]: Broadcasting state change
22:37:22.675533768 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:TxnCoordinator]: TxnCoordinator/2: Request metadata for brokers only: connected
22:37:22.675554106 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:TxnCoordinator]: TxnCoordinator/2: Sent MetadataRequest (v2, 25 bytes @ 0, CorrId 3)
22:37:22.675568672 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [COORD] [thrd:main]: TxnCoordinator/2: Transaction coordinator is now up
22:37:22.675582848 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [GETPID] [thrd:main]: TxnCoordinator/2: Acquiring ProducerId
22:37:22.675598787 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [IDEMPSTATE] [thrd:main]: Idempotent producer state change WaitTransport -> WaitPID
22:37:22.675620434 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [SEND] [thrd:TxnCoordinator]: TxnCoordinator/2: Sent InitProducerIdRequest (v1, 56 bytes @ 0, CorrId 4)
22:37:22.676537072 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:TxnCoordinator]: TxnCoordinator/2: Received MetadataResponse (v2, 108 bytes, CorrId 3, rtt 0.98ms)
22:37:22.676609095 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: TxnCoordinator/2: ===== Received metadata: connected =====
22:37:22.676637185 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: TxnCoordinator/2: ClusterId: ReoFt6AQTMO3BQ3AqAZrwQ, ControllerId: 1
22:37:22.676643659 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: TxnCoordinator/2: 3 brokers, 0 topics
22:37:22.676662744 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: TxnCoordinator/2:   Broker #0/3: host_1045:9092 NodeId 2
22:37:22.676668956 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: TxnCoordinator/2:   Broker #1/3: host_1168:9092 NodeId 3
22:37:22.676674570 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [METADATA] [thrd:main]: TxnCoordinator/2:   Broker #2/3: host_1044:9092 NodeId 1
22:37:22.701774357 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [RECV] [thrd:TxnCoordinator]: TxnCoordinator/2: Received InitProducerIdResponse (v1, 16 bytes, CorrId 4, rtt 26.15ms)
22:37:22.701847723 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [GETPID] [thrd:main]: Acquired PID{Id:121017,Epoch:0}
22:37:22.701872911 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [IDEMPSTATE] [thrd:main]: Idempotent producer state change WaitPID -> Assigned
22:37:22.701879352 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNSTATE] [thrd:main]: Transaction state change WaitPID -> ReadyNotAcked
22:37:22.701921003 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [TXNAPI] [thrd:app]: Transactional API called: init_transactions
22:37:22.701948875 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: host_1044:9092/1: Wake-up
22:37:22.701980334 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: host_1168:9092/3: Wake-up
22:37:22.702039067 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: host_1045:9092/2: Wake-up
22:37:22.702051825 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: TxnCoordinator/2: Wake-up
22:37:22.702077520 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: kafka-test-cluster:9092/bootstrap: Wake-up
22:37:22.702202639 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNSTATE] [thrd:main]: Transaction state change ReadyNotAcked -> Ready
22:37:22.702243783 [Info  ] [KAFKA_TX_PUBLISHER] [main] Initialized transactional producer
22:37:22.702255475 [Info  ] [KAFKA_TX_PUBLISHER] [main] beginning transaction
22:37:22.702296161 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [TXNSTATE] [thrd:main]: Transaction state change Ready -> InTransaction
22:37:22.702328576 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: host_1044:9092/1: Wake-up
22:37:22.702359601 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: host_1168:9092/3: Wake-up
22:37:22.702413028 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: host_1045:9092/2: Wake-up
22:37:22.702425779 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: TxnCoordinator/2: Wake-up
22:37:22.702451350 [Debug ] [KAFKA_TX_PUBLISHER] [anonymous] [7] [WAKEUP] [thrd:main]: kafka-test-cluster:9092/bootstrap: Wake-up
22:37:22.702546693 [Debug ] [KAFKA_TX_PUBLISHER] [main] Created transactional producer [trx_producer]
22:37:33.212717062 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [TOPIC] [thrd:app]: New local topic: ot.TRANSACTIONS_TEST
22:37:33.212720739 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [TOPPARNEW] [thrd:app]: NEW ot.TRANSACTIONS_TEST [-1] 0x1b59cb0 (at rd_kafka_topic_new0:397)
22:37:33.212727109 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [METADATA] [thrd:app]: Hinted cache of 1/1 topic(s) being queried
22:37:33.212728172 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [METADATA] [thrd:app]: Requesting metadata for 1/1 topics: leader query
22:37:33.212733335 [Debug ] [KAFKA_TX_PUBLISHER] [main] [7] [METADATA] [thrd:app]: kafka-test-cluster:9092/bootstrap: Request metadata for 1 topic(s): leader query
22:37:33.230133970 [Debug ] [KAFKA_TX_PUBLISHER] [main] fetch rdkafka consumer handle
22:37:33.233111281 [Info  ] [KAFKA_TX_PUBLISHER] [main] sending consumer current offsets to tx coordinator
22:37:33.233131551 [Debug ] [KAFKA_TX_PUBLISHER] [min] [7] [TXNAPI] [thrd:app]: Transactional API called: send_offsets_to_transaction
sanjay24 commented 4 years ago

as can be seen in the logs above I can't see any Sent MetadataRequest after the request metadata for 1 topic(s): leader query. And send_offsets_to_transaction never returns.

sanjay24 commented 4 years ago

Here's relevant part of the stacktrace

#0  0x00007f364ba06995 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x00000000008a9a49 in cnd_wait (cond=<optimized out>, mtx=<optimized out>) at tinycthread.c:442
#2  0x00000000008a9e25 in cnd_timedwait_abs (cnd=cnd@entry=0x1b7a908, mtx=mtx@entry=0x1b7a8e0, tspec=tspec@entry=0x7ffe1f1ddea0) at tinycthread_extra.c:99
#3  0x000000000086cd7b in rd_kafka_q_pop_serve (rkq=rkq@entry=0x1b7a8e0, timeout_us=<optimized out>, version=version@entry=0, cb_type=cb_type@entry=RD_KAFKA_Q_CB_RETURN,
    callback=callback@entry=0x0, opaque=opaque@entry=0x0) at rdkafka_queue.c:404
#4  0x000000000086ce70 in rd_kafka_q_pop (rkq=rkq@entry=0x1b7a8e0, timeout_us=<optimized out>, version=version@entry=0) at rdkafka_queue.c:428
#5  0x000000000087084f in rd_kafka_op_req0 (destq=<optimized out>, recvq=recvq@entry=0x1b7a8e0, rko=rko@entry=0x1b7a810, timeout_ms=timeout_ms@entry=-1) at rdkafka_op.c:488
#6  0x00000000008c6bd9 in rd_kafka_txn_curr_api_req (rk=rk@entry=0x1b68fb0, name=<optimized out>, name@entry=0xaf3a80 <__FUNCTION__.26278> "rd_kafka_send_offsets_to_transaction",
    rko=rko@entry=0x1b7a810, timeout_ms=60000, timeout_ms@entry=-1, flags=flags@entry=0) at rdkafka_txnmgr.c:1108
#7  0x00000000008cb1fa in rd_kafka_send_offsets_to_transaction (rk=0x1b68fb0, offsets=<optimized out>, cgmetadata=<optimized out>, timeout_ms=<optimized out>) at rdkafka_txnmgr.c:1847
edenhill commented 3 years ago

There's been fixes the transaction manager in the upcoming v1.6.0 release, would be good if you could try to reproduce this on master / v1.6.0-RC1