[KAFKA-1878] ProducerFailureHandlingTest.testCannotSendToInternalTopic fails with TimeoutException while trying to fetch metadata for topic

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 0.9.0.0
• Component/s: system tests
• Assignee: Jaikiran Pai
• Reporter: Jaikiran Pai
• Created: 19/Jan/15 09:57
• Updated: 19/Jan/15 17:06
• Resolved: 19/Jan/15 17:06

Description

The testCannotSendToInternalTopic test method in ProducerFailureHandlingTest fails consistently with the following exception:

Unexpected exception while seding to an invalid topic org.apache.kafka.common.errors.TimeoutException: Failed to update metadata after 3000 ms.
java.lang.AssertionError: Unexpected exception while seding to an invalid topic org.apache.kafka.common.errors.TimeoutException: Failed to update metadata after 3000 ms.
	at org.junit.Assert.fail(Assert.java:91)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at kafka.api.test.ProducerFailureHandlingTest.testCannotSendToInternalTopic(ProducerFailureHandlingTest.scala:317)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at junit.framework.TestCase.runTest(TestCase.java:168)
	at junit.framework.TestCase.runBare(TestCase.java:134)
	at junit.framework.TestResult$1.protect(TestResult.java:110)
	at junit.framework.TestResult.runProtected(TestResult.java:128)
	at junit.framework.TestResult.run(TestResult.java:113)
	at junit.framework.TestCase.run(TestCase.java:124)
	at org.scalatest.junit.JUnit3Suite.run(JUnit3Suite.scala:321)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at org.jetbrains.plugins.scala.testingSupport.scalaTest.ScalaTestRunner.runSingleTest(ScalaTestRunner.java:245)
	at org.jetbrains.plugins.scala.testingSupport.scalaTest.ScalaTestRunner.runScalaTest1(ScalaTestRunner.java:213)
	at org.jetbrains.plugins.scala.testingSupport.scalaTest.ScalaTestRunner.main(ScalaTestRunner.java:30)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)

This failure appears like it's intermittent when the ProducerFailureHandlingTest is run as whole because it hides the timing issue involved in the testCannotSendToInternalTopic test method. Running only that testCannotSendToInternalTopic test method (I did it from IntelliJ IDE) consistently reproduces this failure.

The real issue is that the initialization of the __consumer_offset topic (being accessed in the testCannotSendToInternalTopic test method) is time consuming because that topic is backed by 50 partitions (default) and it takes a while for each of them to be assigned a leader and do other initialization. This times out the metadata fetch (3 seconds) being done by the producer during a send(), which causes the test method to fail.

I've a patch to fix that test method which I'll send shortly.