Major Description
Began seeing this in some failing system tests:
[INFO - 2017-07-18 14:25:55,375 - background_thread - _protected_worker - lineno:39]: Traceback (most recent call last): File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/venv/local/lib/python2.7/site-packages/ducktape-0.6.0-py2.7.egg/ducktape/services/background_thread.py", line 35, in _protected_worker self._worker(idx, node) File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/tests/kafkatest/services/console_consumer.py", line 261, in _worker self.start_jmx_tool(idx, node) File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/tests/kafkatest/services/monitor/jmx.py", line 73, in start_jmx_tool wait_until(lambda: self._jmx_has_output(node), timeout_sec=10, backoff_sec=.5, err_msg="%s: Jmx tool took too long to start" % node.account) File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/venv/local/lib/python2.7/site-packages/ducktape-0.6.0-py2.7.egg/ducktape/utils/util.py", line 36, in wait_until raise TimeoutError(err_msg) TimeoutError: ubuntu@worker7: Jmx tool took too long to start
This is immediately followed by a consumer timeout in the failing cases:
[INFO - 2017-07-18 14:26:46,907 - runner_client - log - lineno:221]: RunnerClient: kafkatest.tests.core.security_rolling_upgrade_test.TestSecurityRollingUpgrade.test_rolling_upgrade_phase_two.broker_protocol=SASL_SSL.client_protocol=SASL_SSL: FAIL: Consumer failed to consume messages for 60s. Traceback (most recent call last): File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/venv/local/lib/python2.7/site-packages/ducktape-0.6.0-py2.7.egg/ducktape/tests/runner_client.py", line 123, in run data = self.run_test() File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/venv/local/lib/python2.7/site-packages/ducktape-0.6.0-py2.7.egg/ducktape/tests/runner_client.py", line 176, in run_test return self.test_context.function(self.test) File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/venv/local/lib/python2.7/site-packages/ducktape-0.6.0-py2.7.egg/ducktape/mark/_mark.py", line 321, in wrapper return functools.partial(f, *args, **kwargs)(*w_args, **w_kwargs) File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/tests/kafkatest/tests/core/security_rolling_upgrade_test.py", line 148, in test_rolling_upgrade_phase_two self.run_produce_consume_validate(self.roll_in_secured_settings, client_protocol, broker_protocol) File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/tests/kafkatest/tests/produce_consume_validate.py", line 106, in run_produce_consume_validate self.start_producer_and_consumer() File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/tests/kafkatest/tests/produce_consume_validate.py", line 79, in start_producer_and_consumer self.consumer_start_timeout_sec) File "/home/jenkins/workspace/system-test-kafka-0.11.0/kafka/venv/local/lib/python2.7/site-packages/ducktape-0.6.0-py2.7.egg/ducktape/utils/util.py", line 36, in wait_until raise TimeoutError(err_msg) TimeoutError: Consumer failed to consume messages for 60s.
There does not appear to be anything wrong with the consumer in the logs, so the timeout seems to be caused by the Jmx tool timeout.
Possibly due to https://github.com/apache/kafka/pull/3447/files?
