You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
We are trying to connect a C++ consumer client with a Kafka Topic using the OAUTHBEARER mechanism using libkafkard version '2.3.0'. We seem to be able to get the bearer token but can not establish a permanent connection with the broker. We don't have a network or server configuration issue, because we are able to connect from the same client host with a java client to this topic using the same OAUTHBEARER mechanism.
We use there parameters:
security.protocol=SASL_SSL,
sasl.mechanism=OAUTHBEARER,
sasl.oauthbearer.token.endpoint.url=https://login.microsoftonline.com/****/oauth2/v2.0/token,
auto.offset.reset=earliest,
sasl.oauthbearer.method=oidc,
sasl.oauthbearer.client.id=our-client-id,
sasl.oauthbearer.client.secret=ourclientsecret,
sasl.oauthbearer.scope=our-client-id/.default,
sasl.oauthbearer.extensions=identity-pool-id=our-pool-id,
debug=all,
group.id=our-group-id
Here are our relevant log messages:
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Selected provider OAUTHBEARER (builtin) for SASL mechanism OAUTHBEARER]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Using OpenSSL version OpenSSL 1.1.1k FIPS 25 Mar 2021 (0x101010bf, librdkafka built with 0x101010bf)]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Group "our-group-id": updating member id "(not-set)" -> ""]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: GroupCoordinator: Enabled low-latency ops queue wake-ups]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: GroupCoordinator: Added new broker with NodeId -1]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:GroupCoordinator]: GroupCoordinator: Enter main broker thread]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id" changed state init -> query-coord (join-state init)]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Broadcasting state change]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Enabled low-latency ops queue wake-ups]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Added new broker with NodeId -1]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd::0/internal]: :0/internal: Enter main broker thread]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: librdkafka v2.3.0 (0x20300ff) host-application-name#consumer-1 initialized (builtin.features gzip,snappy,ssl,sasl,regex,lz4,sasl_gssapi,sasl_plain,sasl_scram,plugins,zstd,sasl_oauthbearer,http,oidc, GCC GXX PKGCONFIG INSTALL GNULD LDS C11THREADS LIBDL PLUGINS ZLIB SSL SASL_CYRUS ZSTD CURL HDRHISTOGRAM LZ4_EXT SYSLOG RAPIDJSON SNAPPY SOCKEM SASL_SCRAM SASL_OAUTHBEARER OAUTHBEARER_OIDC CRC32C_HW, debug 0xfffff)]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Enter main broker thread]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Client configuration:]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: client.id = host-application-name]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: client.software.version = 2.3.0]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: metadata.broker.list = pkc-99999.westeurope.azure.confluent.cloud:9092]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: debug = generic,broker,topic,metadata,feature,queue,msg,protocol,cgrp,security,fetch,interceptor,plugin,consumer,admin,eos,mock,assignor,conf,all]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: socket.timeout.ms = 5000]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: error_cb = 0x7f72db8de8b9]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: throttle_cb = 0x7f72db8de9cc]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: stats_cb = 0x7f72db8dea91]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: log_cb = 0x7f72db8de782]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: opaque = 0x7f72c4118b48]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: default_topic_conf = 0x7f72c4119570]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: security.protocol = sasl_ssl]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: ssl_key = [redacted]]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.mechanisms = OAUTHBEARER]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: oauthbearer_token_refresh_cb = 0x7f72d545eac9]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.method = oidc]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.client.id = our-client-id]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.client.secret = ourclientsecret]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.scope = our-client-id/.default]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.extensions = identity-pool-id]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.token.endpoint.url = https://login.microsoftonline.com/****/oauth2/v2.0/token]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: group.id = our-group-id]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: enable.auto.commit = true]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: fetch.wait.max.ms = 5]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: fetch.min.bytes = 1024]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Default topic configuration:]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: auto.offset.reset = smallest]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id" received op ASSIGN in state query-coord (join-state init)]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: No current assignment to clear]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 0 partition(s):]
24/03/20 15:17:30,513 Last message repeat 3 times.
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": assignment operations done in join-state init (rebalance rejoin=false)]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Selected for cluster connection: coordinator query (broker has 0 connection attempt(s))]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Received CONNECT op]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state INIT -> TRY_CONNECT]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id" received op ASSIGN in state query-coord (join-state init)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": new assignment of 1 partition(s) in join-state init]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: No current assignment to clear]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: New local topic: our.topic]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: NEW our.topic [-1] 0x7f72ac002c40 refcnt 0x7f72ac002cd0 (at rd_kafka_topic_new0:472)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Topic "our.topic" configuration (default_topic_conf):]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: auto.offset.reset = smallest]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: NEW our.topic [0] 0x7f72ac003370 refcnt 0x7f72ac003400 (at rd_kafka_toppar_desired_add:645)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0]: marking as DESIRED]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0]: adding to DESIRED list]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Added 1 partition(s) to assignment which now consists of 1 partition(s) where of 1 are in pending state and 0 are being queried]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 0 partition(s):]
24/03/20 15:17:30,515 Last message repeat 1 time.
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Pending assignment partition our.topic [0] can't fetch committed offset yet (cgrp state query-coord, awaiting 0 commits, 0 partition(s) already being queried)]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Current assignment of 1 partition(s) with 1 pending adds, 0 offset queries, 0 partitions awaiting stop and 0 offset commits in progress]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 49ms: coordinator query]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 15:17:31,515 [Connection/140131041339136] Info: Loop ...
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:background]: Waking up waiting broker threads after setting OAUTHBEARER token]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:background]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Wake-up: OAUTHBEARER token update]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:background]: Wake-up sent to 1 broker thread in state >= TRY_CONNECT: OAUTHBEARER token update]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: broker in state TRY_CONNECT connecting]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state TRY_CONNECT -> CONNECT]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Connecting to ipv4#20.31.55.65:9092 (sasl_ssl) with socket 7]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Connected to ipv4#20.31.55.65:9092]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state CONNECT -> SSL_HANDSHAKE]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Enabled endpoint identification using hostname pkc-99999.westeurope.azure.confluent.cloud]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker SSL certificate verified]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Connected (#1)]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Updated enabled protocol features +ApiVersion to ApiVersion]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state SSL_HANDSHAKE -> APIVERSION_QUERY]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Sent ApiVersionRequest (v3, 63 bytes @ 0, CorrId 1)]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Received ApiVersionResponse (v3, 725 bytes, CorrId 1, rtt 1.73ms)]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker API support:]
...
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey DescribeTransactions (65) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey ListTransactions (66) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey AllocateProducerIds (67) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-68? (68) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-69? (69) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-10000? (10000) Versions 0..4]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-10001? (10001) Versions 0..1]
...
24/03/20 14:21:33,044 [Connection/139785840895744] Info: Loop ...
24/03/20 14:21:33,044 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Cluster connection already in progress: coordinator query]
24/03/20 14:21:33,044 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 14:21:33,044 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 49ms: coordinator query]
...
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Topic our.topic [0]: stored offset INVALID (leader epoch -1), committed offset INVALID (leader epoch -1): not including in commit]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: List with 0 partition(s):]
24/03/20 14:21:33,064 Last message repeat 1 time.
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Pending assignment our.topic [0] can't fetch committed offset yet (cgrp state query-coord, awaiting 0 commits, 0 partition(s) already being queried)]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Current assignment of 1 partition(s) with 1 pending adds, 0 offset queries, 0 partitions awaiting stop and 0 offset commits in progress]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 41ms: coordinator query]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
...
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Topic our.topic metadata information unknown]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Topic our.topic partition count is zero: should refresh metadata]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 41ms: refresh unavailable topics]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Hinted cache of 1/1 topic(s) being queried]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Skipping metadata refresh of 1 topic(s): refresh unavailable topics: no usable brokers]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 41ms: no cluster connection]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (5) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Timed out SaslAuthenticateRequest in flight (after 5003ms, timeout #0)]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: SASL authentication error: SaslAuthenticateRequest failed: Local: Timed out (after 5003ms in state AUTH_REQ) (_TIMED_OUT)]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (3) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: SASL authentication error: SaslAuthenticateRequest failed: Local: Timed out (after 5003ms in state AUTH_REQ)]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state AUTH_REQ -> DOWN]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Purging bufq with 0 buffers]
24/03/20 14:21:34,072 Last message repeat 1 time.
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Updating 0 buffers on connection reset]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Cluster connection already in progress: broker down]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Hinted cache of 1/1 topic(s) being queried]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Skipping metadata refresh of 1 topic(s): broker down: no usable brokers]
24/03/20 14:21:34,072 [Connection/139785840895744] Error: Kafka error sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: SASL authentication error: SaslAuthenticateRequest failed: Local: Timed out (after 5003ms in state AUTH_REQ)
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (4) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Timed out 1 in-flight, 0 retry-queued, 0 out-queue, 0 partially-sent requests]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state DOWN -> INIT]
24/03/20 14:21:34,072 [Connection/139785840895744] Error: Kafka error 1/1 brokers are down
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:main]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Selected for cluster connection: coordinator query (broker has 1 connection attempt(s))]
The text was updated successfully, but these errors were encountered:
We are trying to connect a C++ consumer client with a Kafka Topic using the OAUTHBEARER mechanism using libkafkard version '2.3.0'. We seem to be able to get the bearer token but can not establish a permanent connection with the broker. We don't have a network or server configuration issue, because we are able to connect from the same client host with a java client to this topic using the same OAUTHBEARER mechanism.
We use there parameters:
security.protocol=SASL_SSL,
sasl.mechanism=OAUTHBEARER,
sasl.oauthbearer.token.endpoint.url=https://login.microsoftonline.com/****/oauth2/v2.0/token,
auto.offset.reset=earliest,
sasl.oauthbearer.method=oidc,
sasl.oauthbearer.client.id=our-client-id,
sasl.oauthbearer.client.secret=our
clientsecret,sasl.oauthbearer.scope=our-client-id/.default,
sasl.oauthbearer.extensions=identity-pool-id=our-pool-id,
debug=all,
group.id=our-group-id
Here are our relevant log messages:
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Selected provider OAUTHBEARER (builtin) for SASL mechanism OAUTHBEARER]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Using OpenSSL version OpenSSL 1.1.1k FIPS 25 Mar 2021 (0x101010bf, librdkafka built with 0x101010bf)]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Group "our-group-id": updating member id "(not-set)" -> ""]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: GroupCoordinator: Enabled low-latency ops queue wake-ups]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:app]: GroupCoordinator: Added new broker with NodeId -1]
24/03/20 15:17:30,510 [Connection/140131041339136] Kafka: (7) [[thrd:GroupCoordinator]: GroupCoordinator: Enter main broker thread]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id" changed state init -> query-coord (join-state init)]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Broadcasting state change]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Enabled low-latency ops queue wake-ups]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Added new broker with NodeId -1]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd::0/internal]: :0/internal: Enter main broker thread]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: librdkafka v2.3.0 (0x20300ff) host-application-name#consumer-1 initialized (builtin.features gzip,snappy,ssl,sasl,regex,lz4,sasl_gssapi,sasl_plain,sasl_scram,plugins,zstd,sasl_oauthbearer,http,oidc, GCC GXX PKGCONFIG INSTALL GNULD LDS C11THREADS LIBDL PLUGINS ZLIB SSL SASL_CYRUS ZSTD CURL HDRHISTOGRAM LZ4_EXT SYSLOG RAPIDJSON SNAPPY SOCKEM SASL_SCRAM SASL_OAUTHBEARER OAUTHBEARER_OIDC CRC32C_HW, debug 0xfffff)]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Enter main broker thread]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Client configuration:]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: client.id = host-application-name]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: client.software.version = 2.3.0]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: metadata.broker.list = pkc-99999.westeurope.azure.confluent.cloud:9092]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: debug = generic,broker,topic,metadata,feature,queue,msg,protocol,cgrp,security,fetch,interceptor,plugin,consumer,admin,eos,mock,assignor,conf,all]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: socket.timeout.ms = 5000]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: error_cb = 0x7f72db8de8b9]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: throttle_cb = 0x7f72db8de9cc]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: stats_cb = 0x7f72db8dea91]
24/03/20 15:17:30,511 [Connection/140131041339136] Kafka: (7) [[thrd:app]: log_cb = 0x7f72db8de782]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: opaque = 0x7f72c4118b48]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: default_topic_conf = 0x7f72c4119570]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: security.protocol = sasl_ssl]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: ssl_key = [redacted]]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.mechanisms = OAUTHBEARER]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: oauthbearer_token_refresh_cb = 0x7f72d545eac9]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.method = oidc]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.client.id = our-client-id]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.client.secret = our
clientsecret]24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.scope = our-client-id/.default]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.extensions = identity-pool-id]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: sasl.oauthbearer.token.endpoint.url = https://login.microsoftonline.com/****/oauth2/v2.0/token]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: group.id = our-group-id]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: enable.auto.commit = true]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: fetch.wait.max.ms = 5]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: fetch.min.bytes = 1024]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: Default topic configuration:]
24/03/20 15:17:30,512 [Connection/140131041339136] Kafka: (7) [[thrd:app]: auto.offset.reset = smallest]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id" received op ASSIGN in state query-coord (join-state init)]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: No current assignment to clear]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 0 partition(s):]
24/03/20 15:17:30,513 Last message repeat 3 times.
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": assignment operations done in join-state init (rebalance rejoin=false)]
24/03/20 15:17:30,513 [Connection/140131041339136] Kafka: (7) [[thrd:main]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Selected for cluster connection: coordinator query (broker has 0 connection attempt(s))]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Received CONNECT op]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state INIT -> TRY_CONNECT]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id" received op ASSIGN in state query-coord (join-state init)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": new assignment of 1 partition(s) in join-state init]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: No current assignment to clear]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: New local topic: our.topic]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: NEW our.topic [-1] 0x7f72ac002c40 refcnt 0x7f72ac002cd0 (at rd_kafka_topic_new0:472)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Topic "our.topic" configuration (default_topic_conf):]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: auto.offset.reset = smallest]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: NEW our.topic [0] 0x7f72ac003370 refcnt 0x7f72ac003400 (at rd_kafka_toppar_desired_add:645)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0]: marking as DESIRED]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0]: adding to DESIRED list]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Added 1 partition(s) to assignment which now consists of 1 partition(s) where of 1 are in pending state and 0 are being queried]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 15:17:30,514 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: List with 0 partition(s):]
24/03/20 15:17:30,515 Last message repeat 1 time.
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Pending assignment partition our.topic [0] can't fetch committed offset yet (cgrp state query-coord, awaiting 0 commits, 0 partition(s) already being queried)]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Current assignment of 1 partition(s) with 1 pending adds, 0 offset queries, 0 partitions awaiting stop and 0 offset commits in progress]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 49ms: coordinator query]
24/03/20 15:17:30,515 [Connection/140131041339136] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 15:17:31,515 [Connection/140131041339136] Info: Loop ...
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:background]: Waking up waiting broker threads after setting OAUTHBEARER token]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:background]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Wake-up: OAUTHBEARER token update]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:background]: Wake-up sent to 1 broker thread in state >= TRY_CONNECT: OAUTHBEARER token update]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: broker in state TRY_CONNECT connecting]
24/03/20 15:17:31,515 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state TRY_CONNECT -> CONNECT]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Connecting to ipv4#20.31.55.65:9092 (sasl_ssl) with socket 7]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Connected to ipv4#20.31.55.65:9092]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state CONNECT -> SSL_HANDSHAKE]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Enabled endpoint identification using hostname pkc-99999.westeurope.azure.confluent.cloud]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker SSL certificate verified]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Connected (#1)]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Updated enabled protocol features +ApiVersion to ApiVersion]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state SSL_HANDSHAKE -> APIVERSION_QUERY]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Sent ApiVersionRequest (v3, 63 bytes @ 0, CorrId 1)]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Received ApiVersionResponse (v3, 725 bytes, CorrId 1, rtt 1.73ms)]
24/03/20 15:17:31,516 [Connection/140131041339136] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker API support:]
...
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey DescribeTransactions (65) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey ListTransactions (66) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey AllocateProducerIds (67) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-68? (68) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-69? (69) Versions 0..0]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-10000? (10000) Versions 0..4]
24/03/20 14:21:28,932 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: ApiKey Unknown-10001? (10001) Versions 0..1]
...
24/03/20 14:21:33,044 [Connection/139785840895744] Info: Loop ...
24/03/20 14:21:33,044 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Cluster connection already in progress: coordinator query]
24/03/20 14:21:33,044 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
24/03/20 14:21:33,044 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 49ms: coordinator query]
...
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Topic our.topic [0]: stored offset INVALID (leader epoch -1), committed offset INVALID (leader epoch -1): not including in commit]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Assignment dump (started_cnt=0, wait_stop_cnt=0)]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: List with 1 partition(s):]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: our.topic [0] offset STORED]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: List with 0 partition(s):]
24/03/20 14:21:33,064 Last message repeat 1 time.
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Pending assignment our.topic [0] can't fetch committed offset yet (cgrp state query-coord, awaiting 0 commits, 0 partition(s) already being queried)]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Current assignment of 1 partition(s) with 1 pending adds, 0 offset queries, 0 partitions awaiting stop and 0 offset commits in progress]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 41ms: coordinator query]
24/03/20 14:21:33,064 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Group "our-group-id": no broker available for coordinator query: intervaled in state query-coord]
...
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Topic our.topic metadata information unknown]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Topic our.topic partition count is zero: should refresh metadata]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 41ms: refresh unavailable topics]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Hinted cache of 1/1 topic(s) being queried]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Skipping metadata refresh of 1 topic(s): refresh unavailable topics: no usable brokers]
24/03/20 14:21:33,071 [Connection/139785840895744] Kafka: (7) [[thrd:main]: Not selecting any broker for cluster connection: still suppressed for 41ms: no cluster connection]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (5) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Timed out SaslAuthenticateRequest in flight (after 5003ms, timeout #0)]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: SASL authentication error: SaslAuthenticateRequest failed: Local: Timed out (after 5003ms in state AUTH_REQ) (_TIMED_OUT)]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (3) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: SASL authentication error: SaslAuthenticateRequest failed: Local: Timed out (after 5003ms in state AUTH_REQ)]
24/03/20 14:21:34,071 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state AUTH_REQ -> DOWN]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Purging bufq with 0 buffers]
24/03/20 14:21:34,072 Last message repeat 1 time.
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Updating 0 buffers on connection reset]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Cluster connection already in progress: broker down]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Hinted cache of 1/1 topic(s) being queried]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Skipping metadata refresh of 1 topic(s): broker down: no usable brokers]
24/03/20 14:21:34,072 [Connection/139785840895744] Error: Kafka error sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: SASL authentication error: SaslAuthenticateRequest failed: Local: Timed out (after 5003ms in state AUTH_REQ)
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (4) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Timed out 1 in-flight, 0 retry-queued, 0 out-queue, 0 partially-sent requests]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Broker changed state DOWN -> INIT]
24/03/20 14:21:34,072 [Connection/139785840895744] Error: Kafka error 1/1 brokers are down
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/boot]: Broadcasting state change]
24/03/20 14:21:34,072 [Connection/139785840895744] Kafka: (7) [[thrd:main]: sasl_ssl://pkc-99999.westeurope.azure.confluent.cloud:9092/bootstrap: Selected for cluster connection: coordinator query (broker has 1 connection attempt(s))]
The text was updated successfully, but these errors were encountered: