Major Description
When mirrorMaker mirrors a topic to destination brokers that have topic auto create disabled and a topic doesn't exist on the destination brokers, the producer in mirror maker logs the following
Error while fetching metadata with correlation id 467 : \{mirror-test2=UNKNOWN_TOPIC_OR_PARTITION\} Error while fetching metadata with correlation id 468 : {mirror-test2=UNKNOWN_TOPIC_OR_PARTITION}
This log message is fine and expected. The problem is the log message stops ~5 min later. At which point the logs look fine, but mirror maker is not mirroring any of its topics.
What's worse is mirrorMaker is basically in an unrecoverable state once this happens (the log statement stops). If you create the topic at the destination mirrorMaker still won't mirror data until a restart. Attempts to restart mirrorMaker (cleanly) fail because the process is more or less deadlocked in its shutdown hook.
Here is the reasoning:
- MirrorMaker becomes unrecoverable after 5 minutes because of this loop in the producer
- The producer will keep waiting for metadata for the missing topic or until the max timeout is reached. (max long in this case)
- after 5 minutes the producer stops making a metadata request for the topic because that topic expires here
- topic is never re-added for metadata requests since the only add is before entering the loop here
So basically after 5 minutes all metadata requests moving forward are for no topics since the topic expired. The mirrorMaker thread essentially gets stuck waiting forever since there will never be a metadata request for the topic the thread is waiting on
All of this basically leads to a deadlock state in the shutdown hook.
- shutdown hook sends a shutdown to the mirrorMaker threads
- waits for threads to exit their loop by waitind on a latch
- latch is never counted down in produce
- thread will never exit the loop to countdown the latch on line 462.
This can be seen with a thread dump of the shutdown hook thread
Name: MirrorMakerShutdownHook
State: WAITING on java.util.concurrent.CountDownLatch$Sync@3ffebeac
Total blocked: 0 Total waited: 1
Stack trace:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
kafka.tools.MirrorMaker$MirrorMakerThread.awaitShutdown(MirrorMaker.scala:498)
kafka.tools.MirrorMaker$$anonfun$cleanShutdown$4.apply(MirrorMaker.scala:396)
kafka.tools.MirrorMaker$$anonfun$cleanShutdown$4.apply(MirrorMaker.scala:396)
scala.collection.Iterator$class.foreach(Iterator.scala:893)
The root of the issue more or less related to the issue documented here where the producer can block waiting for metadata. https://issues.apache.org/jira/browse/KAFKA-3450
Attachments
Issue Links
- is related to
-
KAFKA-3575 Use console consumer access topic that does not exist, can not use "Control + C" to exit process
-
- Patch Available
-