Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

"WARN Unexpected exception" leading to -> "This server does not host this topic-partition" #9643

Open
xavsan opened this issue Oct 13, 2022 · 0 comments
Open

"WARN Unexpected exception" leading to -> "This server does not host this topic-partition" #9643

xavsan opened this issue Oct 13, 2022 · 0 comments
Labels
bug enhancement P1 Slightly lower priority to P0 ;)

Comments

@xavsan
Copy link

xavsan commented Oct 13, 2022 •
edited

Describe the bug
In a very rare occurrence, I'm getting an UnknownTopicOrPartitionException while attempting to CREATE a stream where the topic is in fact automatically created yet isn't recognized for some reason. This is a problem, because upon attempting to resend the CREATE command I get the following back "This server does not host this topic-partition". So clearly the topic is being created somewhere just not where it's supposed to. I'm thinking this may be related to KSQL issue #815 and KAFKA issue #6221 which is still unresolved. N.B. the WARN Unexpected exception I'm getting near the top of the exception trace.

To Reproduce
Steps to reproduce the behavior, include:

  1. The version of KSQL is 0.28.2
  2. Start a ksql system and try to execute a CREATE stream command

Expected behavior
Most of the time when I run this exact CREATE command, the proper topic is created and my program is able to continue on.

Actual behaviour

  1. Here are the logs for what I'm seeing.
[  763507] [    46.044849] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:05,153] INFO Creating topic 'locations'  (io.confluent.ksql.services.KafkaTopicClient:113)
[  763507] [    46.451004] [service_kafka]                     [I] [2022-10-06 21:35:05,559] INFO Creating topic locations with configuration {cleanup.policy=delete} and initial partition assignment HashMap(0 -> ArrayBuffer(3), 1 -> ArrayBuffer(1), 2 -> ArrayBuffer(2)) (kafka.zk.AdminZkClient)
[  763524] [    47.234449] [service_kafka]                     [I] [2022-10-06 21:35:06,343] INFO [Controller id=1] New topics: [Set(locations)], deleted topics: [HashSet()], new partition replica assignment [Set(TopicIdReplicaAssignment(locations,Some(k2tLQcs9SUuJdrLnXBMPTA),Map(locations-0 -> ReplicaAssignment(replicas=3, addingReplicas=, removingReplicas=), locations-1 -> ReplicaAssignment(replicas=1, addingReplicas=, removingReplicas=), locations-2 -> ReplicaAssignment(replicas=2, addingReplicas=, removingReplicas=))))] (kafka.controller.KafkaController)
[  763524] [    47.234542] [service_kafka]                     [I] [2022-10-06 21:35:06,343] INFO [Controller id=1] New partition creation callback for locations-0,locations-1,locations-2 (kafka.controller.KafkaController)
[  763524] [    47.234718] [service_kafka]                     [I] [2022-10-06 21:35:06,343] INFO [Controller id=1 epoch=1] Changed partition locations-0 state from NonExistentPartition to NewPartition with assigned replicas 3 (state.change.logger)
[  763524] [    47.234756] [service_kafka]                     [I] [2022-10-06 21:35:06,343] INFO [Controller id=1 epoch=1] Changed partition locations-1 state from NonExistentPartition to NewPartition with assigned replicas 1 (state.change.logger)
[  763524] [    47.234787] [service_kafka]                     [I] [2022-10-06 21:35:06,343] INFO [Controller id=1 epoch=1] Changed partition locations-2 state from NonExistentPartition to NewPartition with assigned replicas 2 (state.change.logger)
[  763524] [    47.234927] [service_kafka]                     [I] [2022-10-06 21:35:06,343] INFO [Controller id=1 epoch=1] Sending UpdateMetadata request to brokers HashSet() for 0 partitions (state.change.logger)
[  763524] [    47.235041] [service_kafka]                     [I] [2022-10-06 21:35:06,343] TRACE [Controller id=1 epoch=1] Changed state of replica 1 for partition locations-1 from NonExistentReplica to NewReplica (state.change.logger)
[  763524] [    47.235081] [service_kafka]                     [I] [2022-10-06 21:35:06,344] TRACE [Controller id=1 epoch=1] Changed state of replica 2 for partition locations-2 from NonExistentReplica to NewReplica (state.change.logger)
[  763524] [    47.235175] [service_kafka]                     [I] [2022-10-06 21:35:06,344] TRACE [Controller id=1 epoch=1] Changed state of replica 3 for partition locations-0 from NonExistentReplica to NewReplica (state.change.logger)
[  763524] [    47.235215] [service_kafka]                     [I] [2022-10-06 21:35:06,344] INFO [Controller id=1 epoch=1] Sending UpdateMetadata request to brokers HashSet() for 0 partitions (state.change.logger)
[  763636] [    52.445479] [service_additional-ksqldb-server]  [I] [2022-10-06 21:35:11,554] ERROR Could not submit metrics to Confluent: version-check.confluent.io: Name or service not known (io.confluent.support.metrics.utils.WebClient:112)
[  763636] [    52.445518] [service_additional-ksqldb-server]  [I] [2022-10-06 21:35:11,554] ERROR Failed to submit metrics via secure endpoint, falling back to insecure endpoint (io.confluent.support.metrics.submitters.ConfluentSubmitter:135)
[  763636] [    52.445895] [service_additional-ksqldb-server]  [I] [2022-10-06 21:35:11,554] ERROR Could not submit metrics to Confluent: version-check.confluent.io (io.confluent.support.metrics.utils.WebClient:112)
[  763636] [    52.446137] [service_additional-ksqldb-server2] [I] [2022-10-06 21:35:11,555] ERROR Could not submit metrics to Confluent: version-check.confluent.io: Name or service not known (io.confluent.support.metrics.utils.WebClient:112)
[  763636] [    52.446291] [service_additional-ksqldb-server2] [I] [2022-10-06 21:35:11,555] ERROR Failed to submit metrics via secure endpoint, falling back to insecure endpoint (io.confluent.support.metrics.submitters.ConfluentSubmitter:135)
[  763636] [    52.446602] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:11,555] ERROR Could not submit metrics to Confluent: version-check.confluent.io: Name or service not known (io.confluent.support.metrics.utils.WebClient:112)
[  763636] [    52.447953] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:11,556] ERROR Failed to submit metrics via secure endpoint, falling back to insecure endpoint (io.confluent.support.metrics.submitters.ConfluentSubmitter:135)
[  763636] [    52.448353] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:11,557] ERROR Could not submit metrics to Confluent: version-check.confluent.io (io.confluent.support.metrics.utils.WebClient:112)
[  763636] [    52.449130] [service_additional-ksqldb-server2] [I] [2022-10-06 21:35:11,558] ERROR Could not submit metrics to Confluent: version-check.confluent.io (io.confluent.support.metrics.utils.WebClient:112)
[  763636] [    52.449255] [service_additional-ksqldb-server2] [I] [2022-10-06 21:35:11,558] ERROR Failed to submit metrics to Confluent via insecure endpoint=http://version-check.confluent.io/ksql/anon -- giving up (io.confluent.support.metrics.submitters.ConfluentSubmitter:165)
[  763636] [    52.450940] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:11,559] ERROR Failed to submit metrics to Confluent via insecure endpoint=http://version-check.confluent.io/ksql/anon -- giving up (io.confluent.support.metrics.submitters.ConfluentSubmitter:165)
[  763636] [    52.451426] [service_additional-ksqldb-server]  [I] [2022-10-06 21:35:11,560] ERROR Failed to submit metrics to Confluent via insecure endpoint=http://version-check.confluent.io/ksql/anon -- giving up (io.confluent.support.metrics.submitters.ConfluentSubmitter:165)
[  763748] [    58.334452] [service_kafka-2]                   [I] [2022-10-06 21:35:17,443] WARN Client session timed out, have not heard from server in 12000ms for session id 0x1000000448a0004 (org.apache.zookeeper.ClientCnxn)
[  763748] [    58.334974] [service_kafka-2]                   [I] [2022-10-06 21:35:17,443] WARN Session 0x1000000448a0004 for sever zookeeper/10.20.20.10:2181, Closing socket connection. Attempting reconnect except it is a SessionExpiredException. (org.apache.zookeeper.ClientCnxn)
[  763748] [    58.334974] [service_kafka-2]                   [I] org.apache.zookeeper.ClientCnxn$SessionTimeoutException: Client session timed out, have not heard from server in 12000ms for session id 0x1000000448a0004
[  763748] [    58.334974] [service_kafka-2]                   [I] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1258)
[  763748] [    58.613266] [service_zookeeper]                 [I] [2022-10-06 21:35:17,721] WARN Unexpected exception (org.apache.zookeeper.server.NIOServerCnxn)
[  763748] [    58.613266] [service_zookeeper]                 [I] EndOfStreamException: Unable to read additional data from client, it probably closed the socket: address = /10.20.20.40:37720, session = 0x1000000448a0004
[  763748] [    58.613266] [service_zookeeper]                 [I] at org.apache.zookeeper.server.NIOServerCnxn.handleFailedRead(NIOServerCnxn.java:163)
[  763748] [    58.613266] [service_zookeeper]                 [I] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:326)
[  763748] [    58.613266] [service_zookeeper]                 [I] at org.apache.zookeeper.server.NIOServerCnxnFactory$IOWorkRequest.doWork(NIOServerCnxnFactory.java:522)
[  763748] [    58.613266] [service_zookeeper]                 [I] at org.apache.zookeeper.server.WorkerService$ScheduledWorkRequest.run(WorkerService.java:154)
[  763748] [    58.613266] [service_zookeeper]                 [I] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[  763748] [    58.613266] [service_zookeeper]                 [I] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[  763748] [    58.613266] [service_zookeeper]                 [I] at java.base/java.lang.Thread.run(Thread.java:829)
[  763764] [    59.569042] [service_kafka]                     [I] [2022-10-06 21:35:18,678] WARN Client session timed out, have not heard from server in 12028ms for session id 0x1000000448a0002 (org.apache.zookeeper.ClientCnxn)
[  763764] [    59.569546] [service_kafka]                     [I] [2022-10-06 21:35:18,678] WARN Session 0x1000000448a0002 for sever zookeeper/10.20.20.10:2181, Closing socket connection. Attempting reconnect except it is a SessionExpiredException. (org.apache.zookeeper.ClientCnxn)
[  763764] [    59.569546] [service_kafka]                     [I] org.apache.zookeeper.ClientCnxn$SessionTimeoutException: Client session timed out, have not heard from server in 12028ms for session id 0x1000000448a0002
[  763764] [    59.569546] [service_kafka]                     [I] at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1258)
[  763764] [    59.630441] [service_zookeeper]                 [I] [2022-10-06 21:35:18,739] WARN Unexpected exception (org.apache.zookeeper.server.NIOServerCnxn)
[  763764] [    59.630441] [service_zookeeper]                 [I] EndOfStreamException: Unable to read additional data from client, it probably closed the socket: address = /10.20.20.15:33790, session = 0x1000000448a0002
[  763764] [    59.630441] [service_zookeeper]                 [I] at org.apache.zookeeper.server.NIOServerCnxn.handleFailedRead(NIOServerCnxn.java:163)
[  763764] [    59.630441] [service_zookeeper]                 [I] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:326)
[  763764] [    59.630441] [service_zookeeper]                 [I] at org.apache.zookeeper.server.NIOServerCnxnFactory$IOWorkRequest.doWork(NIOServerCnxnFactory.java:522)
[  763764] [    59.630441] [service_zookeeper]                 [I] at org.apache.zookeeper.server.WorkerService$ScheduledWorkRequest.run(WorkerService.java:154)
[  763764] [    59.630441] [service_zookeeper]                 [I] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[  763764] [    59.630441] [service_zookeeper]                 [I] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[  763764] [    59.630441] [service_zookeeper]                 [I] at java.base/java.lang.Thread.run(Thread.java:829)
[  763764] [    59.669857] [service_kafka]                     [I] [2022-10-06 21:35:18,778] INFO [ZooKeeperClient Kafka server] Waiting until connected. (kafka.zookeeper.ZooKeeperClient)
[  763764] [    59.669903] [service_kafka]                     [I] [2022-10-06 21:35:18,778] INFO [ZooKeeperClient Kafka server] Connected. (kafka.zookeeper.ZooKeeperClient)
[  763764] [    60.253334] [service_kafka-2]                   [I] [2022-10-06 21:35:19,362] INFO Opening socket connection to server zookeeper/10.20.20.10:2181. (org.apache.zookeeper.ClientCnxn)
[  763764] [    60.359217] [service_kafka-2]                   [I] [2022-10-06 21:35:19,468] INFO Socket connection established, initiating session, client: /10.20.20.40:37848, server: zookeeper/10.20.20.10:2181 (org.apache.zookeeper.ClientCnxn)
[  763764] [    60.471194] [service_kafka-2]                   [I] [2022-10-06 21:35:19,580] INFO Session establishment complete on server zookeeper/10.20.20.10:2181, session id = 0x1000000448a0004, negotiated timeout = 18000 (org.apache.zookeeper.ClientCnxn)
[  763780] [    61.324928] [service_kafka]                     [I] [2022-10-06 21:35:20,433] INFO Opening socket connection to server zookeeper/10.20.20.10:2181. (org.apache.zookeeper.ClientCnxn)
[  763780] [    61.521822] [service_kafka]                     [I] [2022-10-06 21:35:20,630] INFO Socket connection established, initiating session, client: /10.20.20.15:33926, server: zookeeper/10.20.20.10:2181 (org.apache.zookeeper.ClientCnxn)
[  763780] [    61.619583] [service_kafka]                     [I] [2022-10-06 21:35:20,728] INFO Session establishment complete on server zookeeper/10.20.20.10:2181, session id = 0x1000000448a0002, negotiated timeout = 18000 (org.apache.zookeeper.ClientCnxn)
[  763780] [    61.817988] [service_kafka]                     [I] [2022-10-06 21:35:20,925] ERROR [Controller id=1 epoch=1] Controller 1 epoch 1 failed to change state for partition locations-0 from NewPartition to OnlinePartition (state.change.logger)
[  763780] [    61.817988] [service_kafka]                     [I] org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists
[  763780] [    61.817988] [service_kafka]                     [I] at org.apache.zookeeper.KeeperException.create(KeeperException.java:126)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.logFailedStateChange(PartitionStateMachine.scala:520)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.$anonfun$initializeLeaderAndIsrForPartitions$10(PartitionStateMachine.scala:314)
[  763780] [    61.817988] [service_kafka]                     [I] at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
[  763780] [    61.817988] [service_kafka]                     [I] at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
[  763780] [    61.817988] [service_kafka]                     [I] at scala.collection.AbstractIterable.foreach(Iterable.scala:926)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.initializeLeaderAndIsrForPartitions(PartitionStateMachine.scala:304)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:230)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:161)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.KafkaController.onNewPartitionCreation(KafkaController.scala:661)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.KafkaController.processTopicChange(KafkaController.scala:1668)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.KafkaController.process(KafkaController.scala:2544)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.QueuedEvent.process(ControllerEventManager.scala:52)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.process$1(ControllerEventManager.scala:130)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.$anonfun$doWork$1(ControllerEventManager.scala:133)
[  763780] [    61.817988] [service_kafka]                     [I] at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:133)
[  763780] [    61.817988] [service_kafka]                     [I] at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:96)
[  763780] [    61.818083] [service_kafka]                     [I] [2022-10-06 21:35:20,927] ERROR [Controller id=1 epoch=1] Controller 1 epoch 1 failed to change state for partition locations-1 from NewPartition to OnlinePartition (state.change.logger)
[  763780] [    61.818083] [service_kafka]                     [I] org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists
[  763780] [    61.818083] [service_kafka]                     [I] at org.apache.zookeeper.KeeperException.create(KeeperException.java:126)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.logFailedStateChange(PartitionStateMachine.scala:520)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.$anonfun$initializeLeaderAndIsrForPartitions$10(PartitionStateMachine.scala:314)
[  763780] [    61.818083] [service_kafka]                     [I] at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
[  763780] [    61.818083] [service_kafka]                     [I] at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
[  763780] [    61.818083] [service_kafka]                     [I] at scala.collection.AbstractIterable.foreach(Iterable.scala:926)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.initializeLeaderAndIsrForPartitions(PartitionStateMachine.scala:304)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:230)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:161)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.KafkaController.onNewPartitionCreation(KafkaController.scala:661)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.KafkaController.processTopicChange(KafkaController.scala:1668)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.KafkaController.process(KafkaController.scala:2544)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.QueuedEvent.process(ControllerEventManager.scala:52)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.process$1(ControllerEventManager.scala:130)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.$anonfun$doWork$1(ControllerEventManager.scala:133)
[  763780] [    61.818083] [service_kafka]                     [I] at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:133)
[  763780] [    61.818083] [service_kafka]                     [I] at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:96)
[  763780] [    61.818124] [service_kafka]                     [I] [2022-10-06 21:35:20,927] ERROR [Controller id=1 epoch=1] Controller 1 epoch 1 failed to change state for partition locations-2 from NewPartition to OnlinePartition (state.change.logger)
[  763780] [    61.818124] [service_kafka]                     [I] org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists
[  763780] [    61.818124] [service_kafka]                     [I] at org.apache.zookeeper.KeeperException.create(KeeperException.java:126)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.logFailedStateChange(PartitionStateMachine.scala:520)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.$anonfun$initializeLeaderAndIsrForPartitions$10(PartitionStateMachine.scala:314)
[  763780] [    61.818124] [service_kafka]                     [I] at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)
[  763780] [    61.818124] [service_kafka]                     [I] at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)
[  763780] [    61.818124] [service_kafka]                     [I] at scala.collection.AbstractIterable.foreach(Iterable.scala:926)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.initializeLeaderAndIsrForPartitions(PartitionStateMachine.scala:304)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.doHandleStateChanges(PartitionStateMachine.scala:230)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ZkPartitionStateMachine.handleStateChanges(PartitionStateMachine.scala:161)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.KafkaController.onNewPartitionCreation(KafkaController.scala:661)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.KafkaController.processTopicChange(KafkaController.scala:1668)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.KafkaController.process(KafkaController.scala:2544)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.QueuedEvent.process(ControllerEventManager.scala:52)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.process$1(ControllerEventManager.scala:130)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.$anonfun$doWork$1(ControllerEventManager.scala:133)
[  763780] [    61.818124] [service_kafka]                     [I] at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.metrics.KafkaTimer.time(KafkaTimer.scala:31)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.controller.ControllerEventManager$ControllerEventThread.doWork(ControllerEventManager.scala:133)
[  763780] [    61.818124] [service_kafka]                     [I] at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:96)
[  763780] [    61.818210] [service_kafka]                     [I] [2022-10-06 21:35:20,927] INFO [Controller id=1 epoch=1] Sending UpdateMetadata request to brokers HashSet() for 0 partitions (state.change.logger)
[  763780] [    61.818304] [service_kafka]                     [I] [2022-10-06 21:35:20,927] TRACE [Controller id=1 epoch=1] Changed state of replica 1 for partition locations-1 from NewReplica to OnlineReplica (state.change.logger)
[  763780] [    61.818410] [service_kafka]                     [I] [2022-10-06 21:35:20,927] TRACE [Controller id=1 epoch=1] Changed state of replica 2 for partition locations-2 from NewReplica to OnlineReplica (state.change.logger)
[  763780] [    61.818477] [service_kafka]                     [I] [2022-10-06 21:35:20,927] TRACE [Controller id=1 epoch=1] Changed state of replica 3 for partition locations-0 from NewReplica to OnlineReplica (state.change.logger)
[  763780] [    61.818571] [service_kafka]                     [I] [2022-10-06 21:35:20,927] INFO [Controller id=1 epoch=1] Sending UpdateMetadata request to brokers HashSet() for 0 partitions (state.change.logger)
[  763956] [    77.118648] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:36,227] INFO Retrying request. Retry no: 0 Cause: 'org.apache.kafka.common.errors.TimeoutException: The request timed out.' (io.confluent.ksql.util.ExecutorUtil:104)
[  763972] [    78.379519] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:37,488] INFO Retrying request. Retry no: 0 Cause: 'org.apache.kafka.common.errors.UnknownTopicOrPartitionException: This server does not host this topic-partition.' (io.confluent.ksql.util.ExecutorUtil:104)
[  763972] [    79.032667] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:38,141] INFO Retrying request. Retry no: 1 Cause: 'org.apache.kafka.common.errors.UnknownTopicOrPartitionException: This server does not host this topic-partition.' (io.confluent.ksql.util.ExecutorUtil:104)
[  764003] [    79.670827] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:38,779] INFO Retrying request. Retry no: 2 Cause: 'org.apache.kafka.common.errors.UnknownTopicOrPartitionException: This server does not host this topic-partition.' (io.confluent.ksql.util.ExecutorUtil:104)
[  764018] [    80.295010] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:39,403] INFO Retrying request. Retry no: 3 Cause: 'org.apache.kafka.common.errors.UnknownTopicOrPartitionException: This server does not host this topic-partition.' (io.confluent.ksql.util.ExecutorUtil:104)
[  764018] [    80.933035] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:40,041] INFO Retrying request. Retry no: 4 Cause: 'org.apache.kafka.common.errors.UnknownTopicOrPartitionException: This server does not host this topic-partition.' (io.confluent.ksql.util.ExecutorUtil:104)
[  764018] [    80.933669] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:40,042] INFO Processed unsuccessfully: KsqlRequest{ksql='CREATE STREAM riderLocations (profileId VARCHAR, latitude DOUBLE, longitude DOUBLE) WITH (kafka_topic='locations', value_format='json', partitions=3);', configOverrides={}, requestProperties={}, sessionVariables={}, commandSequenceNumber=Optional.empty}, reason:  (io.confluent.ksql.rest.server.resources.KsqlResource:347)
[  764018] [    80.933669] [service_primary-ksqldb-server]     [I] io.confluent.ksql.exception.KafkaResponseGetFailedException: Failed to Describe Kafka Topic(s): [locations]
[  764018] [    80.933669] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.services.KafkaTopicClientImpl.describeTopics(KafkaTopicClientImpl.java:212)
[  764018] [    80.933669] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.services.KafkaTopicClient.describeTopic(KafkaTopicClient.java:162)
[  764018] [    80.933669] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.services.KafkaTopicClientImpl.validateTopicProperties(KafkaTopicClientImpl.java:388)
[  764018] [    80.933669] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.services.KafkaTopicClientImpl.createTopic(KafkaTopicClientImpl.java:133)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.services.KafkaTopicClient.createTopic(KafkaTopicClient.java:102)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.topic.TopicCreateInjector.createTopic(TopicCreateInjector.java:211)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.topic.TopicCreateInjector.createTopic(TopicCreateInjector.java:197)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.topic.TopicCreateInjector.injectForCreateSource(TopicCreateInjector.java:132)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.topic.TopicCreateInjector.inject(TopicCreateInjector.java:91)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.topic.TopicCreateInjector.inject(TopicCreateInjector.java:75)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.statement.InjectorChain.inject(InjectorChain.java:42)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.statement.InjectorChain.inject(InjectorChain.java:42)
[  764018] [    80.933670] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.computation.DistributingExecutor.execute(DistributingExecutor.java:176)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.execution.RequestHandler.lambda$executeStatement$0(RequestHandler.java:123)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.execution.RequestHandler.executeStatement(RequestHandler.java:127)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.execution.RequestHandler.execute(RequestHandler.java:93)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.resources.KsqlResource.handleKsqlStatements(KsqlResource.java:320)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.KsqlServerEndpoints.lambda$executeKsqlRequest$2(KsqlServerEndpoints.java:183)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.KsqlServerEndpoints.lambda$executeOldApiEndpointOnWorker$23(KsqlServerEndpoints.java:341)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.confluent.ksql.rest.server.KsqlServerEndpoints.lambda$executeOnWorker$22(KsqlServerEndpoints.java:327)
[  764018] [    80.933671] [service_primary-ksqldb-server]     [I] at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$2(ContextImpl.java:313)
[  764018] [    80.933672] [service_primary-ksqldb-server]     [I] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[  764018] [    80.933672] [service_primary-ksqldb-server]     [I] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[  764018] [    80.933672] [service_primary-ksqldb-server]     [I] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
[  764018] [    80.933672] [service_primary-ksqldb-server]     [I] at java.base/java.lang.Thread.run(Thread.java:829)
[  764018] [    80.933672] [service_primary-ksqldb-server]     [I] Caused by: org.apache.kafka.common.errors.UnknownTopicOrPartitionException: This server does not host this topic-partition.
[  764018] [    80.945182] [service_primary-ksqldb-server]     [I] [2022-10-06 21:35:40,054] ERROR 10.20.20.35 - - [Thu, 6 Oct 2022 21:35:40 GMT] "POST /ksql HTTP/1.1" 500 348 "-" "python-requests/2.27.1" 162 (io.confluent.ksql.api.server.LoggingHandler:140)
[  764033] [    81.015690] [service_ksqldb-cli]                [I] Incoming post output
[  764033] [    81.015756] [service_ksqldb-cli]                [I] {'@type': 'statement_error', 'error_code': 50000, 'message': 'Failed to Describe Kafka Topic(s): [locations]\nCaused by: This server does not host this topic-partition.', 'statementText': "CREATE STREAM riderLocations (profileId VARCHAR, latitude DOUBLE, longitude DOUBLE) WITH (kafka_topic='locations', value_format='json', partitions=3);", 'entities': []}
[  764033] [    81.015822] [service_ksqldb-cli]                [I] Stream failed. Retrying
@xavsan xavsan changed the title UnknownTopicOrPartitionException: This server does not host this topic-partition "WARN Unexpected exception" leading to -> "This server does not host this topic-partition" Oct 13, 2022
@pgaref pgaref added enhancement P1 Slightly lower priority to P0 ;) and removed needs-triage labels Oct 14, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug enhancement P1 Slightly lower priority to P0 ;)
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@pgaref @xavsan