[IMPALA-8194] TestPauseMonitor.test_jvm_pause_monitor_logs_entries needs to wait longer to see output

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Fix Version/s: Impala 3.2.0
• Labels: broken-build flaky-test
• Epic Color: ghx-label-4
• Assignee: Andrew Sherman
• Reporter: Andrew Sherman
• Created: 13/Feb/19 00:07
• Updated: 14/Mar/19 16:03
• Resolved: 14/Mar/19 16:03

Description

TestPauseMonitor.test_jvm_pause_monitor_logs_entries complains:

FAIL custom_cluster/test_pause_monitor.py::TestPauseMonitor:)::test_jvm_pause_monitor_logs_entries
=================================== FAILURES ===================================
_____________ TestPauseMonitor.test_jvm_pause_monitor_logs_entries _____________
custom_cluster/test_pause_monitor.py:38: in test_jvm_pause_monitor_logs_entries
self.assert_impalad_log_contains('INFO', "Detected pause in JVM or host machine")
common/custom_cluster_test_suite.py:216: in assert_impalad_log_contains
self.assert_log_contains("impalad", level, line_regex, expected_count)
common/custom_cluster_test_suite.py:248: in assert_log_contains
(expected_count, log_file_path, line_regex, found, line)
E AssertionError: Expected 1 lines in file /data0/jenkins/workspace/xxx/repos/Impala/logs/custom_cluster_tests/impalad.impala-xxx.jenkins.log.INFO.20190211-183351.2092 matching regex 'Detected pause in JVM or host machine', but found 0 lines. Last line was:
E I0211 18:34:03.563254 2392 thrift-util.cc:113] TAcceptQueueServer client died: write() send(): Broken pipe

The actual log (archived later) contains:

I0211 18:34:03.563254 2392 thrift-util.cc:113] TAcceptQueueServer client died: write() send(): Broken pipe
I0211 18:34:03.565459 2164 JvmPauseMonitor.java:187] Detected pause in JVM or host machine (eg GC): pause of approximately 4550ms
No GCs detected

so if test_jvm_pause_monitor_logs_entries had waited for 3ms more it would have seen the line it was looking for (assuming the simplest explanation).