vamossagar12 commented on PR #15915: URL: https://github.com/apache/kafka/pull/15915#issuecomment-2163555103
Thanks for the explanation Chris. Yeah even I felt that 10s on it's own is a high enough timeout value. I looked at the logs again within the 436 folder above but what I see is that these [lines of code](https://github.com/apache/kafka/blob/trunk/tests/kafkatest/tests/connect/connect_distributed_test.py#L475-L497) are getting executed, as can be seen in the logs ``` [DEBUG - 2024-05-08 21:10:09,370 - connect - _rest - lineno:265]: Kafka Connect REST request: worker4 http://10.140.42.37:8083/admin/loggers GET None [DEBUG - 2024-05-08 21:10:09,508 - connect - _rest - lineno:267]: http://10.140.42.37:8083/admin/loggers GET response: 200 [DEBUG - 2024-05-08 21:10:09,508 - connect_distributed_test - test_dynamic_logging - lineno:475]: Listed all loggers via REST API: {'org.reflections': {'level': 'ERROR', 'last_modified': None}, 'root': {'level': 'DEBUG', 'last_modified': None}} [DEBUG - 2024-05-08 21:10:09,508 - connect - _rest - lineno:265]: Kafka Connect REST request: worker4 http://10.140.42.37:8083/admin/loggers/org.reflections GET None [DEBUG - 2024-05-08 21:10:09,526 - connect - _rest - lineno:267]: http://10.140.42.37:8083/admin/loggers/org.reflections GET response: 200 [DEBUG - 2024-05-08 21:10:09,527 - connect - _rest - lineno:265]: Kafka Connect REST request: worker4 http://10.140.42.37:8083/admin/loggers/org.reflections PUT {'level': 'INFO'} [DEBUG - 2024-05-08 21:10:09,553 - connect - _rest - lineno:267]: http://10.140.42.37:8083/admin/loggers/org.reflections PUT response: 200 [DEBUG - 2024-05-08 21:10:09,553 - connect - _rest - lineno:265]: Kafka Connect REST request: worker4 http://10.140.42.37:8083/admin/loggers GET None [DEBUG - 2024-05-08 21:10:09,568 - connect - _rest - lineno:267]: http://10.140.42.37:8083/admin/loggers GET response: 200 [DEBUG - 2024-05-08 21:10:09,568 - connect_distributed_test - _loggers_are_set - lineno:619]: Read loggers on <ducktape.cluster.cluster.ClusterNode object at 0x7fb6526bed68> from Connect REST API: {'org.reflections': {'level': 'INFO', 'last_modified': 1715202609537}, 'root': {'level': 'DEBUG', 'last_modified': None}} [DEBUG - 2024-05-08 21:10:09,568 - connect - _rest - lineno:265]: Kafka Connect REST request: worker10 http://10.140.57.125:8083/admin/loggers GET None [DEBUG - 2024-05-08 21:10:09,729 - connect - _rest - lineno:267]: http://10.140.57.125:8083/admin/loggers GET response: 200 [DEBUG - 2024-05-08 21:10:09,729 - connect_distributed_test - _loggers_are_set - lineno:619]: Read loggers on <ducktape.cluster.cluster.ClusterNode object at 0x7fb6526bec88> from Connect REST API: {'org.reflections': {'level': 'ERROR', 'last_modified': None}, 'root': {'level': 'DEBUG', 'last_modified': None}} [DEBUG - 2024-05-08 21:10:09,729 - connect - _rest - lineno:265]: Kafka Connect REST request: worker24 http://10.140.39.52:8083/admin/loggers GET None [DEBUG - 2024-05-08 21:10:09,883 - connect - _rest - lineno:267]: http://10.140.39.52:8083/admin/loggers GET response: 200 [DEBUG - 2024-05-08 21:10:09,883 - connect_distributed_test - _loggers_are_set - lineno:619]: Read loggers on <ducktape.cluster.cluster.ClusterNode object at 0x7fb6526beba8> from Connect REST API: {'org.reflections': {'level': 'ERROR', 'last_modified': None}, 'root': {'level': 'DEBUG', 'last_modified': None}} [DEBUG - 2024-05-08 21:10:09,883 - connect - _rest - lineno:265]: Kafka Connect REST request: worker4 http://10.140.42.37:8083/admin/loggers/root?scope=cluster PUT {'level': 'DEBUG'} [DEBUG - 2024-05-08 21:10:09,898 - connect - _rest - lineno:267]: http://10.140.42.37:8083/admin/loggers/root?scope=cluster PUT response: 204 [DEBUG - 2024-05-08 21:10:09,899 - connect - _rest - lineno:265]: Kafka Connect REST request: worker4 http://10.140.42.37:8083/admin/loggers/root?scope=cluster PUT {'level': 'INFO'} [DEBUG - 2024-05-08 21:10:09,914 - connect - _rest - lineno:267]: http://10.140.42.37:8083/admin/loggers/root?scope=cluster PUT response: 204 [DEBUG - 2024-05-08 21:10:09,915 - connect - _rest - lineno:265]: Kafka Connect REST request: worker4 http://10.140.42.37:8083/admin/loggers GET None [DEBUG - 2024-05-08 21:10:09,926 - connect - _rest - lineno:267]: http://10.140.42.37:8083/admin/loggers GET response: 200 ``` It is only after this line that I see the assert getting stuck on ``` [DEBUG - 2024-05-08 21:10:09,926 - connect_distributed_test - _loggers_are_set - lineno:619]: Read loggers on <ducktape.cluster.cluster.ClusterNode object at 0x7fb6526bed68> from Connect REST API: ``` and printing large blurbs of lines multiple times, and eventually failing with ``` [INFO - 2024-05-08 21:11:06,638 - runner_client - log - lineno:310]: RunnerClient: kafkatest.tests.connect.connect_distributed_test.ConnectDistributedTest.test_dynamic_logging: FAIL: AssertionError() Traceback (most recent call last): File "/home/jenkins/workspace/system-test-kafka-branch-builder/kafka/venv/lib/python3.7/site-packages/ducktape/tests/runner_client.py", line 184, in _do_run data = self.run_test() File "/home/jenkins/workspace/system-test-kafka-branch-builder/kafka/venv/lib/python3.7/site-packages/ducktape/tests/runner_client.py", line 262, in run_test return self.test_context.function(self.test) File "/home/jenkins/workspace/system-test-kafka-branch-builder/kafka/tests/kafkatest/tests/connect/connect_distributed_test.py", line 500, in test_dynamic_logging assert self._loggers_are_set(new_level, request_time, namespace, workers=[worker]) AssertionError ``` While I agree that the `/connectors` query might not be the best way to assert that the worker is well and truly up, in this case I would like to believe that the workers was up. -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: jira-unsubscr...@kafka.apache.org For queries about this service, please contact Infrastructure at: us...@infra.apache.org