Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Duplicate
-
None
-
None
-
None
Description
Observed on Java 11: https://builds.apache.org/job/kafka-pr-jdk11-scala2.12/264/testReport/junit/org.apache.kafka.streams.integration/EosIntegrationTest/shouldNotViolateEosIfOneTaskFails/
at https://github.com/apache/kafka/pull/5795/commits/5bdcd0e023c6f406d585155399f6541bb6a9f9c2
stacktrace:
java.lang.AssertionError:
Expected: <[KeyValue(0, 0), KeyValue(0, 1), KeyValue(0, 2), KeyValue(0, 3), KeyValue(0, 4), KeyValue(0, 5), KeyValue(0, 6), KeyValue(0, 7), KeyValue(0, 8), KeyValue(0, 9)]>
but: was <[KeyValue(0, 0), KeyValue(0, 1), KeyValue(0, 2), KeyValue(0, 3), KeyValue(0, 4), KeyValue(0, 5), KeyValue(0, 6), KeyValue(0, 7), KeyValue(0, 8), KeyValue(0, 9), KeyValue(0, 10), KeyValue(0, 11), KeyValue(0, 12), KeyValue(0, 13), KeyValue(0, 14)]>
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:8)
at org.apache.kafka.streams.integration.EosIntegrationTest.checkResultPerKey(EosIntegrationTest.java:218)
at org.apache.kafka.streams.integration.EosIntegrationTest.shouldNotViolateEosIfOneTaskFails(EosIntegrationTest.java:360)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:106)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38)
at org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:66)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:117)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:155)
at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:137)
at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
at java.base/java.lang.Thread.run(Thread.java:834)
stdout:
[2018-10-24 20:46:01,159] INFO Registered kafka:type=kafka.Log4jController MBean (kafka.utils.Log4jControllerRegistration$:31) [2018-10-24 20:46:02,050] INFO Server environment:zookeeper.version=3.4.13-2d71af4dbe22557fda74f9a9b4309b15a7487f03, built on 06/29/2018 00:39 GMT (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,062] INFO Server environment:host.name=pomona.apache.org (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,065] INFO Server environment:java.version=11 (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,069] INFO Server environment:java.vendor=Oracle Corporation (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,096] INFO Server environment:java.home=/usr/local/asfpackages/java/jdk-11-ea+28 (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,108] INFO Server environment:java.class.path=/home/jenkins/.gradle/caches/4.10.2/workerMain/gradle-worker.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/classes/java/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/resources/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/classes/java/main:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/resources/main:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/test-utils/build/libs/kafka-streams-test-utils-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/clients/build/classes/java/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/clients/build/resources/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/classes/java/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/classes/scala/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/resources/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/libs/kafka-streams-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/libs/kafka_2.11-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/connect/json/build/libs/connect-json-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/connect/api/build/libs/connect-api-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/clients/build/libs/kafka-clients-2.2.0-SNAPSHOT.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-log4j12/1.7.25/110cefe2df103412849d72ef7a67e4e91e4266b4/slf4j-log4j12-1.7.25.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.yammer.metrics/metrics-core/2.2.0/f82c035cfa786d3cbec362c38c22a5f5b1bc8724/metrics-core-2.2.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.typesafe.scala-logging/scala-logging_2.11/3.9.0/e0dba06b4a763a0e2208182b264421baedbb0df/scala-logging_2.11-3.9.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.101tec/zkclient/0.10/c54d4b5a5e89af75a80b6d5857400165ce5188d0/zkclient-0.10.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.apache.zookeeper/zookeeper/3.4.13/31e9937541cef95c4585b547eb2dbd34d3a76f1c/zookeeper-3.4.13.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-api/1.7.25/da76ca59f6a57ee3102f8f9bd9cee742973efa8a/slf4j-api-1.7.25.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.rocksdb/rocksdbjni/5.14.2/a6087318fab540ba0b4c6ff68475ffbedc0b3d10/rocksdbjni-5.14.2.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/log4j/log4j/1.2.17/5af35056b4d257e4b64b9e8069c0746e8b08629f/log4j-1.2.17.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/junit/junit/4.12/2973d150c0dc1fefe998f834810d68f278ea58ec/junit-4.12.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.easymock/easymock/3.6/276883daaf2230e6f1e07c78ad695d2a18c7170b/easymock-3.6.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.bouncycastle/bcpkix-jdk15on/1.60/d0c46320fbc07be3a24eb13a56cee4e3d38e0c75/bcpkix-jdk15on-1.60.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.hamcrest/hamcrest-all/1.3/63a21ebc981131004ad02e0434e799fd7f3a8d5a/hamcrest-all-1.3.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.github.luben/zstd-jni/1.3.5-4/550b6393a007d0867c98611ca8cfbcf53f2eb991/zstd-jni-1.3.5-4.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.lz4/lz4-java/1.5.0/d36fb639f06aaa4f17307625f80e2e32f815672a/lz4-java-1.5.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.xerial.snappy/snappy-java/1.1.7.2/307b286efd119ad2c6d4291128bf110bddc68088/snappy-java-1.1.7.2.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-databind/2.9.7/e6faad47abd3179666e89068485a1b88a195ceb7/jackson-databind-2.9.7.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/net.sf.jopt-simple/jopt-simple/5.0.4/4fdac2fbe92dfad86aa6e9301736f6b4342a3f5c/jopt-simple-5.0.4.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.scala-lang/scala-reflect/2.11.12/2bb23c13c527566d9828107ca4108be2a2c06f01/scala-reflect-2.11.12.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.scala-lang/scala-library/2.11.12/bf5534e6fec3d665bd6419c952a929a8bdd4b591/scala-library-2.11.12.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.hamcrest/hamcrest-core/1.3/42a25dc3219429f0e5d060061f71acb49bf010a0/hamcrest-core-1.3.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.objenesis/objenesis/2.6/639033469776fd37c08358c6b92a4761feb2af4b/objenesis-2.6.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.bouncycastle/bcprov-jdk15on/1.60/bd47ad3bd14b8e82595c7adaa143501e60842a84/bcprov-jdk15on-1.60.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/javax.ws.rs/javax.ws.rs-api/2.1.1/d3466bc9321fe84f268a1adb3b90373fc14b0eb5/javax.ws.rs-api-2.1.1.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-annotations/2.9.0/7c10d545325e3a6e72e06381afe469fd40eb701/jackson-annotations-2.9.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-core/2.9.7/4b7f0e0dc527fab032e9800ed231080fdc3ac015/jackson-core-2.9.7.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.apache.yetus/audience-annotations/0.5.0/55762d3191a8d6610ef46d11e8cb70c7667342a3/audience-annotations-0.5.0.jar (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,139] INFO Server environment:java.library.path=/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,139] INFO Server environment:java.io.tmpdir=/tmp (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,140] INFO Server environment:java.compiler=<NA> (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,140] INFO Server environment:os.name=Linux (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,141] INFO Server environment:os.arch=amd64 (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,141] INFO Server environment:os.version=4.4.0-131-generic (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,198] INFO Server environment:user.name=jenkins (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,199] INFO Server environment:user.home=/home/jenkins (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,199] INFO Server environment:user.dir=/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams (org.apache.zookeeper.server.ZooKeeperServer:100) [2018-10-24 20:46:02,907] INFO Created server with tickTime 500 minSessionTimeout 1000 maxSessionTimeout 10000 datadir /tmp/kafka-5445914688767705662/version-2 snapdir /tmp/kafka-5717242095947966084/version-2 (org.apache.zookeeper.server.ZooKeeperServer:174) [2018-10-24 20:46:03,165] INFO binding to port /127.0.0.1:0 (org.apache.zookeeper.server.NIOServerCnxnFactory:89) [2018-10-24 20:46:07,375] INFO KafkaConfig values: advertised.host.name = null advertised.listeners = null advertised.port = null alter.config.policy.class.name = null alter.log.dirs.replication.quota.window.num = 11 alter.log.dirs.replication.quota.window.size.seconds = 1 authorizer.class.name = auto.create.topics.enable = false auto.leader.rebalance.enable = true background.threads = 10 broker.id = 0 broker.id.generation.enable = true broker.rack = null client.quota.callback.class = null compression.type = producer connection.failed.authentication.delay.ms = 100 connections.max.idle.ms = 600000 controlled.shutdown.enable = true controlled.shutdown.max.retries = 3 controlled.shutdown.retry.backoff.ms = 5000 controller.socket.timeout.ms = 30000 create.topic.policy.class.name = null default.replication.factor = 1 delegation.token.expiry.check.interval.ms = 3600000 delegation.token.expiry.time.ms = 86400000 delegation.token.master.key = null delegation.token.max.lifetime.ms = 604800000 delete.records.purgatory.purge.interval.requests = 1 delete.topic.enable = true fetch.purgatory.purge.interval.requests = 1000 group.initial.rebalance.delay.ms = 0 group.max.session.timeout.ms = 300000 group.min.session.timeout.ms = 0 host.name = localhost inter.broker.listener.name = null inter.broker.protocol.version = 2.1-IV2 kafka.metrics.polling.interval.secs = 10 kafka.metrics.reporters = [] leader.imbalance.check.interval.seconds = 300 leader.imbalance.per.broker.percentage = 10 listener.security.protocol.map = PLAINTEXT:PLAINTEXT,SSL:SSL,SASL_PLAINTEXT:SASL_PLAINTEXT,SASL_SSL:SASL_SSL listeners = null log.cleaner.backoff.ms = 15000 log.cleaner.dedupe.buffer.size = 2097152 log.cleaner.delete.retention.ms = 86400000 log.cleaner.enable = true log.cleaner.io.buffer.load.factor = 0.9 log.cleaner.io.buffer.size = 524288 log.cleaner.io.max.bytes.per.second = 1.7976931348623157E308 log.cleaner.min.cleanable.ratio = 0.5 log.cleaner.min.compaction.lag.ms = 0 log.cleaner.threads = 1 log.cleanup.policy = [delete] log.dir = /tmp/junit4976877634517730742/junit7458939386316814886 log.dirs = null log.flush.interval.messages = 9223372036854775807 log.flush.interval.ms = null log.flush.offset.checkpoint.interval.ms = 60000 log.flush.scheduler.interval.ms = 9223372036854775807 log.flush.start.offset.checkpoint.interval.ms = 60000 log.index.interval.bytes = 4096 log.index.size.max.bytes = 10485760 log.message.downconversion.enable = true log.message.format.version = 2.1-IV2 log.message.timestamp.difference.max.ms = 9223372036854775807 log.message.timestamp.type = CreateTime log.preallocate = false log.retention.bytes = -1 log.retention.check.interval.ms = 300000 log.retention.hours = 168 log.retention.minutes = null log.retention.ms = null log.roll.hours = 168 log.roll.jitter.hours = 0 log.roll.jitter.ms = null log.roll.ms = null log.segment.bytes = 1073741824 log.segment.delete.delay.ms = 60000 max.connections.per.ip = 2147483647 max.connections.per.ip.overrides = max.incremental.fetch.session.cache.slots = 1000 message.max.bytes = 1000000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 min.insync.replicas = 1 num.io.threads = 8 num.network.threads = 3 num.partitions = 1 num.recovery.threads.per.data.dir = 1 num.replica.alter.log.dirs.threads = null num.replica.fetchers = 1 offset.metadata.max.bytes = 4096 offsets.commit.required.acks = -1 offsets.commit.timeout.ms = 5000 offsets.load.buffer.size = 5242880 offsets.retention.check.interval.ms = 600000 offsets.retention.minutes = 10080 offsets.topic.compression.codec = 0 offsets.topic.num.partitions = 50 offsets.topic.replication.factor = 1 offsets.topic.segment.bytes = 104857600 password.encoder.cipher.algorithm = AES/CBC/PKCS5Padding password.encoder.iterations = 4096 password.encoder.key.length = 128 password.encoder.keyfactory.algorithm = null password.encoder.old.secret = null password.encoder.secret = null port = 0 principal.builder.class = null producer.purgatory.purge.interval.requests = 1000 queued.max.request.bytes = -1 queued.max.requests = 500 quota.consumer.default = 9223372036854775807 quota.producer.default = 9223372036854775807 quota.window.num = 11 quota.window.size.seconds = 1 replica.fetch.backoff.ms = 1000 replica.fetch.max.bytes = 1048576 replica.fetch.min.bytes = 1 replica.fetch.response.max.bytes = 10485760 replica.fetch.wait.max.ms = 500 replica.high.watermark.checkpoint.interval.ms = 5000 replica.lag.time.max.ms = 10000 replica.socket.receive.buffer.bytes = 65536 replica.socket.timeout.ms = 30000 replication.quota.window.num = 11 replication.quota.window.size.seconds = 1 request.timeout.ms = 30000 reserved.broker.max.id = 1000 sasl.client.callback.handler.class = null sasl.enabled.mechanisms = [GSSAPI] sasl.jaas.config = null sasl.kerberos.kinit.cmd = /usr/bin/kinit sasl.kerberos.min.time.before.relogin = 60000 sasl.kerberos.principal.to.local.rules = [DEFAULT] sasl.kerberos.service.name = null sasl.kerberos.ticket.renew.jitter = 0.05 sasl.kerberos.ticket.renew.window.factor = 0.8 sasl.login.callback.handler.class = null sasl.login.class = null sasl.login.refresh.buffer.seconds = 300 sasl.login.refresh.min.period.seconds = 60 sasl.login.refresh.window.factor = 0.8 sasl.login.refresh.window.jitter = 0.05 sasl.mechanism.inter.broker.protocol = GSSAPI sasl.server.callback.handler.class = null security.inter.broker.protocol = PLAINTEXT socket.receive.buffer.bytes = 102400 socket.request.max.bytes = 104857600 socket.send.buffer.bytes = 102400 ssl.cipher.suites = [] ssl.client.auth = none ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = https ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS transaction.abort.timed.out.transaction.cleanup.interval.ms = 60000 transaction.max.timeout.ms = 900000 transaction.remove.expired.transaction.cleanup.interval.ms = 3600000 transaction.state.log.load.buffer.size = 5242880 transaction.state.log.min.isr = 2 transaction.state.log.num.partitions = 50 transaction.state.log.replication.factor = 3 transaction.state.log.segment.bytes = 104857600 transactional.id.expiration.ms = 604800000 unclean.leader.election.enable = false zookeeper.connect = 127.0.0.1:37661 zookeeper.connection.timeout.ms = null zookeeper.max.in.flight.requests = 10 zookeeper.session.timeout.ms = 10000 zookeeper.set.acl = false zookeeper.sync.time.ms = 2000 (kafka.server.KafkaConfig:279) [2018-10-24 20:46:09,333] INFO starting (kafka.server.KafkaServer:66) [2018-10-24 20:46:09,378] INFO Connecting to zookeeper on 127.0.0.1:37661 (kafka.server.KafkaServer:66) [2018-10-24 20:46:09,839] INFO [ZooKeeperClient] Initializing a new session to 127.0.0.1:37661. (kafka.zookeeper.ZooKeeperClient:66) [2018-10-24 20:46:09,946] INFO Client environment:zookeeper.version=3.4.13-2d71af4dbe22557fda74f9a9b4309b15a7487f03, built on 06/29/2018 00:39 GMT (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:09,947] INFO Client environment:host.name=pomona.apache.org (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:09,952] INFO Client environment:java.version=11 (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:09,953] INFO Client environment:java.vendor=Oracle Corporation (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:09,989] INFO Client environment:java.home=/usr/local/asfpackages/java/jdk-11-ea+28 (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:09,994] INFO Client environment:java.class.path=/home/jenkins/.gradle/caches/4.10.2/workerMain/gradle-worker.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/classes/java/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/resources/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/classes/java/main:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/resources/main:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/test-utils/build/libs/kafka-streams-test-utils-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/clients/build/classes/java/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/clients/build/resources/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/classes/java/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/classes/scala/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/resources/test:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams/build/libs/kafka-streams-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/core/build/libs/kafka_2.11-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/connect/json/build/libs/connect-json-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/connect/api/build/libs/connect-api-2.2.0-SNAPSHOT.jar:/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/clients/build/libs/kafka-clients-2.2.0-SNAPSHOT.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-log4j12/1.7.25/110cefe2df103412849d72ef7a67e4e91e4266b4/slf4j-log4j12-1.7.25.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.yammer.metrics/metrics-core/2.2.0/f82c035cfa786d3cbec362c38c22a5f5b1bc8724/metrics-core-2.2.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.typesafe.scala-logging/scala-logging_2.11/3.9.0/e0dba06b4a763a0e2208182b264421baedbb0df/scala-logging_2.11-3.9.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.101tec/zkclient/0.10/c54d4b5a5e89af75a80b6d5857400165ce5188d0/zkclient-0.10.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.apache.zookeeper/zookeeper/3.4.13/31e9937541cef95c4585b547eb2dbd34d3a76f1c/zookeeper-3.4.13.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.slf4j/slf4j-api/1.7.25/da76ca59f6a57ee3102f8f9bd9cee742973efa8a/slf4j-api-1.7.25.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.rocksdb/rocksdbjni/5.14.2/a6087318fab540ba0b4c6ff68475ffbedc0b3d10/rocksdbjni-5.14.2.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/log4j/log4j/1.2.17/5af35056b4d257e4b64b9e8069c0746e8b08629f/log4j-1.2.17.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/junit/junit/4.12/2973d150c0dc1fefe998f834810d68f278ea58ec/junit-4.12.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.easymock/easymock/3.6/276883daaf2230e6f1e07c78ad695d2a18c7170b/easymock-3.6.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.bouncycastle/bcpkix-jdk15on/1.60/d0c46320fbc07be3a24eb13a56cee4e3d38e0c75/bcpkix-jdk15on-1.60.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.hamcrest/hamcrest-all/1.3/63a21ebc981131004ad02e0434e799fd7f3a8d5a/hamcrest-all-1.3.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.github.luben/zstd-jni/1.3.5-4/550b6393a007d0867c98611ca8cfbcf53f2eb991/zstd-jni-1.3.5-4.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.lz4/lz4-java/1.5.0/d36fb639f06aaa4f17307625f80e2e32f815672a/lz4-java-1.5.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.xerial.snappy/snappy-java/1.1.7.2/307b286efd119ad2c6d4291128bf110bddc68088/snappy-java-1.1.7.2.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-databind/2.9.7/e6faad47abd3179666e89068485a1b88a195ceb7/jackson-databind-2.9.7.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/net.sf.jopt-simple/jopt-simple/5.0.4/4fdac2fbe92dfad86aa6e9301736f6b4342a3f5c/jopt-simple-5.0.4.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.scala-lang/scala-reflect/2.11.12/2bb23c13c527566d9828107ca4108be2a2c06f01/scala-reflect-2.11.12.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.scala-lang/scala-library/2.11.12/bf5534e6fec3d665bd6419c952a929a8bdd4b591/scala-library-2.11.12.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.hamcrest/hamcrest-core/1.3/42a25dc3219429f0e5d060061f71acb49bf010a0/hamcrest-core-1.3.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.objenesis/objenesis/2.6/639033469776fd37c08358c6b92a4761feb2af4b/objenesis-2.6.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.bouncycastle/bcprov-jdk15on/1.60/bd47ad3bd14b8e82595c7adaa143501e60842a84/bcprov-jdk15on-1.60.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/javax.ws.rs/javax.ws.rs-api/2.1.1/d3466bc9321fe84f268a1adb3b90373fc14b0eb5/javax.ws.rs-api-2.1.1.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-annotations/2.9.0/7c10d545325e3a6e72e06381afe469fd40eb701/jackson-annotations-2.9.0.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/com.fasterxml.jackson.core/jackson-core/2.9.7/4b7f0e0dc527fab032e9800ed231080fdc3ac015/jackson-core-2.9.7.jar:/home/jenkins/.gradle/caches/modules-2/files-2.1/org.apache.yetus/audience-annotations/0.5.0/55762d3191a8d6610ef46d11e8cb70c7667342a3/audience-annotations-0.5.0.jar (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:09,996] INFO Client environment:java.library.path=/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:09,996] INFO Client environment:java.io.tmpdir=/tmp (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,005] INFO Client environment:java.compiler=<NA> (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,011] INFO Client environment:os.name=Linux (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,021] INFO Client environment:os.arch=amd64 (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,023] INFO Client environment:os.version=4.4.0-131-generic (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,050] INFO Client environment:user.name=jenkins (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,066] INFO Client environment:user.home=/home/jenkins (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,067] INFO Client environment:user.dir=/home/jenkins/jenkins-slave/workspace/kafka-pr-jdk11-scala2.12/streams (org.apache.zookeeper.ZooKeeper:100) [2018-10-24 20:46:10,146] INFO Initiating client connection, connectString=127.0.0.1:37661 sessionTimeout=10000 watcher=kafka.zookeeper.ZooKeeperClient$ZooKeeperClientWatcher$@2047e9c3 (org.apache.zookeeper.ZooKeeper:442) [2018-10-24 20:46:10,446] INFO [ZooKeeperClient] Waiting until connected. (kafka.zookeeper.ZooKeeperClient:66) [2018-10-24 20:46:10,462] INFO Opening socket connection to server localhost/127.0.0.1:37661. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn:1029) [2018-10-24 20:46:10,540] INFO Socket connection established to localhost/127.0.0.1:37661, initiating session (org.apache.zookeeper.ClientCnxn:879) [2018-10-24 20:46:10,610] INFO Accepted socket connection from /127.0.0.1:34504 (org.apache.zookeeper.server.NIOServerCnxnFactory:215) [2018-10-24 20:46:10,676] INFO Client attempting to establish new session at /127.0.0.1:34504 (org.apache.zookeeper.server.ZooKeeperServer:949) [2018-10-24 20:46:10,694] INFO Creating new log file: log.1 (org.apache.zookeeper.server.persistence.FileTxnLog:213) [2018-10-24 20:46:10,865] INFO Session establishment complete on server localhost/127.0.0.1:37661, sessionid = 0x101d8d0842e0000, negotiated timeout = 10000 (org.apache.zookeeper.ClientCnxn:1303) [2018-10-24 20:46:10,867] INFO Established session 0x101d8d0842e0000 with negotiated timeout 10000 for client /127.0.0.1:34504 (org.apache.zookeeper.server.ZooKeeperServer:694) [2018-10-24 20:46:10,885] INFO [ZooKeeperClient] Connected. (kafka.zookeeper.ZooKeeperClient:66) [2018-10-24 20:46:11,650] INFO Got user-level KeeperException when processing sessionid:0x101d8d0842e0000 type:create cxid:0x2 zxid:0x3 txntype:-1 reqpath:n/a Error Path:/brokers Error:KeeperErrorCode = NoNode for /brokers (org.apache.zookeeper.server.PrepRequestProcessor:653) [2018-10-24 20:46:11,702] INFO Got user-level KeeperException when processing sessionid:0x101d8d0842e0000 type:create cxid:0x6 zxid:0x7 txntype:-1 reqpath:n/a Error Path:/config Error:KeeperErrorCode = NoNode for /config (org.apache.zookeeper.server.PrepRequestProcessor:653) [2018-10-24 20:46:11,769] INFO Got user-level KeeperException when processing sessionid:0x101d8d0842e0000 type:create cxid:0x9 zxid:0xa txntype:-1 reqpath:n/a Error Path:/admin Error:KeeperErrorCode = NoNode for /admin (org.apache.zookeeper.server.PrepRequestProcessor:653) [2018-10-24 20:46:14,506] INFO Got user-level KeeperException when processing sessionid:0x101d8d0842e0000 type:create cxid:0x15 zxid:0x15 txntype:-1 reqpath:n/a Error Path:/cluster Error:KeeperErrorCode = NoNode for /cluster (org.apache.zookeeper.server.PrepRequestProcessor:653) [2018-10-24 20:46:14,540] INFO Cluster ID = JLuWfH-lTV6_a7vcbPbBvw (kafka.server.KafkaServer:66) [2018-10-24 20:46:14,567] WARN No meta.properties file under dir /tmp/junit4976877634517730742/junit7458939386316814886/meta.properties (kafka.server.BrokerMetadataCheckpoint:70) [2018-10-24 20:46:15,239] INFO KafkaConfig values: advertised.host.name = null advertised.listeners = null advertised.port = null alter.config.policy.class.name = null alter.log.dirs.replication.quota.window.num = 11 alter.log.dirs.replication.quota.window.size.seconds = 1 authorizer.class.name = auto.create.topics.enable = false auto.leader.rebalance.enable = true background.threads = 10 broker.id = 0 broker.id.generation.enable = true broker.rack = null client.quota.callback.class = null compression.type = producer connection.failed.authentication.delay.ms = 100 connections.max.idle.ms = 600000 controlled.shutdown.enable = true controlled.shutdown.max.retries = 3 controlled.shutdown.retry.backoff.ms = 5000 controller.socket.timeout.ms = 30000 create.topic.policy.class.name = null default.replication.factor = 1 delegation.token.expiry.check.interval.ms = 3600000 delegation.token.expiry.time.ms = 86400000 delegation.token.master.key = null delegation.token.max.lifetime.ms = 604800000 delete.records.purgatory.purge.interval.requests = 1 delete.topic.enable = true fetch.purgatory.purge.interval.requests = 1000 group.initial.rebalance.delay.ms = 0 group.max.session.timeout.ms = 300000 group.min.session.timeout.ms = 0 host.name = localhost inter.broker.listener.name = null inter.broker.protocol.version = 2.1-IV2 kafka.metrics.polling.interval.secs = 10 kafka.metrics.reporters = [] leader.imbalance.check.interval.seconds = 300 leader.imbalance.per.broker.percentage = 10 listener.security.protocol.map = PLAINTEXT:PLAINTEXT,SSL:SSL,SASL_PLAINTEXT:SASL_PLAINTEXT,SASL_SSL:SASL_SSL listeners = null log.cleaner.backoff.ms = 15000 log.cleaner.dedupe.buffer.size = 2097152 log.cleaner.delete.retention.ms = 86400000 log.cleaner.enable = true log.cleaner.io.buffer.load.factor = 0.9 log.cleaner.io.buffer.size = 524288 log.cleaner.io.max.bytes.per.second = 1.7976931348623157E308 log.cleaner.min.cleanable.ratio = 0.5 log.cleaner.min.compaction.lag.ms = 0 log.cleaner.threads = 1 log.cleanup.policy = [delete] log.dir = /tmp/junit4976877634517730742/junit7458939386316814886 log.dirs = null log.flush.interval.messages = 9223372036854775807 log.flush.interval.ms = null log.flush.offset.checkpoint.interval.ms = 60000 log.flush.scheduler.interval.ms = 9223372036854775807 log.flush.start.offset.checkpoint.interval.ms = 60000 log.index.interval.bytes = 4096 log.index.size.max.bytes = 10485760 log.message.downconversion.enable = true log.message.format.version = 2.1-IV2 log.message.timestamp.difference.max.ms = 9223372036854775807 log.message.timestamp.type = CreateTime log.preallocate = false log.retention.bytes = -1 log.retention.check.interval.ms = 300000 log.retention.hours = 168 log.retention.minutes = null log.retention.ms = null log.roll.hours = 168 log.roll.jitter.hours = 0 log.roll.jitter.ms = null log.roll.ms = null log.segment.bytes = 1073741824 log.segment.delete.delay.ms = 60000 max.connections.per.ip = 2147483647 max.connections.per.ip.overrides = max.incremental.fetch.session.cache.slots = 1000 message.max.bytes = 1000000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 min.insync.replicas = 1 num.io.threads = 8 num.network.threads = 3 num.partitions = 1 num.recovery.threads.per.data.dir = 1 num.replica.alter.log.dirs.threads = null num.replica.fetchers = 1 offset.metadata.max.bytes = 4096 offsets.commit.required.acks = -1 offsets.commit.timeout.ms = 5000 offsets.load.buffer.size = 5242880 offsets.retention.check.interval.ms = 600000 offsets.retention.minutes = 10080 offsets.topic.compression.codec = 0 offsets.topic.num.partitions = 50 offsets.topic.replication.factor = 1 offsets.topic.segment.bytes = 104857600 password.encoder.cipher.algorithm = AES/CBC/PKCS5Padding password.encoder.iterations = 4096 password.encoder.key.length = 128 password.encoder.keyfactory.algorithm = null password.encoder.old.secret = null password.encoder.secret = null port = 0 principal.builder.class = null producer.purgatory.purge.interval.requests = 1000 queued.max.request.bytes = -1 queued.max.requests = 500 quota.consumer.default = 9223372036854775807 quota.producer.default = 9223372036854775807 quota.window.num = 11 quota.window.size.seconds = 1 replica.fetch.backoff.ms = 1000 replica.fetch.max.bytes = 1048576 replica.fetch.min.bytes = 1 replica.fetch.response.max.bytes = 10485760 replica.fetch.wait.max.ms = 500 replica.high.watermark.checkpoint.interval.ms = 5000 replica.lag.time.max.ms = 10000 replica.socket.receive.buffer.bytes = 65536 replica.socket.timeout.ms = 30000 replication.quota.window.num = 11 replication.quota.window.size.seconds = 1 request.timeout.ms = 30000 reserved.broker.max.id = 1000 sasl.client.callback.handler.class = null sasl.enabled.mechanisms = [GSSAPI] sasl.jaas.config = null sasl.kerberos.kinit.cmd = /usr/bin/kinit sasl.kerberos.min.time.before.relogin = 60000 sasl.kerberos.principal.to.local.rules = [DEFAULT] sasl.kerberos.service.name = null sasl.kerberos.ticket.renew.jitter = 0.05 sasl.kerberos.ticket.renew.window.factor = 0.8 sasl.login.callback.handler.class = null sasl.login.class = null sasl.login.refresh.buffer.seconds = 300 sasl.login.refresh.min.period.seconds = 60 sasl.login.refresh.window.factor = 0.8 sasl.login.refresh.window.jitter = 0.05 sasl.mechanism.inter.broker.protocol = GSSAPI sasl.server.callback.handler.class = null security.inter.broker.protocol = PLAINTEXT socket.receive.buffer.bytes = 102400 socket.request.max.bytes = 104857600 socket.send.buffer.bytes = 102400 ssl.cipher.suites = [] ssl.client.auth = none ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = https ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS transaction.abort.timed.out.transaction.cleanup.interval.ms = 60000 transaction.max.timeout.ms = 900000 transaction.remove.expired.transaction.cleanup.interval.ms = 3600000 transaction.state.log.load.buffer.size = 5242880 transaction.state.log.min.isr = 2 transaction.state.log.num.partitions = 50 transaction.state.log.replication.factor = 3 transaction.state.log.segment.bytes = 104857600 transactional.id.expiration.ms = 604800000 unclean.leader.election.enable = false zookeeper.connect = 127.0.0.1:37661 zookeeper.connection.timeout.ms = null zookeeper.max.in.flight.requests = 10 zookeeper.session.timeout.ms = 10000 zookeeper.set.acl = false zookeeper.sync.time.ms = 2000 (kafka.server.KafkaConfig:279) [2018-10-24 20:46:15,414] INFO KafkaConfig values: advertised.host.name = null advertised.listeners = null advertised.port = null alter.config.policy.class.name = null alter.log.dirs.replication.quota.window.num = 11 alter.log.dirs.replication.quota.window.size.seconds = 1 authorizer.class.name = auto.create.topics.enable = false auto.leader.rebalance.enable = true background.threads = 10 broker.id = 0 broker.id.generation.enable = true broker.rack = null client.quota.callback.class = null compression.type = producer connection.failed.authentication.delay.ms = 100 connections.max.idle.ms = 600000 controlled.shutdown.enable = true controlled.shutdown.max.retries = 3 controlled.shutdown.retry.backoff.ms = 5000 controller.socket.timeout.ms = 30000 create.topic.policy.class.name = null default.replication.factor = 1 delegation.token.expiry.check.interval.ms = 3600000 delegation.token.expiry.time.ms = 86400000 delegation.token.master.key = null delegation.token.max.lifetime.ms = 604800000 delete.records.purgatory.purge.interval.requests = 1 delete.topic.enable = true fetch.purgatory.purge.interval.requests = 1000 group.initial.rebalance.delay.ms = 0 group.max.session.timeout.ms = 300000 group.min.session.timeout.ms = 0 host.name = localhost inter.broker.listener.name = null inter.broker.protocol.version = 2.1-IV2 kafka.metrics.polling.interval.secs = 10 kafka.metrics.reporters = [] leader.imbalance.check.interval.seconds = 300 leader.imbalance.per.broker.percentage = 10 listener.security.protocol.map = PLAINTEXT:PLAINTEXT,SSL:SSL,SASL_PLAINTEXT:SASL_PLAINTEXT,SASL_SSL:SASL_SSL listeners = null log.cleaner.backoff.ms = 15000 log.cleaner.dedupe.buffer.size = 2097152 log.cleaner.delete.retention.ms = 86400000 log.cleaner.enable = true log.cleaner.io.buffer.load.factor = 0.9 log.cleaner.io.buffer.size = 524288 log.cleaner.io.max.bytes.per.second = 1.7976931348623157E308 log.cleaner.min.cleanable.ratio = 0.5 log.cleaner.min.compaction.lag.ms = 0 log.cleaner.threads = 1 log.cleanup.policy = [delete] log.dir = /tmp/junit4976877634517730742/junit7458939386316814886 log.dirs = null log.flush.interval.messages = 9223372036854775807 log.flush.interval.ms = null log.flush.offset.checkpoint.interval.ms = 60000 log.flush.scheduler.interval.ms = 9223372036854775807 log.flush.start.offset.checkpoint.interval.ms = 60000 log.index.interval.bytes = 4096 log.index.size.max.bytes = 10485760 log.message.downconversion.enable = true log.message.format.version = 2.1-IV2 log.message.timestamp.difference.max.ms = 9223372036854775807 log.message.timestamp.type = CreateTime log.preallocate = false log.retention.bytes = -1 log.retention.check.interval.ms = 300000 log.retention.hours = 168 log.retention.minutes = null log.retention.ms = null log.roll.hours = 168 log.roll.jitter.hours = 0 log.roll.jitter.ms = null log.roll.ms = null log.segment.bytes = 1073741824 log.segment.delete.delay.ms = 60000 max.connections.per.ip = 2147483647 max.connections.per.ip.overrides = max.incremental.fetch.session.cache.slots = 1000 message.max.bytes = 1000000 metric.reporters = [] metrics.num.samples = 2 metrics.recording.level = INFO metrics.sample.window.ms = 30000 min.insync.replicas = 1 num.io.threads = 8 num.network.threads = 3 num.partitions = 1 num.recovery.threads.per.data.dir = 1 num.replica.alter.log.dirs.threads = null num.replica.fetchers = 1 offset.metadata.max.bytes = 4096 offsets.commit.required.acks = -1 offsets.commit.timeout.ms = 5000 offsets.load.buffer.size = 5242880 offsets.retention.check.interval.ms = 600000 offsets.retention.minutes = 10080 offsets.topic.compression.codec = 0 offsets.topic.num.partitions = 50 offsets.topic.replication.factor = 1 offsets.topic.segment.bytes = 104857600 password.encoder.cipher.algorithm = AES/CBC/PKCS5Padding password.encoder.iterations = 4096 password.encoder.key.length = 128 password.encoder.keyfactory.algorithm = null password.encoder.old.secret = null password.encoder.secret = null port = 0 principal.builder.class = null producer.purgatory.purge.interval.requests = 1000 queued.max.request.bytes = -1 queued.max.requests = 500 quota.consumer.default = 9223372036854775807 quota.producer.default = 9223372036854775807 quota.window.num = 11 quota.window.size.seconds = 1 replica.fetch.backoff.ms = 1000 replica.fetch.max.bytes = 1048576 replica.fetch.min.bytes = 1 replica.fetch.response.max.bytes = 10485760 replica.fetch.wait.max.ms = 500 replica.high.watermark.checkpoint.interval.ms = 5000 replica.lag.time.max.ms = 10000 replica.socket.receive.buffer.bytes = 65536 replica.socket.timeout.ms = 30000 replication.quota.window.num = 11 replication.quota.window.size.seconds = 1 request.timeout.ms = 30000 reserved.broker.max.id = 1000 sasl.client.callback.handler.class = null sasl.enabled.mechanisms = [GSSAPI] sasl.jaas.config = null sasl.kerberos.kinit.cmd = /usr/bin/kinit sasl.kerberos.min.time.before.relogin = 60000 sasl.kerberos.principal.to.local.rules = [DEFAULT] sasl.kerberos.service.name = null sasl.kerberos.ticket.renew.jitter = 0.05 sasl.kerberos.ticket.renew.window.factor = 0.8 sasl.login.callback.handler.class = null sasl.login.class = null sasl.login.refresh.buffer.seconds = 300 sasl.login.refresh.min.period.seconds = 60 sasl.login.refresh.window.factor = 0.8 sasl.login.refresh.window.jitter = 0.05 sasl.mechanism.inter.broker.protocol = GSSAPI sasl.server.callback.handler.class = null security.inter.broker.protocol = PLAINTEXT socket.receive.buffer.bytes = 102400 socket.request.max.bytes = 104857600 socket.send.buffer.bytes = 102400 ssl.cipher.suites = [] ssl.client.auth = none ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1] ssl.endpoint.identification.algorithm = https ssl.key.password = null ssl.keymanager.algorithm = SunX509 ssl.keystore.location = null ssl.keystore.password = null ssl.keystore.type = JKS ssl.protocol = TLS ssl.provider = null ssl.secure.random.implementation = null ssl.trustmanager.algorithm = PKIX ssl.truststore.location = null ssl.truststore.password = null ssl.truststore.type = JKS transaction.abort.timed.out.transaction.cleanup.interval.ms = 60000 transaction.max.timeout.ms = 900000 transaction.remove.expired.transaction.cleanup.interval.ms = 3600000 transaction.state.log.load.buffer.size = 5242880 transaction.state.log.min.isr = 2 transaction.state.log.num.partitions = 50 transaction.state.log.replication.factor = 3 transaction.state.log.segment.bytes = 104857600 transactional.id.expiration.ms = 604800000 unclean.leader.election.enable = false zookeeper.connect = 127.0.0.1:37661 zookeeper.connection.timeout.ms = null zookeeper.max.in.flight.requests = 10 zookeeper.session.timeout.ms = 10000 zookeeper.set.acl = false zookeeper.sync.time.ms = 2000 (kafka.server.KafkaConfig:279) [2018-10-24 20:46:15,796] INFO [ThrottledChannelReaper-Fetch]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:46:15,802] INFO [ThrottledChannelReaper-Request]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:46:15,810] INFO [ThrottledChannelReaper-Produce]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:46:16,083] INFO Loading logs. (kafka.log.LogManager:66) [2018-10-24 20:46:16,207] INFO Logs loading complete in 0 ms. (kafka.log.LogManager:66) [2018-10-24 20:46:16,369] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager:66) [2018-10-24 20:46:16,411] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager:66) [2018-10-24 20:46:16,461] INFO Starting the log cleaner (kafka.log.LogCleaner:66) [2018-10-24 20:46:16,550] INFO [kafka-log-cleaner-thread-0]: Starting (kafka.log.LogCleaner:66) [2018-10-24 20:46:19,447] INFO Awaiting socket connections on localhost:44565. (kafka.network.Acceptor:66) [2018-10-24 20:46:19,769] INFO [SocketServer brokerId=0] Started 1 acceptor threads (kafka.network.SocketServer:66) [2018-10-24 20:46:19,954] INFO [ExpirationReaper-0-Produce]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:46:19,985] INFO [ExpirationReaper-0-Fetch]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:46:19,998] INFO [ExpirationReaper-0-DeleteRecords]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:46:20,259] INFO [LogDirFailureHandler]: Starting (kafka.server.ReplicaManager$LogDirFailureHandler:66) [2018-10-24 20:46:20,507] INFO Creating /brokers/ids/0 (is it secure? false) (kafka.zk.KafkaZkClient:66) [2018-10-24 20:46:20,513] INFO Result of znode creation at /brokers/ids/0 is: OK (kafka.zk.KafkaZkClient:66) [2018-10-24 20:46:20,516] INFO Registered broker 0 at path /brokers/ids/0 with addresses: ArrayBuffer(EndPoint(localhost,44565,ListenerName(PLAINTEXT),PLAINTEXT)) (kafka.zk.KafkaZkClient:66) [2018-10-24 20:46:20,521] WARN No meta.properties file under dir /tmp/junit4976877634517730742/junit7458939386316814886/meta.properties (kafka.server.BrokerMetadataCheckpoint:70) [2018-10-24 20:46:20,874] INFO [ControllerEventThread controllerId=0] Starting (kafka.controller.ControllerEventManager$ControllerEventThread:66) [2018-10-24 20:46:20,916] INFO Successfully created /controller_epoch with initial epoch 0 (kafka.zk.KafkaZkClient:66) [2018-10-24 20:46:20,970] INFO [ExpirationReaper-0-topic]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:46:21,069] INFO [ExpirationReaper-0-Heartbeat]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:46:21,071] INFO [Controller id=0] 0 successfully elected as the controller. Epoch incremented to 1 and epoch zk version is now 1 (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,072] INFO [Controller id=0] Registering handlers (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,081] INFO [ExpirationReaper-0-Rebalance]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:46:21,090] INFO [Controller id=0] Deleting log dir event notifications (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,117] INFO [Controller id=0] Deleting isr change notifications (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,124] INFO [Controller id=0] Initializing controller context (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,215] INFO [GroupCoordinator 0]: Starting up. (kafka.coordinator.group.GroupCoordinator:66) [2018-10-24 20:46:21,262] INFO [GroupCoordinator 0]: Startup complete. (kafka.coordinator.group.GroupCoordinator:66) [2018-10-24 20:46:21,278] INFO [GroupMetadataManager brokerId=0] Removed 0 expired offsets in 9 milliseconds. (kafka.coordinator.group.GroupMetadataManager:66) [2018-10-24 20:46:21,477] INFO [ProducerId Manager 0]: Acquired new producerId block (brokerId:0,blockStartProducerId:0,blockEndProducerId:999) by writing to Zk with path version 1 (kafka.coordinator.transaction.ProducerIdManager:66) [2018-10-24 20:46:21,616] INFO [TransactionCoordinator id=0] Starting up. (kafka.coordinator.transaction.TransactionCoordinator:66) [2018-10-24 20:46:21,671] INFO [TransactionCoordinator id=0] Startup complete. (kafka.coordinator.transaction.TransactionCoordinator:66) [2018-10-24 20:46:21,708] INFO [Transaction Marker Channel Manager 0]: Starting (kafka.coordinator.transaction.TransactionMarkerChannelManager:66) [2018-10-24 20:46:21,734] INFO [Controller id=0] Partitions being reassigned: Map() (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,736] INFO [Controller id=0] Currently active brokers in the cluster: Set(0) (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,737] INFO [Controller id=0] Currently shutting brokers in the cluster: Set() (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,739] INFO [Controller id=0] Current list of topics in the cluster: Set() (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,739] INFO [Controller id=0] Fetching topic deletions in progress (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,749] INFO [Controller id=0] List of topics to be deleted: (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,770] INFO [Controller id=0] List of topics ineligible for deletion: (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,769] INFO [RequestSendThread controllerId=0] Starting (kafka.controller.RequestSendThread:66) [2018-10-24 20:46:21,773] INFO [Controller id=0] Initializing topic deletion manager (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,774] INFO [Controller id=0] Sending update metadata request (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,862] INFO [ReplicaStateMachine controllerId=0] Initializing replica state (kafka.controller.ReplicaStateMachine:66) [2018-10-24 20:46:21,876] INFO [ReplicaStateMachine controllerId=0] Triggering online replica state changes (kafka.controller.ReplicaStateMachine:66) [2018-10-24 20:46:21,904] INFO [RequestSendThread controllerId=0] Controller 0 connected to localhost:44565 (id: 0 rack: null) for sending state change requests (kafka.controller.RequestSendThread:66) [2018-10-24 20:46:21,931] INFO [ReplicaStateMachine controllerId=0] Started replica state machine with initial state -> Map() (kafka.controller.ReplicaStateMachine:66) [2018-10-24 20:46:21,936] INFO [PartitionStateMachine controllerId=0] Initializing partition state (kafka.controller.PartitionStateMachine:66) [2018-10-24 20:46:21,938] INFO [PartitionStateMachine controllerId=0] Triggering online partition state changes (kafka.controller.PartitionStateMachine:66) [2018-10-24 20:46:21,948] INFO [PartitionStateMachine controllerId=0] Started partition state machine with initial state -> Map() (kafka.controller.PartitionStateMachine:66) [2018-10-24 20:46:21,954] INFO [Controller id=0] Ready to serve as the new controller with epoch 1 (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,969] INFO [Controller id=0] Removing partitions Set() from the list of reassigned partitions in zookeeper (kafka.controller.KafkaController:66) [2018-10-24 20:46:21,976] INFO [Controller id=0] No more partitions need to be reassigned. Deleting zk path /admin/reassign_partitions (kafka.controller.KafkaController:66) [2018-10-24 20:46:22,026] INFO Got user-level KeeperException when processing sessionid:0x101d8d0842e0000 type:multi cxid:0x30 zxid:0x1c txntype:-1 reqpath:n/a aborting remaining multi ops. Error Path:/admin/reassign_partitions Error:KeeperErrorCode = NoNode for /admin/reassign_partitions (org.apache.zookeeper.server.PrepRequestProcessor:596) [2018-10-24 20:46:22,074] INFO [Controller id=0] Partitions undergoing preferred replica election: (kafka.controller.KafkaController:66) [2018-10-24 20:46:22,103] INFO [Controller id=0] Partitions that completed preferred replica election: (kafka.controller.KafkaController:66) [2018-10-24 20:46:22,106] INFO [Controller id=0] Skipping preferred replica election for partitions due to topic deletion: (kafka.controller.KafkaController:66) [2018-10-24 20:46:22,108] INFO [Controller id=0] Resuming preferred replica election for partitions: (kafka.controller.KafkaController:66) [2018-10-24 20:46:22,109] INFO [Controller id=0] Starting preferred replica leader election for partitions (kafka.controller.KafkaController:66) [2018-10-24 20:46:22,112] INFO Got user-level KeeperException when processing sessionid:0x101d8d0842e0000 type:multi cxid:0x32 zxid:0x1d txntype:-1 reqpath:n/a aborting remaining multi ops. Error Path:/admin/preferred_replica_election Error:KeeperErrorCode = NoNode for /admin/preferred_replica_election (org.apache.zookeeper.server.PrepRequestProcessor:596) [2018-10-24 20:46:22,137] INFO [Controller id=0] Starting the controller scheduler (kafka.controller.KafkaController:66) [2018-10-24 20:46:22,318] INFO [/config/changes-event-process-thread]: Starting (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread:66) [2018-10-24 20:46:22,391] INFO [SocketServer brokerId=0] Started processors for 1 acceptors (kafka.network.SocketServer:66) [2018-10-24 20:46:22,397] INFO Kafka version : 2.2.0-SNAPSHOT (org.apache.kafka.common.utils.AppInfoParser:109) [2018-10-24 20:46:22,398] INFO Kafka commitId : 6ee8a783175c9fa6 (org.apache.kafka.common.utils.AppInfoParser:110) [2018-10-24 20:46:22,449] INFO [KafkaServer id=0] started (kafka.server.KafkaServer:66) [2018-10-24 20:46:22,469] INFO KafkaConfig values: advertised.host.name = null advertised.listeners = null advertised.port = null alter.config.policy.class.name = null alter.log.dirs.replication.quota.window.num = 11 alter.log.dirs.replication.quota.window.size.seconds = 1 authorizer.class.name = auto.create.topics.enable = false auto.leader.rebalance.enable = true background.threads = 10 broker.id = 1 broker.id.generation.enable = true broker.rack = null client.quota.callback.class = null compression.type = producer connection.failed.authentication.delay.ms = 100 connections.max.idle.ms = 600000 controlled.shutdown.enable = true controlled.shutdown.max.retries = 3 controlled.shutdown.retry.backoff.ms = 5000 controller.socket.timeout.ms = 30000 create.topic.policy.class.name = null default.replication.factor = 1 delegation.token.expiry.check.interval.ms = 3600000 delegation.token.expiry.time.ms = 86400000 delegation.token.master.key = null delegation.token.max.lifetime.ms = 604800000 delete.records.purgatory.purge ...[truncated 3385363 chars]... lerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,421] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-23 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-23 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,421] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-47 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-47 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,422] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-18 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-18 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,422] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-26 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-26 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,423] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-36 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-36 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,423] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-5 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-5 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,424] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-8 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-8 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,424] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-16 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-16 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,424] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-11 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-11 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,425] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-40 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-40 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,425] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-19 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-19 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,426] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-27 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-27 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,426] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-41 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-41 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,427] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-1 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-1 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,427] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-34 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-34 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,427] ERROR [Controller id=2 epoch=3] Controller 2 epoch 3 failed to change state for partition __transaction_state-35 from OnlinePartition to OnlinePartition (state.change.logger:76) kafka.common.StateChangeFailedException: Failed to elect leader for partition __transaction_state-35 under strategy ControlledShutdownPartitionLeaderElectionStrategy at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:366) at kafka.controller.PartitionStateMachine$$anonfun$doElectLeaderForPartitions$3.apply(PartitionStateMachine.scala:364) at scala.collection.mutable.ResizableArray$class.foreach(ResizableArray.scala:59) at scala.collection.mutable.ArrayBuffer.foreach(ArrayBuffer.scala:48) at kafka.controller.PartitionStateMachine.doElectLeaderForPartitions(PartitionStateMachine.scala:364) at kafka.controller.PartitionStateMachine.electLeaderForPartitions(PartitionStateMachine.scala:292) at kafka.controller.PartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:210) at kafka.controller.PartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:133) at kafka.controller.KafkaController$ControlledShutdown.kafka$controller$KafkaController$ControlledShutdown$$doControlledShutdown(KafkaController.scala:1043) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at kafka.controller.KafkaController$ControlledShutdown$$anonfun$24.apply(KafkaController.scala:1017) at scala.util.Try$.apply(Try.scala:192) at kafka.controller.KafkaController$ControlledShutdown.process(KafkaController.scala:1017) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply$mcV$sp(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.controller.ControllerEventManager$ControllerEventThread$$anonfun$doWork$1.apply(ControllerEventManager.scala:89) at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31) at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:88) at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) [2018-10-24 20:48:02,429] INFO [KafkaServer id=2] Remaining partitions to move: __transaction_state-42,__transaction_state-13,__transaction_state-46,__transaction_state-17,__transaction_state-34,__transaction_state-5,__transaction_state-38,__transaction_state-9,__transaction_state-26,__transaction_state-30,__transaction_state-1,__transaction_state-18,__transaction_state-22,__transaction_state-12,__transaction_state-45,__transaction_state-16,__transaction_state-49,__transaction_state-4,__transaction_state-37,__transaction_state-8,__transaction_state-41,__transaction_state-29,__transaction_state-0,__transaction_state-33,__transaction_state-21,__transaction_state-25,__transaction_state-11,__transaction_state-44,__transaction_state-15,__transaction_state-48,__transaction_state-3,__transaction_state-36,__transaction_state-7,__transaction_state-40,__transaction_state-28,__transaction_state-32,__transaction_state-20,__transaction_state-24,__transaction_state-10,__transaction_state-43,__transaction_state-14,__transaction_state-47,__transaction_state-2,__transaction_state-35,__transaction_state-6,__transaction_state-39,__transaction_state-27,__transaction_state-31,__transaction_state-19,__transaction_state-23 (kafka.server.KafkaServer:66) [2018-10-24 20:48:02,429] INFO [KafkaServer id=2] Error from controller: NONE (kafka.server.KafkaServer:66) [2018-10-24 20:48:07,429] WARN [KafkaServer id=2] Retrying controlled shutdown after the previous attempt failed... (kafka.server.KafkaServer:70) [2018-10-24 20:48:07,431] WARN [KafkaServer id=2] Proceeding to do an unclean shutdown as all the controlled shutdown attempts failed (kafka.server.KafkaServer:70) [2018-10-24 20:48:07,431] INFO [/config/changes-event-process-thread]: Shutting down (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread:66) [2018-10-24 20:48:07,432] INFO [/config/changes-event-process-thread]: Stopped (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread:66) [2018-10-24 20:48:07,432] INFO [/config/changes-event-process-thread]: Shutdown completed (kafka.common.ZkNodeChangeNotificationListener$ChangeEventProcessThread:66) [2018-10-24 20:48:07,432] INFO [SocketServer brokerId=2] Stopping socket server request processors (kafka.network.SocketServer:66) [2018-10-24 20:48:07,435] INFO [SocketServer brokerId=2] Stopped socket server request processors (kafka.network.SocketServer:66) [2018-10-24 20:48:07,435] INFO [Kafka Request Handler on Broker 2], shutting down (kafka.server.KafkaRequestHandlerPool:66) [2018-10-24 20:48:07,436] INFO [Kafka Request Handler on Broker 2], shut down completely (kafka.server.KafkaRequestHandlerPool:66) [2018-10-24 20:48:07,439] INFO [KafkaApi-2] Shutdown complete. (kafka.server.KafkaApis:66) [2018-10-24 20:48:07,439] INFO [ExpirationReaper-2-topic]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,478] INFO [ExpirationReaper-2-topic]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,478] INFO [ExpirationReaper-2-topic]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,478] INFO [TransactionCoordinator id=2] Shutting down. (kafka.coordinator.transaction.TransactionCoordinator:66) [2018-10-24 20:48:07,479] INFO [ProducerId Manager 2]: Shutdown complete: last producerId assigned 2001 (kafka.coordinator.transaction.ProducerIdManager:66) [2018-10-24 20:48:07,479] INFO [Transaction State Manager 2]: Shutdown complete (kafka.coordinator.transaction.TransactionStateManager:66) [2018-10-24 20:48:07,480] INFO [Transaction Marker Channel Manager 2]: Shutting down (kafka.coordinator.transaction.TransactionMarkerChannelManager:66) [2018-10-24 20:48:07,480] INFO [Transaction Marker Channel Manager 2]: Stopped (kafka.coordinator.transaction.TransactionMarkerChannelManager:66) [2018-10-24 20:48:07,480] INFO [Transaction Marker Channel Manager 2]: Shutdown completed (kafka.coordinator.transaction.TransactionMarkerChannelManager:66) [2018-10-24 20:48:07,480] INFO [TransactionCoordinator id=2] Shutdown complete. (kafka.coordinator.transaction.TransactionCoordinator:66) [2018-10-24 20:48:07,481] INFO [GroupCoordinator 2]: Shutting down. (kafka.coordinator.group.GroupCoordinator:66) [2018-10-24 20:48:07,481] INFO [ExpirationReaper-2-Heartbeat]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,678] INFO [ExpirationReaper-2-Heartbeat]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,678] INFO [ExpirationReaper-2-Heartbeat]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,679] INFO [ExpirationReaper-2-Rebalance]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,878] INFO [ExpirationReaper-2-Rebalance]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,878] INFO [ExpirationReaper-2-Rebalance]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:07,878] INFO [GroupCoordinator 2]: Shutdown complete. (kafka.coordinator.group.GroupCoordinator:66) [2018-10-24 20:48:07,879] INFO [ReplicaManager broker=2] Shutting down (kafka.server.ReplicaManager:66) [2018-10-24 20:48:07,879] INFO [LogDirFailureHandler]: Shutting down (kafka.server.ReplicaManager$LogDirFailureHandler:66) [2018-10-24 20:48:07,879] INFO [LogDirFailureHandler]: Stopped (kafka.server.ReplicaManager$LogDirFailureHandler:66) [2018-10-24 20:48:07,879] INFO [LogDirFailureHandler]: Shutdown completed (kafka.server.ReplicaManager$LogDirFailureHandler:66) [2018-10-24 20:48:07,880] INFO [ReplicaFetcherManager on broker 2] shutting down (kafka.server.ReplicaFetcherManager:66) [2018-10-24 20:48:07,880] INFO [ReplicaFetcherManager on broker 2] shutdown completed (kafka.server.ReplicaFetcherManager:66) [2018-10-24 20:48:07,880] INFO [ReplicaAlterLogDirsManager on broker 2] shutting down (kafka.server.ReplicaAlterLogDirsManager:66) [2018-10-24 20:48:07,880] INFO [ReplicaAlterLogDirsManager on broker 2] shutdown completed (kafka.server.ReplicaAlterLogDirsManager:66) [2018-10-24 20:48:07,880] INFO [ExpirationReaper-2-Fetch]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,057] INFO [ExpirationReaper-2-Fetch]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,057] INFO [ExpirationReaper-2-Fetch]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,058] INFO [ExpirationReaper-2-Produce]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,230] INFO [ExpirationReaper-2-Produce]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,230] INFO [ExpirationReaper-2-Produce]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,230] INFO [ExpirationReaper-2-DeleteRecords]: Shutting down (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,319] INFO [ExpirationReaper-2-DeleteRecords]: Stopped (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,319] INFO [ExpirationReaper-2-DeleteRecords]: Shutdown completed (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper:66) [2018-10-24 20:48:08,321] INFO [ReplicaManager broker=2] Shut down completely (kafka.server.ReplicaManager:66) [2018-10-24 20:48:08,321] INFO Shutting down. (kafka.log.LogManager:66) [2018-10-24 20:48:08,321] INFO Shutting down the log cleaner. (kafka.log.LogCleaner:66) [2018-10-24 20:48:08,322] INFO [kafka-log-cleaner-thread-0]: Shutting down (kafka.log.LogCleaner:66) [2018-10-24 20:48:08,322] INFO [kafka-log-cleaner-thread-0]: Stopped (kafka.log.LogCleaner:66) [2018-10-24 20:48:08,322] INFO [kafka-log-cleaner-thread-0]: Shutdown completed (kafka.log.LogCleaner:66) [2018-10-24 20:48:08,325] INFO [ProducerStateManager partition=__transaction_state-12] Writing producer snapshot at offset 161 (kafka.log.ProducerStateManager:66) [2018-10-24 20:48:08,329] INFO [ProducerStateManager partition=__transaction_state-0] Writing producer snapshot at offset 8 (kafka.log.ProducerStateManager:66) [2018-10-24 20:48:08,337] INFO [ProducerStateManager partition=__transaction_state-11] Writing producer snapshot at offset 72 (kafka.log.ProducerStateManager:66) [2018-10-24 20:48:08,340] INFO [ProducerStateManager partition=__transaction_state-1] Writing producer snapshot at offset 16 (kafka.log.ProducerStateManager:66) [2018-10-24 20:48:08,341] INFO [ProducerStateManager partition=appId-1-store-changelog-0] Writing producer snapshot at offset 27 (kafka.log.ProducerStateManager:66) [2018-10-24 20:48:08,347] INFO Shutdown complete. (kafka.log.LogManager:66) [2018-10-24 20:48:08,348] INFO [ControllerEventThread controllerId=2] Shutting down (kafka.controller.ControllerEventManager$ControllerEventThread:66) [2018-10-24 20:48:08,348] INFO [ControllerEventThread controllerId=2] Stopped (kafka.controller.ControllerEventManager$ControllerEventThread:66) [2018-10-24 20:48:08,348] INFO [ControllerEventThread controllerId=2] Shutdown completed (kafka.controller.ControllerEventManager$ControllerEventThread:66) [2018-10-24 20:48:08,349] INFO [PartitionStateMachine controllerId=2] Stopped partition state machine (kafka.controller.PartitionStateMachine:66) [2018-10-24 20:48:08,349] INFO [ReplicaStateMachine controllerId=2] Stopped replica state machine (kafka.controller.ReplicaStateMachine:66) [2018-10-24 20:48:08,350] INFO [RequestSendThread controllerId=2] Shutting down (kafka.controller.RequestSendThread:66) [2018-10-24 20:48:08,350] INFO [RequestSendThread controllerId=2] Stopped (kafka.controller.RequestSendThread:66) [2018-10-24 20:48:08,350] INFO [RequestSendThread controllerId=2] Shutdown completed (kafka.controller.RequestSendThread:66) [2018-10-24 20:48:08,351] INFO [Controller id=2] Resigned (kafka.controller.KafkaController:66) [2018-10-24 20:48:08,351] INFO [ZooKeeperClient] Closing. (kafka.zookeeper.ZooKeeperClient:66) [2018-10-24 20:48:08,352] INFO Processed session termination for sessionid: 0x101d8d0842e0002 (org.apache.zookeeper.server.PrepRequestProcessor:487) [2018-10-24 20:48:08,353] INFO Session: 0x101d8d0842e0002 closed (org.apache.zookeeper.ZooKeeper:693) [2018-10-24 20:48:08,353] INFO Closed socket connection for client /127.0.0.1:34812 which had sessionid 0x101d8d0842e0002 (org.apache.zookeeper.server.NIOServerCnxn:1056) [2018-10-24 20:48:08,353] INFO [ZooKeeperClient] Closed. (kafka.zookeeper.ZooKeeperClient:66) [2018-10-24 20:48:08,353] INFO EventThread shut down for session: 0x101d8d0842e0002 (org.apache.zookeeper.ClientCnxn:522) [2018-10-24 20:48:08,354] INFO [ThrottledChannelReaper-Fetch]: Shutting down (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:08,464] INFO [ThrottledChannelReaper-Fetch]: Stopped (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:08,464] INFO [ThrottledChannelReaper-Fetch]: Shutdown completed (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:08,465] INFO [ThrottledChannelReaper-Produce]: Shutting down (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:09,461] INFO [ThrottledChannelReaper-Produce]: Stopped (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:09,461] INFO [ThrottledChannelReaper-Produce]: Shutdown completed (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:09,461] INFO [ThrottledChannelReaper-Request]: Shutting down (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:09,498] INFO [ThrottledChannelReaper-Request]: Stopped (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:09,498] INFO [ThrottledChannelReaper-Request]: Shutdown completed (kafka.server.ClientQuotaManager$ThrottledChannelReaper:66) [2018-10-24 20:48:09,498] INFO [SocketServer brokerId=2] Shutting down socket server (kafka.network.SocketServer:66) [2018-10-24 20:48:09,514] INFO [SocketServer brokerId=2] Shutdown completed (kafka.network.SocketServer:66) [2018-10-24 20:48:09,515] INFO [KafkaServer id=2] shut down completed (kafka.server.KafkaServer:66) [2018-10-24 20:48:09,534] INFO shutting down (org.apache.zookeeper.server.ZooKeeperServer:502) [2018-10-24 20:48:09,534] INFO Shutting down (org.apache.zookeeper.server.SessionTrackerImpl:226) [2018-10-24 20:48:09,534] INFO Shutting down (org.apache.zookeeper.server.PrepRequestProcessor:769) [2018-10-24 20:48:09,535] INFO Shutting down (org.apache.zookeeper.server.SyncRequestProcessor:208) [2018-10-24 20:48:09,535] INFO PrepRequestProcessor exited loop! (org.apache.zookeeper.server.PrepRequestProcessor:144) [2018-10-24 20:48:09,535] INFO SyncRequestProcessor exited! (org.apache.zookeeper.server.SyncRequestProcessor:186) [2018-10-24 20:48:09,536] INFO shutdown of request processor complete (org.apache.zookeeper.server.FinalRequestProcessor:403) [2018-10-24 20:48:09,552] INFO NIOServerCnxn factory exited run method (org.apache.zookeeper.server.NIOServerCnxnFactory:242)
Attachments
Issue Links
- duplicates
-
-
- Resolved
-
- is related to
-
-
- Resolved
-