Closed bahtiyarsharipov closed 3 weeks ago
Мы используем 2.7.3 кафку, в котором еще зукипер работает. Такой проблемы не наблюдаем. Причин может много - какой размер сообщения используется? Синхронная или асинхронная отправка - если синхронная - то в сколько потоков отправляются сообщения. Включены ли логи? Если включены - то можно посмотреть что пишется туда. Дополнительно можно установить параметр debug, чтобы собирать расширенные логи. Так же можно в логи самой кафки заглянуть, обычно там тоже можно накапать что нибудь.
Кафка стоит 3.6.0. Запускаю на win10 с помощью wsl2(ubuntu). В консоли все работает. Размер сообщения минимальный - просто "Hi". С логами проблема - Устанавливаю директорию "C:\1С" - ничего не пишет - права есть у всех на все. Ставлю директорию ubuntu (может думаю передает логи на сервер кафки - тоже пусто -/home/kafka/logs/1C -права тоже есть. Отправляю асинхронно. поток 1. Включил дебаг в кафке.
[2023-12-01 13:25:13,486] INFO Reading configuration from: config/zookeeper.properties (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,488] WARN config/zookeeper.properties is relative. Prepend ./ to indicate that you're sure! (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,491] INFO clientPortAddress is 0.0.0.0:2181 (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,491] INFO secureClientPort is not set (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,491] INFO observerMasterPort is not set (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,491] INFO metricsProvider.className is org.apache.zookeeper.metrics.impl.DefaultMetricsProvider (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,494] INFO autopurge.snapRetainCount set to 3 (org.apache.zookeeper.server.DatadirCleanupManager)
[2023-12-01 13:25:13,494] INFO autopurge.purgeInterval set to 0 (org.apache.zookeeper.server.DatadirCleanupManager)
[2023-12-01 13:25:13,494] INFO Purge task is not scheduled. (org.apache.zookeeper.server.DatadirCleanupManager)
[2023-12-01 13:25:13,494] WARN Either no config or no quorum defined in config, running in standalone mode (org.apache.zookeeper.server.quorum.QuorumPeerMain)
[2023-12-01 13:25:13,495] INFO Log4j 1.2 jmx support not found; jmx disabled. (org.apache.zookeeper.jmx.ManagedUtil)
[2023-12-01 13:25:13,496] INFO Reading configuration from: config/zookeeper.properties (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,496] WARN config/zookeeper.properties is relative. Prepend ./ to indicate that you're sure! (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,496] INFO clientPortAddress is 0.0.0.0:2181 (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,496] INFO secureClientPort is not set (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,496] INFO observerMasterPort is not set (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,496] INFO metricsProvider.className is org.apache.zookeeper.metrics.impl.DefaultMetricsProvider (org.apache.zookeeper.server.quorum.QuorumPeerConfig)
[2023-12-01 13:25:13,497] INFO Starting server (org.apache.zookeeper.server.ZooKeeperServerMain)
[2023-12-01 13:25:13,507] INFO ServerMetrics initialized with provider org.apache.zookeeper.metrics.impl.DefaultMetricsProvider@78047b92 (org.apache.zookeeper.server.ServerMetrics)
[2023-12-01 13:25:13,511] INFO ACL digest algorithm is: SHA1 (org.apache.zookeeper.server.auth.DigestAuthenticationProvider)
[2023-12-01 13:25:13,511] INFO zookeeper.DigestAuthenticationProvider.enabled = true (org.apache.zookeeper.server.auth.DigestAuthenticationProvider)
[2023-12-01 13:25:13,513] DEBUG Opening datadir:/home/kafka/kafka/logs snapDir:/home/kafka/kafka/logs (org.apache.zookeeper.server.persistence.FileTxnSnapLog)
[2023-12-01 13:25:13,514] INFO zookeeper.snapshot.trust.empty : false (org.apache.zookeeper.server.persistence.FileTxnSnapLog)
[2023-12-01 13:25:13,524] INFO (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,524] INFO __ _ (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,524] INFO | / | | (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,524] INFO / / _ | | _ (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,524] INFO / / / \ / \ | |/ / / \ / \ | ' \ / \ | '| (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,525] INFO / / | () | | () | | < | / | / | |_) | | / | | (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,525] INFO /____| \/ _/ ||_\ \| _| | ./ __| || (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,525] INFO | | (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,525] INFO |_| (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,525] INFO (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:zookeeper.version=3.8.2-139d619b58292d7734b4fc83a0f44be4e7b0c986, built on 2023-07-05 19:24 UTC (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:host.name=Bahtiyar. (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:java.version=11.0.21 (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:java.vendor=Ubuntu (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64 (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:java.class.path=/home/kafka/kafka/bin/../libs/activation-1.1.1.jar:/home/kafka/kafka/bin/../libs/aopalliance-repackaged-2.6.1.jar:/home/kafka/kafka/bin/../libs/argparse4j-0.7.0.jar:/home/kafka/kafka/bin/../libs/audience-annotations-0.12.0.jar:/home/kafka/kafka/bin/../libs/caffeine-2.9.3.jar:/home/kafka/kafka/bin/../libs/checker-qual-3.19.0.jar:/home/kafka/kafka/bin/../libs/commons-beanutils-1.9.4.jar:/home/kafka/kafka/bin/../libs/commons-cli-1.4.jar:/home/kafka/kafka/bin/../libs/commons-collections-3.2.2.jar:/home/kafka/kafka/bin/../libs/commons-digester-2.1.jar:/home/kafka/kafka/bin/../libs/commons-io-2.11.0.jar:/home/kafka/kafka/bin/../libs/commons-lang3-3.8.1.jar:/home/kafka/kafka/bin/../libs/commons-logging-1.2.jar:/home/kafka/kafka/bin/../libs/commons-validator-1.7.jar:/home/kafka/kafka/bin/../libs/connect-api-3.6.0.jar:/home/kafka/kafka/bin/../libs/connect-basic-auth-extension-3.6.0.jar:/home/kafka/kafka/bin/../libs/connect-json-3.6.0.jar:/home/kafka/kafka/bin/../libs/connect-mirror-3.6.0.jar:/home/kafka/kafka/bin/../libs/connect-mirror-client-3.6.0.jar:/home/kafka/kafka/bin/../libs/connect-runtime-3.6.0.jar:/home/kafka/kafka/bin/../libs/connect-transforms-3.6.0.jar:/home/kafka/kafka/bin/../libs/error_prone_annotations-2.10.0.jar:/home/kafka/kafka/bin/../libs/hk2-api-2.6.1.jar:/home/kafka/kafka/bin/../libs/hk2-locator-2.6.1.jar:/home/kafka/kafka/bin/../libs/hk2-utils-2.6.1.jar:/home/kafka/kafka/bin/../libs/jackson-annotations-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-core-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-databind-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-dataformat-csv-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-datatype-jdk8-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-jaxrs-base-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-jaxrs-json-provider-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-module-jaxb-annotations-2.13.5.jar:/home/kafka/kafka/bin/../libs/jackson-module-scala_2.13-2.13.5.jar:/home/kafka/kafka/bin/../libs/jakarta.activation-api-1.2.2.jar:/home/kafka/kafka/bin/../libs/jakarta.annotation-api-1.3.5.jar:/home/kafka/kafka/bin/../libs/jakarta.inject-2.6.1.jar:/home/kafka/kafka/bin/../libs/jakarta.validation-api-2.0.2.jar:/home/kafka/kafka/bin/../libs/jakarta.ws.rs-api-2.1.6.jar:/home/kafka/kafka/bin/../libs/jakarta.xml.bind-api-2.3.3.jar:/home/kafka/kafka/bin/../libs/javassist-3.29.2-GA.jar:/home/kafka/kafka/bin/../libs/javax.activation-api-1.2.0.jar:/home/kafka/kafka/bin/../libs/javax.annotation-api-1.3.2.jar:/home/kafka/kafka/bin/../libs/javax.servlet-api-3.1.0.jar:/home/kafka/kafka/bin/../libs/javax.ws.rs-api-2.1.1.jar:/home/kafka/kafka/bin/../libs/jaxb-api-2.3.1.jar:/home/kafka/kafka/bin/../libs/jersey-client-2.39.1.jar:/home/kafka/kafka/bin/../libs/jersey-common-2.39.1.jar:/home/kafka/kafka/bin/../libs/jersey-container-servlet-2.39.1.jar:/home/kafka/kafka/bin/../libs/jersey-container-servlet-core-2.39.1.jar:/home/kafka/kafka/bin/../libs/jersey-hk2-2.39.1.jar:/home/kafka/kafka/bin/../libs/jersey-server-2.39.1.jar:/home/kafka/kafka/bin/../libs/jetty-client-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-continuation-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-http-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-io-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-security-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-server-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-servlet-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-servlets-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-util-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jetty-util-ajax-9.4.52.v20230823.jar:/home/kafka/kafka/bin/../libs/jline-3.22.0.jar:/home/kafka/kafka/bin/../libs/jopt-simple-5.0.4.jar:/home/kafka/kafka/bin/../libs/jose4j-0.9.3.jar:/home/kafka/kafka/bin/../libs/jsr305-3.0.2.jar:/home/kafka/kafka/bin/../libs/kafka-clients-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-group-coordinator-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-log4j-appender-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-metadata-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-raft-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-server-common-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-shell-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-storage-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-storage-api-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-streams-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-streams-examples-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-streams-scala_2.13-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-streams-test-utils-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-tools-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka-tools-api-3.6.0.jar:/home/kafka/kafka/bin/../libs/kafka_2.13-3.6.0.jar:/home/kafka/kafka/bin/../libs/lz4-java-1.8.0.jar:/home/kafka/kafka/bin/../libs/maven-artifact-3.8.8.jar:/home/kafka/kafka/bin/../libs/metrics-core-2.2.0.jar:/home/kafka/kafka/bin/../libs/metrics-core-4.1.12.1.jar:/home/kafka/kafka/bin/../libs/netty-buffer-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-codec-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-common-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-handler-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-resolver-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-transport-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-transport-classes-epoll-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-transport-native-epoll-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/netty-transport-native-unix-common-4.1.94.Final.jar:/home/kafka/kafka/bin/../libs/osgi-resource-locator-1.0.3.jar:/home/kafka/kafka/bin/../libs/paranamer-2.8.jar:/home/kafka/kafka/bin/../libs/pcollections-4.0.1.jar:/home/kafka/kafka/bin/../libs/plexus-utils-3.3.1.jar:/home/kafka/kafka/bin/../libs/reflections-0.10.2.jar:/home/kafka/kafka/bin/../libs/reload4j-1.2.25.jar:/home/kafka/kafka/bin/../libs/rocksdbjni-7.9.2.jar:/home/kafka/kafka/bin/../libs/scala-collection-compat_2.13-2.10.0.jar:/home/kafka/kafka/bin/../libs/scala-java8-compat_2.13-1.0.2.jar:/home/kafka/kafka/bin/../libs/scala-library-2.13.11.jar:/home/kafka/kafka/bin/../libs/scala-logging_2.13-3.9.4.jar:/home/kafka/kafka/bin/../libs/scala-reflect-2.13.11.jar:/home/kafka/kafka/bin/../libs/slf4j-api-1.7.36.jar:/home/kafka/kafka/bin/../libs/slf4j-reload4j-1.7.36.jar:/home/kafka/kafka/bin/../libs/snappy-java-1.1.10.4.jar:/home/kafka/kafka/bin/../libs/swagger-annotations-2.2.8.jar:/home/kafka/kafka/bin/../libs/trogdor-3.6.0.jar:/home/kafka/kafka/bin/../libs/zookeeper-3.8.2.jar:/home/kafka/kafka/bin/../libs/zookeeper-jute-3.8.2.jar:/home/kafka/kafka/bin/../libs/zstd-jni-1.5.5-1.jar (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:java.io.tmpdir=/tmp (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:13,528] INFO Server environment:java.compiler=
[2023-12-01 13:25:40,467] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:40,467] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x12 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,467] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x12 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,467] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,467] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,467] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,469] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics serverPath:/brokers/topics finished:false header:: 18,12 replyHeader:: 18,52,0 request:: '/brokers/topics,F response:: v{'quickstart-events},s{6,6,1701417381667,1701417381667,0,1,0,0,0,1,33} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:40,472] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:40,472] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x13 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/quickstart-events (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,472] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x13 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/quickstart-events (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,472] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,472] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,472] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,472] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/topics/quickstart-events serverPath:/config/topics/quickstart-events finished:false header:: 19,4 replyHeader:: 19,52,0 request:: '/config/topics/quickstart-events,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b7d7d,s{32,32,1701417419760,1701417419760,0,0,0,0,25,0,32} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:40,475] INFO Loading logs from log dirs ArraySeq(/home/kafka/kafka/logs) (kafka.log.LogManager) [2023-12-01 13:25:40,487] INFO Recovering 2 logs from /home/kafka/kafka/logs since no clean shutdown file was found (kafka.log.LogManager) [2023-12-01 13:25:40,489] DEBUG Adding log recovery metrics (kafka.log.LogManager) [2023-12-01 13:25:40,489] DEBUG Loading log /home/kafka/kafka/logs/quickstart-events-0 (kafka.log.LogManager) [2023-12-01 13:25:40,525] INFO [LogLoader partition=quickstart-events-0, dir=/home/kafka/kafka/logs] Recovering unflushed segment 0. 0/1 recovered for quickstart-events-0. (kafka.log.LogLoader) [2023-12-01 13:25:40,526] INFO [LogLoader partition=quickstart-events-0, dir=/home/kafka/kafka/logs] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,526] INFO [LogLoader partition=quickstart-events-0, dir=/home/kafka/kafka/logs] Reloading from producer snapshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,526] INFO [LogLoader partition=quickstart-events-0, dir=/home/kafka/kafka/logs] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,528] DEBUG Loaded index file /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 1310720, lastOffset = 0, file position = 10485760 (org.apache.kafka.storage.internals.log.OffsetIndex) [2023-12-01 13:25:40,528] DEBUG Truncated index /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.index to 0 entries; position is now 0 and last offset is now 0 (org.apache.kafka.storage.internals.log.OffsetIndex) [2023-12-01 13:25:40,528] DEBUG Index /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.index was not resized because it already has size 10485760 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,528] DEBUG Loaded index file /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 873813, lastOffset = 0, file position = 10485756 (org.apache.kafka.storage.internals.log.TimeIndex) [2023-12-01 13:25:40,528] DEBUG Truncated index /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.timeindex to 0 entries; position is now 0 and last entry is now 0 (org.apache.kafka.storage.internals.log.TimeIndex) [2023-12-01 13:25:40,529] DEBUG Index /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.timeindex was not resized because it already has size 10485756 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,539] DEBUG Resized /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.index to 0, position is 0 and limit is 0 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,540] DEBUG Resized /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.timeindex to 12, position is 12 and limit is 12 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,545] INFO [ProducerStateManager partition=quickstart-events-0]Wrote producer snapshot at offset 3 with 1 producer ids in 5 ms. (org.apache.kafka.storage.internals.log.ProducerStateManager) [2023-12-01 13:25:40,547] DEBUG Resized /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.index to 10485760, position is 0 and limit is 10485760 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,547] DEBUG Resized /home/kafka/kafka/logs/quickstart-events-0/00000000000000000000.timeindex to 10485756, position is 12 and limit is 10485756 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,557] DEBUG [LeaderEpochCache quickstart-events-0] Cleared entries [EpochEntry(epoch=0, startOffset=0)] and rewrote first entry EpochEntry(epoch=0, startOffset=0) after truncating to start offset 0, leaving 1 in the cache. (org.apache.kafka.storage.internals.epoch.LeaderEpochFileCache) [2023-12-01 13:25:40,559] INFO [LogLoader partition=quickstart-events-0, dir=/home/kafka/kafka/logs] Loading producer state till offset 3 with message format version 2 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,559] INFO [LogLoader partition=quickstart-events-0, dir=/home/kafka/kafka/logs] Reloading from producer snapshot and rebuilding producer state from offset 3 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,559] INFO [ProducerStateManager partition=quickstart-events-0]Loading producer state from snapshot file 'SnapshotFile(offset=3, file=/home/kafka/kafka/logs/quickstart-events-0/00000000000000000003.snapshot)' (org.apache.kafka.storage.internals.log.ProducerStateManager) [2023-12-01 13:25:40,561] INFO [LogLoader partition=quickstart-events-0, dir=/home/kafka/kafka/logs] Producer state recovery took 1ms for snapshot load and 0ms for segment recovery from offset 3 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,574] DEBUG Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,576] INFO Completed load of Log(dir=/home/kafka/kafka/logs/quickstart-events-0, topicId=ypm-NPoHTkGr1z5l_cVhqw, topic=quickstart-events, partition=0, highWatermark=0, lastStableOffset=0, logStartOffset=0, logEndOffset=3) with 1 segments, local-log-start-offset 0 and log-end-offset 3 in 84ms (1/2 completed in /home/kafka/kafka/logs) (kafka.log.LogManager) [2023-12-01 13:25:40,576] DEBUG Loading log /home/kafka/kafka/logs/version-2 (kafka.log.LogManager) [2023-12-01 13:25:40,577] INFO [LogLoader partition=version-2, dir=/home/kafka/kafka/logs] Recovering unflushed segment 0. 0/1 recovered for version-2. (kafka.log.LogLoader) [2023-12-01 13:25:40,577] INFO [LogLoader partition=version-2, dir=/home/kafka/kafka/logs] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,578] INFO [LogLoader partition=version-2, dir=/home/kafka/kafka/logs] Reloading from producer snapshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,578] INFO [LogLoader partition=version-2, dir=/home/kafka/kafka/logs] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,578] DEBUG Loaded index file /home/kafka/kafka/logs/version-2/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 1310720, lastOffset = 0, file position = 10485760 (org.apache.kafka.storage.internals.log.OffsetIndex) [2023-12-01 13:25:40,578] DEBUG Truncated index /home/kafka/kafka/logs/version-2/00000000000000000000.index to 0 entries; position is now 0 and last offset is now 0 (org.apache.kafka.storage.internals.log.OffsetIndex) [2023-12-01 13:25:40,578] DEBUG Index /home/kafka/kafka/logs/version-2/00000000000000000000.index was not resized because it already has size 10485760 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,578] DEBUG Loaded index file /home/kafka/kafka/logs/version-2/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 873813, lastOffset = 0, file position = 10485756 (org.apache.kafka.storage.internals.log.TimeIndex) [2023-12-01 13:25:40,578] DEBUG Truncated index /home/kafka/kafka/logs/version-2/00000000000000000000.timeindex to 0 entries; position is now 0 and last entry is now 0 (org.apache.kafka.storage.internals.log.TimeIndex) [2023-12-01 13:25:40,578] DEBUG Index /home/kafka/kafka/logs/version-2/00000000000000000000.timeindex was not resized because it already has size 10485756 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,578] DEBUG Resized /home/kafka/kafka/logs/version-2/00000000000000000000.index to 0, position is 0 and limit is 0 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,579] DEBUG Resized /home/kafka/kafka/logs/version-2/00000000000000000000.timeindex to 0, position is 0 and limit is 0 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,579] DEBUG Resized /home/kafka/kafka/logs/version-2/00000000000000000000.index to 10485760, position is 0 and limit is 10485760 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,579] DEBUG Resized /home/kafka/kafka/logs/version-2/00000000000000000000.timeindex to 10485756, position is 0 and limit is 10485756 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:25:40,579] INFO [LogLoader partition=version-2, dir=/home/kafka/kafka/logs] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,579] INFO [LogLoader partition=version-2, dir=/home/kafka/kafka/logs] Reloading from producer snapshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,579] INFO [LogLoader partition=version-2, dir=/home/kafka/kafka/logs] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$) [2023-12-01 13:25:40,580] DEBUG Scheduling task flush-metadata-file with initial delay 0 ms and period -1 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,581] DEBUG Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,582] INFO Completed load of Log(dir=/home/kafka/kafka/logs/version-2, topic=version, partition=2, highWatermark=0, lastStableOffset=0, logStartOffset=0, logEndOffset=0) with 1 segments, local-log-start-offset 0 and log-end-offset 0 in 6ms (2/2 completed in /home/kafka/kafka/logs) (kafka.log.LogManager) [2023-12-01 13:25:40,583] DEBUG Removing log recovery metrics (kafka.log.LogManager) [2023-12-01 13:25:40,586] INFO Loaded 2 logs in 110ms (unclean log dirs = ArrayBuffer(/home/kafka/kafka/logs)) (kafka.log.LogManager) [2023-12-01 13:25:40,587] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager) [2023-12-01 13:25:40,587] DEBUG Scheduling task kafka-log-retention with initial delay 30000 ms and period 300000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,588] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager) [2023-12-01 13:25:40,588] DEBUG Scheduling task kafka-log-flusher with initial delay 30000 ms and period 9223372036854775807 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,588] DEBUG Scheduling task kafka-recovery-point-checkpoint with initial delay 30000 ms and period 60000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,589] DEBUG Scheduling task kafka-log-start-offset-checkpoint with initial delay 30000 ms and period 60000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,589] DEBUG Scheduling task kafka-delete-logs with initial delay 30000 ms and period -1 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,598] INFO Starting the log cleaner (kafka.log.LogCleaner)
[2023-12-01 13:25:40,654] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:40,654] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x14 zxid:0xfffffffffffffffe txntype:unknown reqpath:/feature (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,654] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x14 zxid:0xfffffffffffffffe txntype:unknown reqpath:/feature (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,656] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/feature serverPath:/feature finished:false header:: 20,3 replyHeader:: 20,52,0 request:: '/feature,T response:: s{28,28,1701417382578,1701417382578,0,0,0,0,38,0,28} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:40,658] DEBUG Reading feature ZK node at path: /feature (kafka.server.FinalizedFeatureChangeListener) [2023-12-01 13:25:40,660] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:40,660] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:/feature (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,660] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:/feature (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,660] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,660] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,660] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,661] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/feature serverPath:/feature finished:false header:: 21,4 replyHeader:: 21,52,0 request:: '/feature,T response:: #7b226665617475726573223a7b7d2c2276657273696f6e223a322c22737461747573223a317d,s{28,28,1701417382578,1701417382578,0,0,0,0,38,0,28} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:40,669] INFO [MetadataCache brokerId=0] Updated cache from existing None to latest Features(version=3.6-IV2, finalizedFeatures={}, finalizedFeaturesEpoch=0). (kafka.server.metadata.ZkMetadataCache)
[2023-12-01 13:25:40,694] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,695] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,797] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,797] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,897] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,898] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,920] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas) [2023-12-01 13:25:40,934] INFO [SocketServer listenerType=ZK_BROKER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(PLAINTEXT) (kafka.network.SocketServer)
[2023-12-01 13:25:40,939] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,940] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread)
[2023-12-01 13:25:40,970] DEBUG Scheduling task isr-expiration with initial delay 0 ms and period 15000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:40,970] DEBUG Scheduling task shutdown-idle-replica-alter-log-dirs-thread with initial delay 0 ms and period 10000 ms. (org.apache.kafka.server.util.KafkaScheduler)
[2023-12-01 13:25:40,973] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:40,973] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x16 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,974] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x16 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:40,974] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,974] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,974] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:40,974] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/ids serverPath:/brokers/ids finished:false header:: 22,12 replyHeader:: 22,52,0 request:: '/brokers/ids,F response:: v{},s{5,5,1701417381662,1701417381662,0,2,0,0,0,0,37} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:40,998] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:40,998] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,002] INFO Creating /brokers/ids/0 (is it secure? false) (kafka.zk.KafkaZkClient) [2023-12-01 13:25:41,013] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,014] DEBUG Processing ACL: 31,s{'world,'anyone} (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,014] DEBUG Permission requested: 4 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,014] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,014] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,014] DEBUG Digest got from data tree is: 65083339351 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,014] DEBUG Digest got from outstandingChanges is: 65697161732 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,014] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,014] DEBUG Permission requested: 2 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,014] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,014] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,014] DEBUG Digest got from outstandingChanges is: 66156644477 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,014] DEBUG Digest got from outstandingChanges is: 69297183020 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,016] DEBUG Processing request:: sessionid:0x1000002184f0000 type:multi cxid:0x17 zxid:0x35 txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,016] DEBUG brokers (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:25:41,017] DEBUG brokers (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:25:41,017] DEBUG Digests are matching for Zxid: 35, Digest in log and actual tree: 69297183020 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:25:41,017] DEBUG sessionid:0x1000002184f0000 type:multi cxid:0x17 zxid:0x35 txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,019] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:null serverPath:null finished:false header:: 23,14 replyHeader:: 23,53,0 request:: org.apache.zookeeper.MultiOperationRecord@87070fa3 response:: org.apache.zookeeper.MultiResponse@1dbbce7e (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,021] INFO Stat of the created znode at /brokers/ids/0 is: 53,53,1701419141013,1701419141013,1,0,0,72057603035693056,202,0,53 (kafka.zk.KafkaZkClient) [2023-12-01 13:25:41,022] INFO Registered broker 0 at path /brokers/ids/0 with addresses: PLAINTEXT://Bahtiyar.:9092, czxid (broker epoch): 53 (kafka.zk.KafkaZkClient) [2023-12-01 13:25:41,040] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,040] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,071] INFO [ControllerEventThread controllerId=0] Starting (kafka.controller.ControllerEventManager$ControllerEventThread)
[2023-12-01 13:25:41,078] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,078] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x18 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,078] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x18 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,079] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/controller serverPath:/controller finished:false header:: 24,3 replyHeader:: 24,53,-101 request:: '/controller,T response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,080] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,081] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x19 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,081] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x19 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,081] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/controller serverPath:/controller finished:false header:: 25,4 replyHeader:: 25,53,-101 request:: '/controller,T response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,083] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,083] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller_epoch (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,083] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x1a zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller_epoch (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,084] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,084] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,084] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,084] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/controller_epoch serverPath:/controller_epoch finished:false header:: 26,4 replyHeader:: 26,53,0 request:: '/controller_epoch,F response:: #31,s{26,27,1701417382559,1701417382566,1,0,0,0,1,0,26} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,085] DEBUG Try to create /controller and increment controller epoch to 2 with expected controller epoch zkVersion 1 (kafka.zk.KafkaZkClient) [2023-12-01 13:25:41,088] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,088] DEBUG Processing ACL: 31,s{'world,'anyone} (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,088] DEBUG Permission requested: 4 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,088] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,088] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,088] DEBUG Digest got from data tree is: 69297183020 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,088] DEBUG Digest got from outstandingChanges is: 68276778671 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,088] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,089] DEBUG Permission requested: 2 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,089] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,089] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,089] DEBUG Digest got from outstandingChanges is: 71093744464 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,089] DEBUG Digest got from outstandingChanges is: 70591705581 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,090] DEBUG Processing request:: sessionid:0x1000002184f0000 type:multi cxid:0x1b zxid:0x36 txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,091] DEBUG controller (org.apache.zookeeper.common.PathTrie)
[2023-12-01 13:25:41,092] DEBUG Got notification session id: 0x1000002184f0000 (org.apache.zookeeper.ClientCnxn)
[2023-12-01 13:25:41,093] DEBUG controller_epoch (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:25:41,093] DEBUG Digests are matching for Zxid: 36, Digest in log and actual tree: 70591705581 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:25:41,093] DEBUG sessionid:0x1000002184f0000 type:multi cxid:0x1b zxid:0x36 txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,093] DEBUG Got WatchedEvent state:SyncConnected type:NodeCreated path:/controller for session id 0x1000002184f0000 (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,094] DEBUG [ZooKeeperClient Kafka server] Received event: WatchedEvent state:SyncConnected type:NodeCreated path:/controller (kafka.zookeeper.ZooKeeperClient) [2023-12-01 13:25:41,094] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:null serverPath:null finished:false header:: 27,14 replyHeader:: 27,54,0 request:: org.apache.zookeeper.MultiOperationRecord@8d7fae96 response:: org.apache.zookeeper.MultiResponse@f3584fc1 (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,095] INFO [Controller id=0] 0 successfully elected as the controller. Epoch incremented to 2 and epoch zk version is now 2 (kafka.controller.KafkaController) [2023-12-01 13:25:41,096] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,096] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:/feature (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,096] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x1c zxid:0xfffffffffffffffe txntype:unknown reqpath:/feature (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,096] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,096] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,096] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,097] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/feature serverPath:/feature finished:false header:: 28,4 replyHeader:: 28,54,0 request:: '/feature,T response:: #7b226665617475726573223a7b7d2c2276657273696f6e223a322c22737461747573223a317d,s{28,28,1701417382578,1701417382578,0,0,0,0,38,0,28} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,098] INFO [Controller id=0] Registering handlers (kafka.controller.KafkaController) [2023-12-01 13:25:41,099] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,099] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,100] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,100] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/preferred_replica_election (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,100] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x1d zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/preferred_replica_election (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,101] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/admin/preferred_replica_election serverPath:/admin/preferred_replica_election finished:false header:: 29,3 replyHeader:: 29,54,-101 request:: '/admin/preferred_replica_election,T response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,102] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,102] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x1e zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/reassign_partitions (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,102] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x1e zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/reassign_partitions (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,103] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/admin/reassign_partitions serverPath:/admin/reassign_partitions finished:false header:: 30,3 replyHeader:: 30,54,-101 request:: '/admin/reassign_partitions,T response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,104] INFO [Controller id=0] Deleting log dir event notifications (kafka.controller.KafkaController) [2023-12-01 13:25:41,105] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,105] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x1f zxid:0xfffffffffffffffe txntype:unknown reqpath:/log_dir_event_notification (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,105] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x1f zxid:0xfffffffffffffffe txntype:unknown reqpath:/log_dir_event_notification (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,105] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,105] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,105] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,106] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/log_dir_event_notification serverPath:/log_dir_event_notification finished:false header:: 31,12 replyHeader:: 31,54,0 request:: '/log_dir_event_notification,T response:: v{},s{16,16,1701417381710,1701417381710,0,0,0,0,0,0,16} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,108] INFO [Controller id=0] Deleting isr change notifications (kafka.controller.KafkaController) [2023-12-01 13:25:41,108] INFO [GroupCoordinator 0]: Starting up. (kafka.coordinator.group.GroupCoordinator) [2023-12-01 13:25:41,109] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,109] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x20 zxid:0xfffffffffffffffe txntype:unknown reqpath:/isr_change_notification (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,109] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x20 zxid:0xfffffffffffffffe txntype:unknown reqpath:/isr_change_notification (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,109] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,109] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,109] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,110] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,110] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x21 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/consumer_offsets (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,110] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x21 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/__consumer_offsets (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,110] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/isr_change_notification serverPath:/isr_change_notification finished:false header:: 32,12 replyHeader:: 32,54,0 request:: '/isr_change_notification,T response:: v{},s{14,14,1701417381702,1701417381702,0,0,0,0,0,0,14} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,111] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics/consumer_offsets serverPath:/brokers/topics/consumer_offsets finished:false header:: 33,4 replyHeader:: 33,54,-101 request:: '/brokers/topics/__consumer_offsets,F response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,112] INFO [Controller id=0] Initializing controller context (kafka.controller.KafkaController) [2023-12-01 13:25:41,112] DEBUG Initializing task scheduler. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,112] DEBUG Scheduling task delete-expired-group-metadata with initial delay 0 ms and period 600000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,113] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,113] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x22 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,113] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x22 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,113] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,113] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,113] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,113] INFO [GroupCoordinator 0]: Startup complete. (kafka.coordinator.group.GroupCoordinator) [2023-12-01 13:25:41,114] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/ids serverPath:/brokers/ids finished:false header:: 34,12 replyHeader:: 34,54,0 request:: '/brokers/ids,T response:: v{'0},s{5,5,1701417381662,1701417381662,0,3,0,0,0,1,53} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,116] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,116] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x23 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids/0 (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,116] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x23 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids/0 (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,116] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,116] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,117] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,117] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/ids/0 serverPath:/brokers/ids/0 finished:false header:: 35,4 replyHeader:: 35,54,0 request:: '/brokers/ids/0,F response:: #7b226665617475726573223a7b7d2c226c697374656e65725f73656375726974795f70726f746f636f6c5f6d6170223a7b22504c41494e54455854223a22504c41494e54455854227d2c22656e64706f696e7473223a5b22504c41494e544558543a2f2f42616874697961722e3a39303932225d2c226a6d785f706f7274223a2d312c22706f7274223a393039322c22686f7374223a2242616874697961722e222c2276657273696f6e223a352c2274696d657374616d70223a2231373031343139313430393739227d,s{53,53,1701419141013,1701419141013,1,0,0,72057603035693056,202,0,53} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,128] INFO [Controller id=0] Initialized broker epochs cache: HashMap(0 -> 53) (kafka.controller.KafkaController) [2023-12-01 13:25:41,129] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,129] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x24 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,129] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x24 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,130] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,130] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,130] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,130] INFO [TransactionCoordinator id=0] Starting up. (kafka.coordinator.transaction.TransactionCoordinator) [2023-12-01 13:25:41,131] DEBUG Initializing task scheduler. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,131] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics serverPath:/brokers/topics finished:false header:: 36,12 replyHeader:: 36,54,0 request:: '/brokers/topics,T response:: v{'quickstart-events},s{6,6,1701417381667,1701417381667,0,1,0,0,0,1,33} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,131] DEBUG Scheduling task transaction-abort with initial delay 10000 ms and period 10000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,133] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,133] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x25 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/transaction_state (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,133] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x25 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/transaction_state (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,134] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics/__transaction_state serverPath:/brokers/topics/transaction_state finished:false header:: 37,4 replyHeader:: 37,54,-101 request:: '/brokers/topics/__transaction_state,F response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,134] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,134] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x26 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/quickstart-events (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,134] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x26 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/quickstart-events (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,134] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,134] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,134] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,135] DEBUG Scheduling task transactionalId-expiration with initial delay 3600000 ms and period 3600000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,135] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics/quickstart-events serverPath:/brokers/topics/quickstart-events finished:false header:: 38,4 replyHeader:: 38,54,0 request:: '/brokers/topics/quickstart-events,T response:: #7b22706172746974696f6e73223a7b2230223a5b305d7d2c22746f7069635f6964223a2279706d2d4e506f48546b4772317a356c5f6356687177222c22616464696e675f7265706c69636173223a7b7d2c2272656d6f76696e675f7265706c69636173223a7b7d2c2276657273696f6e223a337d,s{33,33,1701417419766,1701417419766,0,1,0,0,116,1,34} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,135] INFO [TransactionCoordinator id=0] Startup complete. (kafka.coordinator.transaction.TransactionCoordinator)
[2023-12-01 13:25:41,144] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,144] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,148] DEBUG [Controller id=0] Register BrokerModifications handler for Set(0) (kafka.controller.KafkaController) [2023-12-01 13:25:41,153] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,153] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x27 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids/0 (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,153] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x27 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/ids/0 (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,157] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/ids/0 serverPath:/brokers/ids/0 finished:false header:: 39,3 replyHeader:: 39,54,0 request:: '/brokers/ids/0,T response:: s{53,53,1701419141013,1701419141013,1,0,0,72057603035693056,202,0,53} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,162] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,162] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x28 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/quickstart-events/partitions/0/state (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,162] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x28 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/quickstart-events/partitions/0/state (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,162] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,162] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,162] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,163] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics/quickstart-events/partitions/0/state serverPath:/brokers/topics/quickstart-events/partitions/0/state finished:false header:: 40,4 replyHeader:: 40,54,0 request:: '/brokers/topics/quickstart-events/partitions/0/state,F response:: #7b22636f6e74726f6c6c65725f65706f6368223a312c226c6561646572223a302c2276657273696f6e223a312c226c65616465725f65706f6368223a302c22697372223a5b305d7d,s{36,36,1701417419801,1701417419801,0,0,0,0,72,0,36} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,167] DEBUG [Channel manager on controller 0]: Controller 0 trying to connect to broker 0 (kafka.controller.ControllerChannelManager) [2023-12-01 13:25:41,173] INFO [RequestSendThread controllerId=0] Starting (kafka.controller.RequestSendThread) [2023-12-01 13:25:41,176] INFO [Controller id=0] Currently active brokers in the cluster: Set(0) (kafka.controller.KafkaController) [2023-12-01 13:25:41,176] INFO [Controller id=0] Currently shutting brokers in the cluster: HashSet() (kafka.controller.KafkaController) [2023-12-01 13:25:41,176] INFO [Controller id=0] Current list of topics in the cluster: HashSet(quickstart-events) (kafka.controller.KafkaController) [2023-12-01 13:25:41,177] INFO [Controller id=0] Fetching topic deletions in progress (kafka.controller.KafkaController) [2023-12-01 13:25:41,178] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,178] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x29 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/delete_topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,178] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x29 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/delete_topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,178] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,178] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,178] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer)
[2023-12-01 13:25:41,179] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/admin/delete_topics serverPath:/admin/delete_topics finished:false header:: 41,12 replyHeader:: 41,54,0 request:: '/admin/delete_topics,T response:: v{},s{12,12,1701417381694,1701417381694,0,0,0,0,0,0,12} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,182] INFO [Controller id=0] List of topics to be deleted: (kafka.controller.KafkaController) [2023-12-01 13:25:41,182] INFO [Controller id=0] List of topics ineligible for deletion: (kafka.controller.KafkaController) [2023-12-01 13:25:41,182] INFO [Controller id=0] Initializing topic deletion manager (kafka.controller.KafkaController) [2023-12-01 13:25:41,183] INFO [Topic Deletion Manager 0] Initializing manager with initial deletions: Set(), initial ineligible deletions: HashSet() (kafka.controller.TopicDeletionManager) [2023-12-01 13:25:41,184] INFO [Controller id=0] Sending update metadata request (kafka.controller.KafkaController) [2023-12-01 13:25:41,186] INFO [Controller id=0 epoch=2] Sending UpdateMetadata request to brokers HashSet(0) for 0 partitions (state.change.logger) [2023-12-01 13:25:41,194] INFO [ReplicaStateMachine controllerId=0] Initializing replica state (kafka.controller.ZkReplicaStateMachine) [2023-12-01 13:25:41,196] DEBUG Resolved host Bahtiyar. as 127.0.1.1 (org.apache.kafka.clients.ClientUtils) [2023-12-01 13:25:41,196] DEBUG [Controller id=0, targetBrokerId=0] Initiating connection to node Bahtiyar.:9092 (id: 0 rack: null) using address Bahtiyar./127.0.1.1 (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,197] INFO [ReplicaStateMachine controllerId=0] Triggering online replica state changes (kafka.controller.ZkReplicaStateMachine) [2023-12-01 13:25:41,199] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,199] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,202] DEBUG [Controller id=0, targetBrokerId=0] Connection with Bahtiyar./127.0.1.1 (channelId=0) disconnected (org.apache.kafka.common.network.Selector) java.net.ConnectException: Connection refused at java.base/sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:777) at org.apache.kafka.common.network.PlaintextTransportLayer.finishConnect(PlaintextTransportLayer.java:50) at org.apache.kafka.common.network.KafkaChannel.finishConnect(KafkaChannel.java:224) at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:526) at org.apache.kafka.common.network.Selector.poll(Selector.java:481) at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:571) at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73) at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:298) at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:251) at org.apache.kafka.server.util.ShutdownableThread.run(ShutdownableThread.java:130)
[2023-12-01 13:25:41,206] INFO [Controller id=0, targetBrokerId=0] Node 0 disconnected. (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,206] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,207] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,207] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2a zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,207] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2a zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,207] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,207] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,207] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,207] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2b zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/changes (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,207] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2b zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/changes (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,207] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,207] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,207] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,208] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/topics serverPath:/config/topics finished:false header:: 42,12 replyHeader:: 42,54,0 request:: '/config/topics,F response:: v{'quickstart-events},s{17,17,1701417381714,1701417381714,0,1,0,0,0,1,32} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,208] WARN [Controller id=0, targetBrokerId=0] Connection to node 0 (Bahtiyar./127.0.1.1:9092) could not be established. Broker may not be available. (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,208] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/changes serverPath:/config/changes finished:false header:: 43,12 replyHeader:: 43,54,0 request:: '/config/changes,T response:: v{},s{9,9,1701417381680,1701417381680,0,0,0,0,0,0,9} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,209] WARN [RequestSendThread controllerId=0] Controller 0's connection to broker Bahtiyar.:9092 (id: 0 rack: null) was unsuccessful (kafka.controller.RequestSendThread) java.io.IOException: Connection to Bahtiyar.:9092 (id: 0 rack: null) failed. at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:70) at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:298) at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:251) at org.apache.kafka.server.util.ShutdownableThread.run(ShutdownableThread.java:130) [2023-12-01 13:25:41,210] INFO [Controller id=0, targetBrokerId=0] Client requested connection close from node 0 (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,210] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,210] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x2c zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/quickstart-events (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,210] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x2c zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/quickstart-events (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,210] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,210] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,210] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,211] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/topics/quickstart-events serverPath:/config/topics/quickstart-events finished:false header:: 44,4 replyHeader:: 44,54,0 request:: '/config/topics/quickstart-events,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b7d7d,s{32,32,1701417419760,1701417419760,0,0,0,0,25,0,32} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,213] INFO [Controller id=0 epoch=2] Sending LeaderAndIsr request to broker 0 with 1 become-leader and 0 become-follower partitions (state.change.logger) [2023-12-01 13:25:41,216] DEBUG Removing leader.replication.throttled.replicas from broker 0 for topic quickstart-events (kafka.server.TopicConfigHandler) [2023-12-01 13:25:41,216] DEBUG Removing follower.replication.throttled.replicas from broker 0 for topic quickstart-events (kafka.server.TopicConfigHandler) [2023-12-01 13:25:41,216] INFO [Controller id=0 epoch=2] Sending UpdateMetadata request to brokers HashSet(0) for 1 partitions (state.change.logger) [2023-12-01 13:25:41,217] INFO [ReplicaStateMachine controllerId=0] Triggering offline replica state changes (kafka.controller.ZkReplicaStateMachine) [2023-12-01 13:25:41,217] DEBUG [ReplicaStateMachine controllerId=0] Started replica state machine with initial state -> HashMap([Topic=quickstart-events,Partition=0,Replica=0] -> OnlineReplica) (kafka.controller.ZkReplicaStateMachine) [2023-12-01 13:25:41,218] INFO [PartitionStateMachine controllerId=0] Initializing partition state (kafka.controller.ZkPartitionStateMachine) [2023-12-01 13:25:41,219] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,219] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2d zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/clients (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,219] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2d zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/clients (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,219] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,219] INFO [PartitionStateMachine controllerId=0] Triggering online partition state changes (kafka.controller.ZkPartitionStateMachine) [2023-12-01 13:25:41,219] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,219] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,220] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/clients serverPath:/config/clients finished:false header:: 45,12 replyHeader:: 45,54,0 request:: '/config/clients,F response:: v{},s{18,18,1701417381718,1701417381718,0,0,0,0,0,0,18} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,220] DEBUG [PartitionStateMachine controllerId=0] Started partition state machine with initial state -> HashMap(quickstart-events-0 -> OnlinePartition) (kafka.controller.ZkPartitionStateMachine) [2023-12-01 13:25:41,221] INFO [Controller id=0] Ready to serve as the new controller with epoch 2 (kafka.controller.KafkaController) [2023-12-01 13:25:41,222] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,222] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x2e zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/reassign_partitions (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,222] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x2e zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/reassign_partitions (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,222] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,222] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2f zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/users (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,222] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x2f zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/users (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,222] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,222] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,222] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,223] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/admin/reassign_partitions serverPath:/admin/reassign_partitions finished:false header:: 46,3 replyHeader:: 46,54,-101 request:: '/admin/reassign_partitions,T response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,223] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/users serverPath:/config/users finished:false header:: 47,12 replyHeader:: 47,54,0 request:: '/config/users,F response:: v{},s{19,19,1701417381722,1701417381722,0,0,0,0,0,0,19} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,224] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,225] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x30 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/users (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,225] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,225] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x30 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/users (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,225] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,225] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,225] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,225] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x31 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/preferred_replica_election (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,225] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x31 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/preferred_replica_election (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,226] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/users serverPath:/config/users finished:false header:: 48,12 replyHeader:: 48,54,0 request:: '/config/users,F response:: v{},s{19,19,1701417381722,1701417381722,0,0,0,0,0,0,19} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,226] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/admin/preferred_replica_election serverPath:/admin/preferred_replica_election finished:false header:: 49,4 replyHeader:: 49,54,-101 request:: '/admin/preferred_replica_election,T response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,227] INFO [Controller id=0] Partitions undergoing preferred replica election: (kafka.controller.KafkaController) [2023-12-01 13:25:41,228] INFO [Controller id=0] Partitions that completed preferred replica election: (kafka.controller.KafkaController) [2023-12-01 13:25:41,228] INFO [Controller id=0] Skipping preferred replica election for partitions due to topic deletion: (kafka.controller.KafkaController) [2023-12-01 13:25:41,228] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,228] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x32 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/ips (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,228] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x32 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/ips (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,228] INFO [Controller id=0] Resuming preferred replica election for partitions: (kafka.controller.KafkaController) [2023-12-01 13:25:41,228] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,229] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,229] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,229] INFO [Controller id=0] Starting replica leader election (PREFERRED) for partitions triggered by ZkTriggered (kafka.controller.KafkaController) [2023-12-01 13:25:41,229] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/ips serverPath:/config/ips finished:false header:: 50,12 replyHeader:: 50,54,0 request:: '/config/ips,F response:: v{},s{21,21,1701417381729,1701417381729,0,0,0,0,0,0,21} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,231] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,231] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x33 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/brokers (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,231] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x33 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/brokers (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,231] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,231] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,231] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,232] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/brokers serverPath:/config/brokers finished:false header:: 51,12 replyHeader:: 51,54,0 request:: '/config/brokers,F response:: v{},s{20,20,1701417381725,1701417381725,0,0,0,0,0,0,20} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,233] INFO [SocketServer listenerType=ZK_BROKER, nodeId=0] Enabling request processing. (kafka.network.SocketServer) [2023-12-01 13:25:41,233] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,233] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,234] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,234] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,234] DEBUG Digest got from data tree is: 70591705581 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,234] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,234] DEBUG Permission requested: 8 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,234] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,234] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,234] DEBUG Digest got from data tree is: 70591705581 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:25:41,236] DEBUG Processing request:: sessionid:0x1000002184f0000 type:multi cxid:0x34 zxid:0x37 txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,236] DEBUG Ignoring processTxn failure hdr: -1 : error: -101 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:25:41,236] DEBUG Ignoring processTxn failure hdr: 14 : error: -101 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:25:41,236] DEBUG Digests are matching for Zxid: 37, Digest in log and actual tree: 70591705581 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:25:41,236] DEBUG sessionid:0x1000002184f0000 type:multi cxid:0x34 zxid:0x37 txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,236] INFO Awaiting socket connections on 0.0.0.0:9092. (kafka.network.DataPlaneAcceptor) [2023-12-01 13:25:41,236] DEBUG Opened endpoint null:9092 (kafka.network.DataPlaneAcceptor) [2023-12-01 13:25:41,237] DEBUG Starting processors for listener ListenerName(PLAINTEXT) (kafka.network.DataPlaneAcceptor) [2023-12-01 13:25:41,238] DEBUG Starting acceptor thread for listener ListenerName(PLAINTEXT) (kafka.network.DataPlaneAcceptor) [2023-12-01 13:25:41,239] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:null serverPath:null finished:false header:: 52,14 replyHeader:: 52,55,0 request:: org.apache.zookeeper.MultiOperationRecord@22801201 response:: org.apache.zookeeper.MultiResponse@441 (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,241] INFO [Controller id=0] Starting the controller scheduler (kafka.controller.KafkaController) [2023-12-01 13:25:41,241] DEBUG Initializing task scheduler. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,241] DEBUG Scheduling task auto-leader-rebalance-task with initial delay 5000 ms and period -1 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,244] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,244] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,245] INFO Kafka version: 3.6.0 (org.apache.kafka.common.utils.AppInfoParser) [2023-12-01 13:25:41,245] INFO Kafka commitId: 60e845626d8a465a (org.apache.kafka.common.utils.AppInfoParser) [2023-12-01 13:25:41,245] INFO Kafka startTimeMs: 1701419141239 (org.apache.kafka.common.utils.AppInfoParser) [2023-12-01 13:25:41,246] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,246] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x35 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,246] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x35 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,247] INFO [KafkaServer id=0] started (kafka.server.KafkaServer) [2023-12-01 13:25:41,247] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/controller serverPath:/controller finished:false header:: 53,3 replyHeader:: 53,55,0 request:: '/controller,T response:: s{54,54,1701419141088,1701419141088,0,0,0,72057603035693056,80,0,54} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,248] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,248] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x36 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,248] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x36 zxid:0xfffffffffffffffe txntype:unknown reqpath:/controller (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,248] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,248] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,248] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:25:41,249] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/controller serverPath:/controller finished:false header:: 54,4 replyHeader:: 54,55,0 request:: '/controller,T response:: #7b2276657273696f6e223a322c2262726f6b65726964223a302c2274696d657374616d70223a2231373031343139313431303832222c226b72616674436f6e74726f6c6c657245706f6368223a2d317d,s{54,54,1701419141088,1701419141088,0,0,0,72057603035693056,80,0,54} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,251] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:41,251] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x37 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/preferred_replica_election (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,251] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x37 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/preferred_replica_election (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:41,252] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/admin/preferred_replica_election serverPath:/admin/preferred_replica_election finished:false header:: 55,3 replyHeader:: 55,55,-101 request:: '/admin/preferred_replica_election,T response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:41,300] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,300] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,310] DEBUG Resolved host Bahtiyar. as 127.0.1.1 (org.apache.kafka.clients.ClientUtils) [2023-12-01 13:25:41,310] DEBUG [Controller id=0, targetBrokerId=0] Initiating connection to node Bahtiyar.:9092 (id: 0 rack: null) using address Bahtiyar./127.0.1.1 (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,311] DEBUG [Controller id=0, targetBrokerId=0] Created socket with SO_RCVBUF = 65536, SO_SNDBUF = 1313280, SO_TIMEOUT = 0 to node 0 (org.apache.kafka.common.network.Selector) [2023-12-01 13:25:41,312] DEBUG [Controller id=0, targetBrokerId=0] Completed connection to node 0. Ready. (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,312] INFO [RequestSendThread controllerId=0] Controller 0 connected to Bahtiyar.:9092 (id: 0 rack: null) for sending state change requests (kafka.controller.RequestSendThread)
[2023-12-01 13:25:41,317] DEBUG Processor 0 listening to new connection from /127.0.0.1:56524 (kafka.network.Processor) [2023-12-01 13:25:41,329] DEBUG [Controller id=0, targetBrokerId=0] Sending UPDATE_METADATA request with header RequestHeader(apiKey=UPDATE_METADATA, apiVersion=8, clientId=0, correlationId=0, headerVersion=2) and timeout 30000 to node 0: UpdateMetadataRequestData(controllerId=0, isKRaftController=false, controllerEpoch=2, brokerEpoch=53, ungroupedPartitionStates=[], topicStates=[], liveBrokers=[UpdateMetadataBroker(id=0, v0Host='', v0Port=0, endpoints=[UpdateMetadataEndpoint(port=9092, host='Bahtiyar.', listener='PLAINTEXT', securityProtocol=0)], rack=null)]) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,345] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,345] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: No controller provided, retrying after backoff (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,353] DEBUG [Controller id=0, targetBrokerId=0] Received UPDATE_METADATA response from node 0 for request with header RequestHeader(apiKey=UPDATE_METADATA, apiVersion=8, clientId=0, correlationId=0, headerVersion=2): UpdateMetadataResponseData(errorCode=0) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,355] DEBUG [Controller id=0, targetBrokerId=0] Sending LEADER_AND_ISR request with header RequestHeader(apiKey=LEADER_AND_ISR, apiVersion=7, clientId=0, correlationId=1, headerVersion=2) and timeout 30000 to node 0: LeaderAndIsrRequestData(controllerId=0, isKRaftController=false, controllerEpoch=2, brokerEpoch=53, type=0, ungroupedPartitionStates=[], topicStates=[LeaderAndIsrTopicState(topicName='quickstart-events', topicId=ypm-NPoHTkGr1z5l_cVhqw, partitionStates=[LeaderAndIsrPartitionState(topicName='quickstart-events', partitionIndex=0, controllerEpoch=1, leader=0, leaderEpoch=0, isr=[0], partitionEpoch=0, replicas=[0], addingReplicas=[], removingReplicas=[], isNew=false, leaderRecoveryState=0)])], liveLeaders=[LeaderAndIsrLiveLeader(brokerId=0, hostName='Bahtiyar.', port=9092)]) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,362] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":6,"requestApiVersion":8,"correlationId":0,"clientId":"0","requestApiKeyName":"UPDATE_METADATA"},"request":{"controllerId":0,"isKRaftController":false,"controllerEpoch":2,"brokerEpoch":53,"topicStates":[],"liveBrokers":[{"id":0,"endpoints":[{"port":9092,"host":"Bahtiyar.","listener":"PLAINTEXT","securityProtocol":0}],"rack":null}]},"response":{"errorCode":0},"connection":"127.0.1.1:9092-127.0.0.1:56524-0","totalTimeMs":18.298,"requestQueueTimeMs":4.249,"localTimeMs":12.795,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.168,"sendTimeMs":1.084,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"unknown","softwareVersion":"unknown"}} (kafka.request.logger) [2023-12-01 13:25:41,366] INFO [Broker id=0] Handling LeaderAndIsr request correlationId 1 from controller 0 for 1 partitions (state.change.logger) [2023-12-01 13:25:41,377] INFO [ReplicaFetcherManager on broker 0] Removed fetcher for partitions Set(quickstart-events-0) (kafka.server.ReplicaFetcherManager) [2023-12-01 13:25:41,378] INFO [Broker id=0] Stopped fetchers as part of LeaderAndIsr request correlationId 1 from controller 0 epoch 2 as part of the become-leader transition for 1 partitions (state.change.logger) [2023-12-01 13:25:41,384] INFO [Partition quickstart-events-0 broker=0] Log loaded for partition quickstart-events-0 with initial high watermark 3 (kafka.cluster.Partition) [2023-12-01 13:25:41,385] INFO [Broker id=0] Leader quickstart-events-0 with topic id Some(ypm-NPoHTkGr1z5l_cVhqw) starts at leader epoch 0 from offset 3 with partition epoch 0, high watermark 3, ISR [0], adding replicas [] and removing replicas [] . Previous leader None and previous leader epoch was -1. (state.change.logger) [2023-12-01 13:25:41,388] DEBUG Scheduling task highwatermark-checkpoint with initial delay 0 ms and period 5000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:41,393] INFO [Broker id=0] Finished LeaderAndIsr request in 28ms correlationId 1 from controller 0 for 1 partitions (state.change.logger) [2023-12-01 13:25:41,397] DEBUG [Controller id=0, targetBrokerId=0] Received LEADER_AND_ISR response from node 0 for request with header RequestHeader(apiKey=LEADER_AND_ISR, apiVersion=7, clientId=0, correlationId=1, headerVersion=2): LeaderAndIsrResponseData(errorCode=0, partitionErrors=[], topics=[LeaderAndIsrTopicError(topicId=ypm-NPoHTkGr1z5l_cVhqw, partitionErrors=[LeaderAndIsrPartitionError(topicName='', partitionIndex=0, errorCode=0)])]) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,397] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":4,"requestApiVersion":7,"correlationId":1,"clientId":"0","requestApiKeyName":"LEADER_AND_ISR"},"request":{"controllerId":0,"isKRaftController":false,"controllerEpoch":2,"brokerEpoch":53,"type":0,"topicStates":[{"topicName":"quickstart-events","topicId":"ypm-NPoHTkGr1z5l_cVhqw","partitionStates":[{"partitionIndex":0,"controllerEpoch":1,"leader":0,"leaderEpoch":0,"isr":[0],"partitionEpoch":0,"replicas":[0],"addingReplicas":[],"removingReplicas":[],"isNew":false,"leaderRecoveryState":0}]}],"liveLeaders":[{"brokerId":0,"hostName":"Bahtiyar.","port":9092}]},"response":{"errorCode":0,"topics":[{"topicId":"ypm-NPoHTkGr1z5l_cVhqw","partitionErrors":[{"partitionIndex":0,"errorCode":0}]}]},"connection":"127.0.1.1:9092-127.0.0.1:56524-0","totalTimeMs":33.666,"requestQueueTimeMs":1.514,"localTimeMs":31.728,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.17,"sendTimeMs":0.252,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"unknown","softwareVersion":"unknown"}} (kafka.request.logger) [2023-12-01 13:25:41,398] DEBUG [Controller id=0, targetBrokerId=0] Sending UPDATE_METADATA request with header RequestHeader(apiKey=UPDATE_METADATA, apiVersion=8, clientId=0, correlationId=2, headerVersion=2) and timeout 30000 to node 0: UpdateMetadataRequestData(controllerId=0, isKRaftController=false, controllerEpoch=2, brokerEpoch=53, ungroupedPartitionStates=[], topicStates=[UpdateMetadataTopicState(topicName='quickstart-events', topicId=ypm-NPoHTkGr1z5l_cVhqw, partitionStates=[UpdateMetadataPartitionState(topicName='quickstart-events', partitionIndex=0, controllerEpoch=1, leader=0, leaderEpoch=0, isr=[0], zkVersion=0, replicas=[0], offlineReplicas=[])])], liveBrokers=[UpdateMetadataBroker(id=0, v0Host='', v0Port=0, endpoints=[UpdateMetadataEndpoint(port=9092, host='Bahtiyar.', listener='PLAINTEXT', securityProtocol=0)], rack=null)]) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,401] DEBUG [zk-broker-0-to-controller-forwarding-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,403] INFO [zk-broker-0-to-controller-forwarding-channel-manager]: Recorded new controller, from now on will use node Bahtiyar.:9092 (id: 0 rack: null) (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,403] INFO [Broker id=0] Add 1 partitions and deleted 0 partitions from metadata cache in response to UpdateMetadata request sent by controller 0 epoch 2 with correlation id 2 (state.change.logger) [2023-12-01 13:25:41,404] DEBUG [Controller id=0, targetBrokerId=0] Received UPDATE_METADATA response from node 0 for request with header RequestHeader(apiKey=UPDATE_METADATA, apiVersion=8, clientId=0, correlationId=2, headerVersion=2): UpdateMetadataResponseData(errorCode=0) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:25:41,405] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":6,"requestApiVersion":8,"correlationId":2,"clientId":"0","requestApiKeyName":"UPDATE_METADATA"},"request":{"controllerId":0,"isKRaftController":false,"controllerEpoch":2,"brokerEpoch":53,"topicStates":[{"topicName":"quickstart-events","topicId":"ypm-NPoHTkGr1z5l_cVhqw","partitionStates":[{"partitionIndex":0,"controllerEpoch":1,"leader":0,"leaderEpoch":0,"isr":[0],"zkVersion":0,"replicas":[0],"offlineReplicas":[]}]}],"liveBrokers":[{"id":0,"endpoints":[{"port":9092,"host":"Bahtiyar.","listener":"PLAINTEXT","securityProtocol":0}],"rack":null}]},"response":{"errorCode":0},"connection":"127.0.1.1:9092-127.0.0.1:56524-0","totalTimeMs":5.875,"requestQueueTimeMs":1.039,"localTimeMs":4.376,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.118,"sendTimeMs":0.34,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"unknown","softwareVersion":"unknown"}} (kafka.request.logger) [2023-12-01 13:25:41,445] DEBUG [zk-broker-0-to-controller-alter-partition-channel-manager]: Controller isn't cached, looking for local metadata changes (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:41,445] INFO [zk-broker-0-to-controller-alter-partition-channel-manager]: Recorded new controller, from now on will use node Bahtiyar.:9092 (id: 0 rack: null) (kafka.server.BrokerToControllerRequestThread) [2023-12-01 13:25:46,242] INFO [Controller id=0] Processing automatic preferred replica leader election (kafka.controller.KafkaController) [2023-12-01 13:25:46,244] DEBUG [Controller id=0] Topics not in preferred replica for broker 0 Map() (kafka.controller.KafkaController) [2023-12-01 13:25:46,245] DEBUG Scheduling task auto-leader-rebalance-task with initial delay 300000 ms and period -1 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:25:47,258] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:47,258] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:47,258] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:47,258] DEBUG Got ping response for session id: 0x1000002184f0000 after 1ms. (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:53,264] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:53,264] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:53,264] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:53,265] DEBUG Got ping response for session id: 0x1000002184f0000 after 2ms. (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:25:59,270] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:25:59,271] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:59,271] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:25:59,271] DEBUG Got ping response for session id: 0x1000002184f0000 after 1ms. (org.apache.zookeeper.ClientCnxn)
[2023-12-01 13:26:04,022] DEBUG Processor 1 listening to new connection from /0:0:0:0:0:0:0:1:45848 (kafka.network.Processor) [2023-12-01 13:26:04,028] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":18,"requestApiVersion":3,"correlationId":1,"clientId":"testProducer","requestApiKeyName":"API_VERSIONS"},"request":{"clientSoftwareName":"librdkafka","clientSoftwareVersion":"2.3.0"},"response":{"errorCode":0,"apiKeys":[{"apiKey":0,"minVersion":0,"maxVersion":9},{"apiKey":1,"minVersion":0,"maxVersion":15},{"apiKey":2,"minVersion":0,"maxVersion":8},{"apiKey":3,"minVersion":0,"maxVersion":12},{"apiKey":4,"minVersion":0,"maxVersion":7},{"apiKey":5,"minVersion":0,"maxVersion":4},{"apiKey":6,"minVersion":0,"maxVersion":8},{"apiKey":7,"minVersion":0,"maxVersion":3},{"apiKey":8,"minVersion":0,"maxVersion":8},{"apiKey":9,"minVersion":0,"maxVersion":8},{"apiKey":10,"minVersion":0,"maxVersion":4},{"apiKey":11,"minVersion":0,"maxVersion":9},{"apiKey":12,"minVersion":0,"maxVersion":4},{"apiKey":13,"minVersion":0,"maxVersion":5},{"apiKey":14,"minVersion":0,"maxVersion":5},{"apiKey":15,"minVersion":0,"maxVersion":5},{"apiKey":16,"minVersion":0,"maxVersion":4},{"apiKey":17,"minVersion":0,"maxVersion":1},{"apiKey":18,"minVersion":0,"maxVersion":3},{"apiKey":19,"minVersion":0,"maxVersion":7},{"apiKey":20,"minVersion":0,"maxVersion":6},{"apiKey":21,"minVersion":0,"maxVersion":2},{"apiKey":22,"minVersion":0,"maxVersion":4},{"apiKey":23,"minVersion":0,"maxVersion":4},{"apiKey":24,"minVersion":0,"maxVersion":4},{"apiKey":25,"minVersion":0,"maxVersion":3},{"apiKey":26,"minVersion":0,"maxVersion":3},{"apiKey":27,"minVersion":0,"maxVersion":1},{"apiKey":28,"minVersion":0,"maxVersion":3},{"apiKey":29,"minVersion":0,"maxVersion":3},{"apiKey":30,"minVersion":0,"maxVersion":3},{"apiKey":31,"minVersion":0,"maxVersion":3},{"apiKey":32,"minVersion":0,"maxVersion":4},{"apiKey":33,"minVersion":0,"maxVersion":2},{"apiKey":34,"minVersion":0,"maxVersion":2},{"apiKey":35,"minVersion":0,"maxVersion":4},{"apiKey":36,"minVersion":0,"maxVersion":2},{"apiKey":37,"minVersion":0,"maxVersion":3},{"apiKey":38,"minVersion":0,"maxVersion":3},{"apiKey":39,"minVersion":0,"maxVersion":2},{"apiKey":40,"minVersion":0,"maxVersion":2},{"apiKey":41,"minVersion":0,"maxVersion":3},{"apiKey":42,"minVersion":0,"maxVersion":2},{"apiKey":43,"minVersion":0,"maxVersion":2},{"apiKey":44,"minVersion":0,"maxVersion":1},{"apiKey":45,"minVersion":0,"maxVersion":0},{"apiKey":46,"minVersion":0,"maxVersion":0},{"apiKey":47,"minVersion":0,"maxVersion":0},{"apiKey":48,"minVersion":0,"maxVersion":1},{"apiKey":49,"minVersion":0,"maxVersion":1},{"apiKey":50,"minVersion":0,"maxVersion":0},{"apiKey":51,"minVersion":0,"maxVersion":0},{"apiKey":56,"minVersion":0,"maxVersion":3},{"apiKey":57,"minVersion":0,"maxVersion":1},{"apiKey":58,"minVersion":0,"maxVersion":0},{"apiKey":60,"minVersion":0,"maxVersion":0},{"apiKey":61,"minVersion":0,"maxVersion":0},{"apiKey":65,"minVersion":0,"maxVersion":0},{"apiKey":66,"minVersion":0,"maxVersion":0},{"apiKey":67,"minVersion":0,"maxVersion":0}],"throttleTimeMs":0,"finalizedFeaturesEpoch":0},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":4.568,"requestQueueTimeMs":0.911,"localTimeMs":3.382,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.072,"sendTimeMs":0.202,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"unknown","softwareVersion":"unknown"}} (kafka.request.logger) [2023-12-01 13:26:04,038] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,038] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x38 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/delete_topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,038] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x38 zxid:0xfffffffffffffffe txntype:unknown reqpath:/admin/delete_topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,039] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/admin/delete_topics/newnew serverPath:/admin/delete_topics/newnew finished:false header:: 56,3 replyHeader:: 56,55,-101 request:: '/admin/delete_topics/newnew,F response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,040] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,040] DEBUG Processing request:: sessionid:0x1000002184f0000 type:exists cxid:0x39 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,040] DEBUG sessionid:0x1000002184f0000 type:exists cxid:0x39 zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,041] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics/newnew serverPath:/brokers/topics/newnew finished:false header:: 57,3 replyHeader:: 57,55,-101 request:: '/brokers/topics/newnew,F response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,044] INFO Creating topic newnew with configuration {} and initial partition assignment HashMap(0 -> ArrayBuffer(0)) (kafka.zk.AdminZkClient) [2023-12-01 13:26:04,046] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,048] DEBUG Processing request:: sessionid:0x1000002184f0000 type:setData cxid:0x3a zxid:0x38 txntype:-1 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,048] DEBUG Ignoring processTxn failure hdr: -1 : error: -101 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:26:04,049] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/topics/newnew serverPath:/config/topics/newnew finished:false header:: 58,5 replyHeader:: 58,56,-101 request:: '/config/topics/newnew,#7b2276657273696f6e223a312c22636f6e666967223a7b7d7d,-1 response:: (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,050] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,050] DEBUG Processing ACL: 31,s{'world,'anyone} (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,050] DEBUG Permission requested: 4 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,050] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,050] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,050] DEBUG Digest got from data tree is: 70591705581 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,050] DEBUG Digest got from outstandingChanges is: 72795778043 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,051] DEBUG Processing request:: sessionid:0x1000002184f0000 type:create cxid:0x3b zxid:0x39 txntype:1 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,052] DEBUG config (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:26:04,052] DEBUG Digests are matching for Zxid: 39, Digest in log and actual tree: 75923241920 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:26:04,052] DEBUG sessionid:0x1000002184f0000 type:create cxid:0x3b zxid:0x39 txntype:1 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,052] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/topics/newnew serverPath:/config/topics/newnew finished:false header:: 59,1 replyHeader:: 59,57,0 request:: '/config/topics/newnew,#7b2276657273696f6e223a312c22636f6e666967223a7b7d7d,v{s{31,s{'world,'anyone}}},0 response:: '/config/topics/newnew (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,056] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,056] DEBUG Processing ACL: 31,s{'world,'anyone} (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,056] DEBUG Permission requested: 4 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,056] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,056] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,056] DEBUG Digest got from data tree is: 75923241920 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,056] DEBUG Digest got from outstandingChanges is: 77381721435 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,057] DEBUG Processing request:: sessionid:0x1000002184f0000 type:create cxid:0x3c zxid:0x3a txntype:1 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,058] DEBUG brokers (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:26:04,058] DEBUG Digests are matching for Zxid: 3a, Digest in log and actual tree: 79174336021 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:26:04,058] DEBUG sessionid:0x1000002184f0000 type:create cxid:0x3c zxid:0x3a txntype:1 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,058] DEBUG Got notification session id: 0x1000002184f0000 (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,058] DEBUG Got WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/brokers/topics for session id 0x1000002184f0000 (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,058] DEBUG [ZooKeeperClient Kafka server] Received event: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/brokers/topics (kafka.zookeeper.ZooKeeperClient) [2023-12-01 13:26:04,058] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics/newnew serverPath:/brokers/topics/newnew finished:false header:: 60,1 replyHeader:: 60,58,0 request:: '/brokers/topics/newnew,#7b22706172746974696f6e73223a7b2230223a5b305d7d2c22746f7069635f6964223a225a585766546976555133475a43684264397038597341222c22616464696e675f7265706c69636173223a7b7d2c2272656d6f76696e675f7265706c69636173223a7b7d2c2276657273696f6e223a337d,v{s{31,s{'world,'anyone}}},0 response:: '/brokers/topics/newnew (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,059] DEBUG Updated path /brokers/topics/newnew with Map(newnew-0 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=)) for replica assignment (kafka.zk.AdminZkClient) [2023-12-01 13:26:04,059] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,059] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getChildren2 cxid:0x3d zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,060] DEBUG sessionid:0x1000002184f0000 type:getChildren2 cxid:0x3d zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,060] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,060] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,060] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,060] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics serverPath:/brokers/topics finished:false header:: 61,12 replyHeader:: 61,58,0 request:: '/brokers/topics,T response:: v{'quickstart-events,'newnew},s{6,6,1701417381667,1701417381667,0,2,0,0,0,2,58} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,061] DEBUG Cleared inflight topic creation state for HashMap(newnew -> CreatableTopic(name='newnew', numPartitions=1, replicationFactor=1, assignments=[], configs=[])) (kafka.server.DefaultAutoTopicCreationManager) [2023-12-01 13:26:04,062] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,062] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x3e zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,062] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x3e zxid:0xfffffffffffffffe txntype:unknown reqpath:/brokers/topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,062] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,062] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,062] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,063] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/brokers/topics/newnew serverPath:/brokers/topics/newnew finished:false header:: 62,4 replyHeader:: 62,58,0 request:: '/brokers/topics/newnew,T response:: #7b22706172746974696f6e73223a7b2230223a5b305d7d2c22746f7069635f6964223a225a585766546976555133475a43684264397038597341222c22616464696e675f7265706c69636173223a7b7d2c2272656d6f76696e675f7265706c69636173223a7b7d2c2276657273696f6e223a337d,s{58,58,1701419164055,1701419164055,0,0,0,0,116,0,58} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,064] INFO [Controller id=0] New topics: [Set(newnew)], deleted topics: [HashSet()], new partition replica assignment [Set(TopicIdReplicaAssignment(newnew,Some(ZXWfTivUQ3GZChBd9p8YsA),Map(newnew-0 -> ReplicaAssignment(replicas=0, addingReplicas=, removingReplicas=))))] (kafka.controller.KafkaController) [2023-12-01 13:26:04,065] INFO [Controller id=0] New partition creation callback for newnew-0 (kafka.controller.KafkaController) [2023-12-01 13:26:04,066] INFO [Controller id=0 epoch=2] Changed partition newnew-0 state from NonExistentPartition to NewPartition with assigned replicas 0 (state.change.logger) [2023-12-01 13:26:04,066] INFO [Controller id=0 epoch=2] Sending UpdateMetadata request to brokers HashSet() for 0 partitions (state.change.logger) [2023-12-01 13:26:04,066] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":3,"requestApiVersion":12,"correlationId":2,"clientId":"testProducer","requestApiKeyName":"METADATA"},"request":{"topics":[{"topicId":"AAAAAAAAAAAAAAAAAAAAAA","name":"newnew"}],"allowAutoTopicCreation":true,"includeTopicAuthorizedOperations":false},"response":{"throttleTimeMs":0,"brokers":[{"nodeId":0,"host":"Bahtiyar.","port":9092,"rack":null}],"clusterId":"y50rYylwQauDgsl64Qtr4Q","controllerId":0,"topics":[{"errorCode":5,"name":"newnew","topicId":"AAAAAAAAAAAAAAAAAAAAAA","isInternal":false,"partitions":[],"topicAuthorizedOperations":-2147483648}]},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":37.553,"requestQueueTimeMs":0.666,"localTimeMs":36.591,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.083,"sendTimeMs":0.211,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"librdkafka","softwareVersion":"2.3.0"}} (kafka.request.logger) [2023-12-01 13:26:04,068] INFO [Controller id=0 epoch=2] Sending UpdateMetadata request to brokers HashSet() for 0 partitions (state.change.logger) [2023-12-01 13:26:04,070] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,070] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,070] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,070] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,070] DEBUG Digest got from data tree is: 79174336021 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,070] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,070] DEBUG Processing ACL: 31,s{'world,'anyone} (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,071] DEBUG Permission requested: 4 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,071] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,071] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,071] DEBUG Digest got from data tree is: 79174336021 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,071] DEBUG Digest got from outstandingChanges is: 78317046651 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,071] DEBUG Digest got from outstandingChanges is: 81970111970 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,072] DEBUG Processing request:: sessionid:0x1000002184f0000 type:multi cxid:0x3f zxid:0x3b txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,072] DEBUG brokers (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:26:04,072] DEBUG Digests are matching for Zxid: 3b, Digest in log and actual tree: 81970111970 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:26:04,072] DEBUG sessionid:0x1000002184f0000 type:multi cxid:0x3f zxid:0x3b txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,073] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:null serverPath:null finished:false header:: 63,14 replyHeader:: 63,59,0 request:: org.apache.zookeeper.MultiOperationRecord@b3215045 response:: org.apache.zookeeper.MultiResponse@aced506d (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,075] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,075] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,075] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,075] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,075] DEBUG Digest got from data tree is: 81970111970 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,075] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,075] DEBUG Processing ACL: 31,s{'world,'anyone} (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,075] DEBUG Permission requested: 4 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,075] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,075] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,076] DEBUG Digest got from data tree is: 81970111970 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,076] DEBUG Digest got from outstandingChanges is: 79124051384 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,076] DEBUG Digest got from outstandingChanges is: 79923338172 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,077] DEBUG Processing request:: sessionid:0x1000002184f0000 type:multi cxid:0x40 zxid:0x3c txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,077] DEBUG brokers (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:26:04,077] DEBUG Digests are matching for Zxid: 3c, Digest in log and actual tree: 79923338172 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:26:04,077] DEBUG sessionid:0x1000002184f0000 type:multi cxid:0x40 zxid:0x3c txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,078] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:null serverPath:null finished:false header:: 64,14 replyHeader:: 64,60,0 request:: org.apache.zookeeper.MultiOperationRecord@2ce3dde6 response:: org.apache.zookeeper.MultiResponse@26afde0e (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,079] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,080] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,080] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,080] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,080] DEBUG Digest got from data tree is: 79923338172 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,080] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,080] DEBUG Processing ACL: 31,s{'world,'anyone} (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,080] DEBUG Permission requested: 4 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,080] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,080] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,080] DEBUG Digest got from data tree is: 79923338172 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,080] DEBUG Digest got from outstandingChanges is: 81049427542 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,080] DEBUG Digest got from outstandingChanges is: 81814925915 (org.apache.zookeeper.server.PrepRequestProcessor) [2023-12-01 13:26:04,082] DEBUG Processing request:: sessionid:0x1000002184f0000 type:multi cxid:0x41 zxid:0x3d txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,082] DEBUG brokers (org.apache.zookeeper.common.PathTrie) [2023-12-01 13:26:04,082] DEBUG Digests are matching for Zxid: 3d, Digest in log and actual tree: 81814925915 (org.apache.zookeeper.server.DataTree) [2023-12-01 13:26:04,082] DEBUG sessionid:0x1000002184f0000 type:multi cxid:0x41 zxid:0x3d txntype:14 reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,083] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:null serverPath:null finished:false header:: 65,14 replyHeader:: 65,61,0 request:: org.apache.zookeeper.MultiOperationRecord@d0c9ffc response:: org.apache.zookeeper.MultiResponse@8616b250 (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,084] INFO [Controller id=0 epoch=2] Changed partition newnew-0 from NewPartition to OnlinePartition with state LeaderAndIsr(leader=0, leaderEpoch=0, isrWithBrokerEpoch=List(BrokerState(brokerId=0, brokerEpoch=-1)), leaderRecoveryState=RECOVERED, partitionEpoch=0) (state.change.logger) [2023-12-01 13:26:04,084] INFO [Controller id=0 epoch=2] Sending LeaderAndIsr request to broker 0 with 1 become-leader and 0 become-follower partitions (state.change.logger) [2023-12-01 13:26:04,085] INFO [Controller id=0 epoch=2] Sending UpdateMetadata request to brokers HashSet(0) for 1 partitions (state.change.logger) [2023-12-01 13:26:04,085] INFO [Controller id=0 epoch=2] Sending UpdateMetadata request to brokers HashSet() for 0 partitions (state.change.logger) [2023-12-01 13:26:04,085] DEBUG [Controller id=0, targetBrokerId=0] Sending LEADER_AND_ISR request with header RequestHeader(apiKey=LEADER_AND_ISR, apiVersion=7, clientId=0, correlationId=3, headerVersion=2) and timeout 30000 to node 0: LeaderAndIsrRequestData(controllerId=0, isKRaftController=false, controllerEpoch=2, brokerEpoch=53, type=0, ungroupedPartitionStates=[], topicStates=[LeaderAndIsrTopicState(topicName='newnew', topicId=ZXWfTivUQ3GZChBd9p8YsA, partitionStates=[LeaderAndIsrPartitionState(topicName='newnew', partitionIndex=0, controllerEpoch=2, leader=0, leaderEpoch=0, isr=[0], partitionEpoch=0, replicas=[0], addingReplicas=[], removingReplicas=[], isNew=true, leaderRecoveryState=0)])], liveLeaders=[LeaderAndIsrLiveLeader(brokerId=0, hostName='Bahtiyar.', port=9092)]) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:26:04,086] INFO [Broker id=0] Handling LeaderAndIsr request correlationId 3 from controller 0 for 1 partitions (state.change.logger) [2023-12-01 13:26:04,086] INFO [ReplicaFetcherManager on broker 0] Removed fetcher for partitions Set(newnew-0) (kafka.server.ReplicaFetcherManager) [2023-12-01 13:26:04,086] INFO [Broker id=0] Stopped fetchers as part of LeaderAndIsr request correlationId 3 from controller 0 epoch 2 as part of the become-leader transition for 1 partitions (state.change.logger) [2023-12-01 13:26:04,088] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:04,088] DEBUG Processing request:: sessionid:0x1000002184f0000 type:getData cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,088] DEBUG sessionid:0x1000002184f0000 type:getData cxid:0x42 zxid:0xfffffffffffffffe txntype:unknown reqpath:/config/topics/newnew (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:04,088] DEBUG Permission requested: 1 (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,088] DEBUG ACLs for node: [31,s{'world,'anyone} ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,088] DEBUG Client credentials: ['ip,'127.0.0.1 ] (org.apache.zookeeper.server.ZooKeeperServer) [2023-12-01 13:26:04,089] DEBUG Reading reply session id: 0x1000002184f0000, packet:: clientPath:/config/topics/newnew serverPath:/config/topics/newnew finished:false header:: 66,4 replyHeader:: 66,61,0 request:: '/config/topics/newnew,F response:: #7b2276657273696f6e223a312c22636f6e666967223a7b7d7d,s{57,57,1701419164050,1701419164050,0,0,0,0,25,0,57} (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:04,091] DEBUG Loaded index file /home/kafka/kafka/logs/newnew-0/00000000000000000000.index with maxEntries = 1310720, maxIndexSize = 10485760, entries = 0, lastOffset = 0, file position = 0 (org.apache.kafka.storage.internals.log.OffsetIndex) [2023-12-01 13:26:04,091] DEBUG Index /home/kafka/kafka/logs/newnew-0/00000000000000000000.index was not resized because it already has size 10485760 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:26:04,091] DEBUG Loaded index file /home/kafka/kafka/logs/newnew-0/00000000000000000000.timeindex with maxEntries = 873813, maxIndexSize = 10485760, entries = 0, lastOffset = 0, file position = 0 (org.apache.kafka.storage.internals.log.TimeIndex) [2023-12-01 13:26:04,092] DEBUG Index /home/kafka/kafka/logs/newnew-0/00000000000000000000.timeindex was not resized because it already has size 10485756 (org.apache.kafka.storage.internals.log.AbstractIndex) [2023-12-01 13:26:04,092] INFO [LogLoader partition=newnew-0, dir=/home/kafka/kafka/logs] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$) [2023-12-01 13:26:04,094] DEBUG Scheduling task flush-metadata-file with initial delay 0 ms and period -1 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:26:04,094] DEBUG Scheduling task PeriodicProducerExpirationCheck with initial delay 600000 ms and period 600000 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:26:04,095] INFO Created log for partition newnew-0 in /home/kafka/kafka/logs/newnew-0 with properties {} (kafka.log.LogManager) [2023-12-01 13:26:04,095] INFO [Partition newnew-0 broker=0] No checkpointed highwatermark is found for partition newnew-0 (kafka.cluster.Partition) [2023-12-01 13:26:04,095] INFO [Partition newnew-0 broker=0] Log loaded for partition newnew-0 with initial high watermark 0 (kafka.cluster.Partition) [2023-12-01 13:26:04,095] INFO [Broker id=0] Leader newnew-0 with topic id Some(ZXWfTivUQ3GZChBd9p8YsA) starts at leader epoch 0 from offset 0 with partition epoch 0, high watermark 0, ISR [0], adding replicas [] and removing replicas [] . Previous leader None and previous leader epoch was -1. (state.change.logger) [2023-12-01 13:26:04,095] DEBUG [LeaderEpochCache newnew-0] Appended new epoch entry EpochEntry(epoch=0, startOffset=0). Cache now contains 1 entries. (org.apache.kafka.storage.internals.epoch.LeaderEpochFileCache) [2023-12-01 13:26:04,105] INFO [Broker id=0] Finished LeaderAndIsr request in 20ms correlationId 3 from controller 0 for 1 partitions (state.change.logger) [2023-12-01 13:26:04,105] DEBUG [Controller id=0, targetBrokerId=0] Received LEADER_AND_ISR response from node 0 for request with header RequestHeader(apiKey=LEADER_AND_ISR, apiVersion=7, clientId=0, correlationId=3, headerVersion=2): LeaderAndIsrResponseData(errorCode=0, partitionErrors=[], topics=[LeaderAndIsrTopicError(topicId=ZXWfTivUQ3GZChBd9p8YsA, partitionErrors=[LeaderAndIsrPartitionError(topicName='', partitionIndex=0, errorCode=0)])]) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:26:04,106] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":4,"requestApiVersion":7,"correlationId":3,"clientId":"0","requestApiKeyName":"LEADER_AND_ISR"},"request":{"controllerId":0,"isKRaftController":false,"controllerEpoch":2,"brokerEpoch":53,"type":0,"topicStates":[{"topicName":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","partitionStates":[{"partitionIndex":0,"controllerEpoch":2,"leader":0,"leaderEpoch":0,"isr":[0],"partitionEpoch":0,"replicas":[0],"addingReplicas":[],"removingReplicas":[],"isNew":true,"leaderRecoveryState":0}]}],"liveLeaders":[{"brokerId":0,"hostName":"Bahtiyar.","port":9092}]},"response":{"errorCode":0,"topics":[{"topicId":"ZXWfTivUQ3GZChBd9p8YsA","partitionErrors":[{"partitionIndex":0,"errorCode":0}]}]},"connection":"127.0.1.1:9092-127.0.0.1:56524-0","totalTimeMs":20.012,"requestQueueTimeMs":0.156,"localTimeMs":19.584,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.075,"sendTimeMs":0.196,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"unknown","softwareVersion":"unknown"}} (kafka.request.logger) [2023-12-01 13:26:04,106] DEBUG [Controller id=0, targetBrokerId=0] Sending UPDATE_METADATA request with header RequestHeader(apiKey=UPDATE_METADATA, apiVersion=8, clientId=0, correlationId=4, headerVersion=2) and timeout 30000 to node 0: UpdateMetadataRequestData(controllerId=0, isKRaftController=false, controllerEpoch=2, brokerEpoch=53, ungroupedPartitionStates=[], topicStates=[UpdateMetadataTopicState(topicName='newnew', topicId=ZXWfTivUQ3GZChBd9p8YsA, partitionStates=[UpdateMetadataPartitionState(topicName='newnew', partitionIndex=0, controllerEpoch=2, leader=0, leaderEpoch=0, isr=[0], zkVersion=0, replicas=[0], offlineReplicas=[])])], liveBrokers=[UpdateMetadataBroker(id=0, v0Host='', v0Port=0, endpoints=[UpdateMetadataEndpoint(port=9092, host='Bahtiyar.', listener='PLAINTEXT', securityProtocol=0)], rack=null)]) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:26:04,106] INFO [Broker id=0] Add 1 partitions and deleted 0 partitions from metadata cache in response to UpdateMetadata request sent by controller 0 epoch 2 with correlation id 4 (state.change.logger) [2023-12-01 13:26:04,108] DEBUG [Controller id=0, targetBrokerId=0] Received UPDATE_METADATA response from node 0 for request with header RequestHeader(apiKey=UPDATE_METADATA, apiVersion=8, clientId=0, correlationId=4, headerVersion=2): UpdateMetadataResponseData(errorCode=0) (org.apache.kafka.clients.NetworkClient) [2023-12-01 13:26:04,108] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":6,"requestApiVersion":8,"correlationId":4,"clientId":"0","requestApiKeyName":"UPDATE_METADATA"},"request":{"controllerId":0,"isKRaftController":false,"controllerEpoch":2,"brokerEpoch":53,"topicStates":[{"topicName":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","partitionStates":[{"partitionIndex":0,"controllerEpoch":2,"leader":0,"leaderEpoch":0,"isr":[0],"zkVersion":0,"replicas":[0],"offlineReplicas":[]}]}],"liveBrokers":[{"id":0,"endpoints":[{"port":9092,"host":"Bahtiyar.","listener":"PLAINTEXT","securityProtocol":0}],"rack":null}]},"response":{"errorCode":0},"connection":"127.0.1.1:9092-127.0.0.1:56524-0","totalTimeMs":1.876,"requestQueueTimeMs":0.173,"localTimeMs":1.416,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.092,"sendTimeMs":0.193,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"unknown","softwareVersion":"unknown"}} (kafka.request.logger) [2023-12-01 13:26:05,035] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":3,"requestApiVersion":12,"correlationId":3,"clientId":"testProducer","requestApiKeyName":"METADATA"},"request":{"topics":[{"topicId":"AAAAAAAAAAAAAAAAAAAAAA","name":"newnew"}],"allowAutoTopicCreation":true,"includeTopicAuthorizedOperations":false},"response":{"throttleTimeMs":0,"brokers":[{"nodeId":0,"host":"Bahtiyar.","port":9092,"rack":null}],"clusterId":"y50rYylwQauDgsl64Qtr4Q","controllerId":0,"topics":[{"errorCode":0,"name":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","isInternal":false,"partitions":[{"errorCode":0,"partitionIndex":0,"leaderId":0,"leaderEpoch":0,"replicaNodes":[0],"isrNodes":[0],"offlineReplicas":[]}],"topicAuthorizedOperations":-2147483648}]},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":3.112,"requestQueueTimeMs":0.204,"localTimeMs":2.599,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.114,"sendTimeMs":0.193,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"librdkafka","softwareVersion":"2.3.0"}} (kafka.request.logger) [2023-12-01 13:26:06,035] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":3,"requestApiVersion":12,"correlationId":4,"clientId":"testProducer","requestApiKeyName":"METADATA"},"request":{"topics":[{"topicId":"AAAAAAAAAAAAAAAAAAAAAA","name":"newnew"}],"allowAutoTopicCreation":true,"includeTopicAuthorizedOperations":false},"response":{"throttleTimeMs":0,"brokers":[{"nodeId":0,"host":"Bahtiyar.","port":9092,"rack":null}],"clusterId":"y50rYylwQauDgsl64Qtr4Q","controllerId":0,"topics":[{"errorCode":0,"name":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","isInternal":false,"partitions":[{"errorCode":0,"partitionIndex":0,"leaderId":0,"leaderEpoch":0,"replicaNodes":[0],"isrNodes":[0],"offlineReplicas":[]}],"topicAuthorizedOperations":-2147483648}]},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":0.919,"requestQueueTimeMs":0.178,"localTimeMs":0.478,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.096,"sendTimeMs":0.166,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"librdkafka","softwareVersion":"2.3.0"}} (kafka.request.logger) [2023-12-01 13:26:07,050] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":3,"requestApiVersion":12,"correlationId":5,"clientId":"testProducer","requestApiKeyName":"METADATA"},"request":{"topics":[{"topicId":"AAAAAAAAAAAAAAAAAAAAAA","name":"newnew"}],"allowAutoTopicCreation":true,"includeTopicAuthorizedOperations":false},"response":{"throttleTimeMs":0,"brokers":[{"nodeId":0,"host":"Bahtiyar.","port":9092,"rack":null}],"clusterId":"y50rYylwQauDgsl64Qtr4Q","controllerId":0,"topics":[{"errorCode":0,"name":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","isInternal":false,"partitions":[{"errorCode":0,"partitionIndex":0,"leaderId":0,"leaderEpoch":0,"replicaNodes":[0],"isrNodes":[0],"offlineReplicas":[]}],"topicAuthorizedOperations":-2147483648}]},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":1.589,"requestQueueTimeMs":0.279,"localTimeMs":0.842,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.206,"sendTimeMs":0.26,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"librdkafka","softwareVersion":"2.3.0"}} (kafka.request.logger) [2023-12-01 13:26:08,062] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":3,"requestApiVersion":12,"correlationId":6,"clientId":"testProducer","requestApiKeyName":"METADATA"},"request":{"topics":[{"topicId":"AAAAAAAAAAAAAAAAAAAAAA","name":"newnew"}],"allowAutoTopicCreation":true,"includeTopicAuthorizedOperations":false},"response":{"throttleTimeMs":0,"brokers":[{"nodeId":0,"host":"Bahtiyar.","port":9092,"rack":null}],"clusterId":"y50rYylwQauDgsl64Qtr4Q","controllerId":0,"topics":[{"errorCode":0,"name":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","isInternal":false,"partitions":[{"errorCode":0,"partitionIndex":0,"leaderId":0,"leaderEpoch":0,"replicaNodes":[0],"isrNodes":[0],"offlineReplicas":[]}],"topicAuthorizedOperations":-2147483648}]},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":1.135,"requestQueueTimeMs":0.31,"localTimeMs":0.486,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.189,"sendTimeMs":0.148,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"librdkafka","softwareVersion":"2.3.0"}} (kafka.request.logger) [2023-12-01 13:26:09,062] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":3,"requestApiVersion":12,"correlationId":7,"clientId":"testProducer","requestApiKeyName":"METADATA"},"request":{"topics":[{"topicId":"AAAAAAAAAAAAAAAAAAAAAA","name":"newnew"}],"allowAutoTopicCreation":true,"includeTopicAuthorizedOperations":false},"response":{"throttleTimeMs":0,"brokers":[{"nodeId":0,"host":"Bahtiyar.","port":9092,"rack":null}],"clusterId":"y50rYylwQauDgsl64Qtr4Q","controllerId":0,"topics":[{"errorCode":0,"name":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","isInternal":false,"partitions":[{"errorCode":0,"partitionIndex":0,"leaderId":0,"leaderEpoch":0,"replicaNodes":[0],"isrNodes":[0],"offlineReplicas":[]}],"topicAuthorizedOperations":-2147483648}]},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":0.896,"requestQueueTimeMs":0.244,"localTimeMs":0.486,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.056,"sendTimeMs":0.108,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"librdkafka","softwareVersion":"2.3.0"}} (kafka.request.logger) [2023-12-01 13:26:10,077] DEBUG Completed request:{"isForwarded":false,"requestHeader":{"requestApiKey":3,"requestApiVersion":12,"correlationId":8,"clientId":"testProducer","requestApiKeyName":"METADATA"},"request":{"topics":[{"topicId":"AAAAAAAAAAAAAAAAAAAAAA","name":"newnew"}],"allowAutoTopicCreation":true,"includeTopicAuthorizedOperations":false},"response":{"throttleTimeMs":0,"brokers":[{"nodeId":0,"host":"Bahtiyar.","port":9092,"rack":null}],"clusterId":"y50rYylwQauDgsl64Qtr4Q","controllerId":0,"topics":[{"errorCode":0,"name":"newnew","topicId":"ZXWfTivUQ3GZChBd9p8YsA","isInternal":false,"partitions":[{"errorCode":0,"partitionIndex":0,"leaderId":0,"leaderEpoch":0,"replicaNodes":[0],"isrNodes":[0],"offlineReplicas":[]}],"topicAuthorizedOperations":-2147483648}]},"connection":"0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0","totalTimeMs":1.888,"requestQueueTimeMs":0.397,"localTimeMs":1.076,"remoteTimeMs":0.0,"throttleTimeMs":0,"responseQueueTimeMs":0.131,"sendTimeMs":0.283,"securityProtocol":"PLAINTEXT","principal":"User:ANONYMOUS","listener":"PLAINTEXT","clientInformation":{"softwareName":"librdkafka","softwareVersion":"2.3.0"}} (kafka.request.logger) [2023-12-01 13:26:10,096] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:10,096] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:10,097] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:10,097] DEBUG Got ping response for session id: 0x1000002184f0000 after 2ms. (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:10,588] DEBUG Beginning log cleanup... (kafka.log.LogManager) [2023-12-01 13:26:10,589] DEBUG Checking for dirty logs to flush... (kafka.log.LogManager) [2023-12-01 13:26:10,590] DEBUG Scheduling task kafka-delete-logs with initial delay 60000 ms and period -1 ms. (org.apache.kafka.server.util.KafkaScheduler) [2023-12-01 13:26:10,590] DEBUG Garbage collecting 'quickstart-events-0' (kafka.log.LogManager) [2023-12-01 13:26:10,590] DEBUG Checking if flush is needed on quickstart-events flush interval 9223372036854775807 last flushed 1701419140563 time since last flush: 30026 (kafka.log.LogManager) [2023-12-01 13:26:10,590] DEBUG Checking if flush is needed on version flush interval 9223372036854775807 last flushed 1701419140580 time since last flush: 30010 (kafka.log.LogManager) [2023-12-01 13:26:10,590] DEBUG Checking if flush is needed on newnew flush interval 9223372036854775807 last flushed 1701419164093 time since last flush: 6497 (kafka.log.LogManager) [2023-12-01 13:26:10,594] DEBUG Garbage collecting 'version-2' (kafka.log.LogManager) [2023-12-01 13:26:10,594] DEBUG Garbage collecting 'newnew-0' (kafka.log.LogManager) [2023-12-01 13:26:10,595] DEBUG Log cleanup completed. 0 files deleted in 0 seconds (kafka.log.LogManager) [2023-12-01 13:26:10,996] DEBUG [SocketServer listenerType=ZK_BROKER, nodeId=0] Connection with /0:0:0:0:0:0:0:1 (channelId=0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0) disconnected (org.apache.kafka.common.network.Selector) java.io.EOFException at org.apache.kafka.common.network.NetworkReceive.readFrom(NetworkReceive.java:86) at org.apache.kafka.common.network.KafkaChannel.receive(KafkaChannel.java:452) at org.apache.kafka.common.network.KafkaChannel.read(KafkaChannel.java:402) at org.apache.kafka.common.network.Selector.attemptRead(Selector.java:674) at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:576) at org.apache.kafka.common.network.Selector.poll(Selector.java:481) at kafka.network.Processor.poll(SocketServer.scala:1107) at kafka.network.Processor.run(SocketServer.scala:1011) at java.base/java.lang.Thread.run(Thread.java:829) [2023-12-01 13:26:16,103] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:16,104] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:16,104] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:16,104] DEBUG Got ping response for session id: 0x1000002184f0000 after 1ms. (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:22,109] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:22,110] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:22,110] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:22,110] DEBUG Got ping response for session id: 0x1000002184f0000 after 1ms. (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:28,117] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:28,117] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:28,117] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:28,118] DEBUG Got ping response for session id: 0x1000002184f0000 after 1ms. (org.apache.zookeeper.ClientCnxn) [2023-12-01 13:26:34,122] DEBUG Checking session 0x1000002184f0000 (org.apache.zookeeper.server.SessionTrackerImpl) [2023-12-01 13:26:34,123] DEBUG Processing request:: sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:34,123] DEBUG sessionid:0x1000002184f0000 type:ping cxid:0xfffffffffffffffe zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a (org.apache.zookeeper.server.FinalRequestProcessor) [2023-12-01 13:26:34,123] DEBUG Got ping response for session id: 0x1000002184f0000 after 1ms. (org.apache.zookeeper.ClientCnxn)
лог от момента запуска и включая одну отправку сообщения в топик newnew видно что топик создается - потом есть одна ошибка смысл которой пока не ясен [2023-12-01 13:26:10,996] DEBUG [SocketServer listenerType=ZK_BROKER, nodeId=0] Connection with /0:0:0:0:0:0:0:1 (channelId=0:0:0:0:0:0:0:1:9092-0:0:0:0:0:0:0:1:45848-0) disconnected (org.apache.kafka.common.network.Selector) java.io.EOFException at org.apache.kafka.common.network.NetworkReceive.readFrom(NetworkReceive.java:86) at org.apache.kafka.common.network.KafkaChannel.receive(KafkaChannel.java:452) at org.apache.kafka.common.network.KafkaChannel.read(KafkaChannel.java:402) at org.apache.kafka.common.network.Selector.attemptRead(Selector.java:674) at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:576) at org.apache.kafka.common.network.Selector.poll(Selector.java:481) at kafka.network.Processor.poll(SocketServer.scala:1107) at kafka.network.Processor.run(SocketServer.scala:1011) at java.base/java.lang.Thread.run(Thread.java:829)
при отправке сообщения из консоли в новый топик -также все срабатывает создается топик но этой ошибки нет
В логе контроллера есть тоже ошибка [2023-12-01 13:25:41,209] WARN [RequestSendThread controllerId=0] Controller 0's connection to broker Bahtiyar.:9092 (id: 0 rack: null) was unsuccessful (kafka.controller.RequestSendThread) java.io.IOException: Connection to Bahtiyar.:9092 (id: 0 rack: null) failed. at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:70) at kafka.controller.RequestSendThread.brokerReady(ControllerChannelManager.scala:298) at kafka.controller.RequestSendThread.doWork(ControllerChannelManager.scala:251) at org.apache.kafka.server.util.ShutdownableThread.run(ShutdownableThread.java:130)
Какая-то сетевая проблема может, пока не понимаю. Но при запуске с крафтом такого нет
Логи от компоненты создаются пустыми параметры устанавливаю
Как вариант, можно попробовать воспользоваться утилитами plumber (для отправки https://github.com/RPG-18/plumber/releases/tag/v1.7.1) offset explorer или akhq или даже conduktor - попробовать через них - отправить/получить сообщение, чтобы исключить сетевые проблемы, но это нужно делать с той же машины где и внешняя компонента 1с находится.
Странно что логи пустые - в журнале регистрации есть какие либо ошибки из разряда "Аварийное завершение компоненты..."?
если топики были созданы через скрипт kafka-topics.sh, удали эти топики и создай новые, меня логи увели в другую степь, я думал что проблема в взаимодействии кафки с зукипером, проявлялось тем что я вижу топики через offset explorer но открытие таблицы сопровождалось дикой задержкой, доходило до 30 секунд, в логах могли быть рандомные ошибки, после создания топика через offset explorer задержка ушла, а сообщения моментально стали писаться
Все хорошо работает если Кафка запущена без зукипера(крафт). Но когда запуская старую кафку с зукипером, ничего не происходит. Ни ошибки ни сообщений. Топик создается. Кто-то сталкивался с таким?