Use AddAwaitFileContainsTestRun more in autests (#13034)

bneradt · web-flow · commit 064014b40f2f · 2026-03-30T17:10:26.000-05:00
This switches the migrated gold tests from condwait file polling to
AddAwaitFileContainsTestRun so they wait for stable log content
rather than raw file creation.

This also:

- Makes the await helper safe for regex needles
- Cleans up stale condwait path leftovers from earlier migrations.
diff --git a/tests/gold_tests/autest-site/when.test.ext b/tests/gold_tests/autest-site/when.test.ext
@@ -89,7 +89,7 @@ def AddAwaitFileContainsTestRun(test, name, file_path, needle, desired_count=1)
     '''
     tr = test.AddTestRun(name)
     p = tr.Processes.Default
-    p.Command = f'echo waiting for {needle} in {file_path}'
+    p.Command = f'echo waiting for file content in {file_path}'
     await_process = tr.Processes.Process('await', 'sleep 60')
     await_process.Ready = When.FileContains(file_path, needle, desired_count)
     await_process.StartupTimeout = 30
diff --git a/tests/gold_tests/connect/connect.test.py b/tests/gold_tests/connect/connect.test.py
@@ -94,14 +94,14 @@ def __testCase0(self):
         self.__checkProcessAfter(tr)
 
     def __testAccessLog(self):
-        """Wait for log file to appear, then wait one extra second to make sure TS is done writing it."""
+        """Wait for the access log entry to be written."""
         Test.Disk.File(os.path.join(self.ts.Variables.LOGDIR, 'access.log'), exists=True, content='gold/connect_access.gold')
 
-        tr = Test.AddTestRun()
-        tr.Processes.Default.Command = (
-            os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' +
-            os.path.join(self.ts.Variables.LOGDIR, 'access.log'))
-        tr.Processes.Default.ReturnCode = 0
+        Test.AddAwaitFileContainsTestRun(
+            'Await CONNECT access log entry.',
+            os.path.join(self.ts.Variables.LOGDIR, 'access.log'),
+            'CONNECT',
+        )
 
     def run(self):
         self.__testCase0()
diff --git a/tests/gold_tests/connect_down_policy/connect_down_policy_3.test.py b/tests/gold_tests/connect_down_policy/connect_down_policy_3.test.py
@@ -85,11 +85,11 @@ def _test_inactive_timeout(self):
 
     def _test_mark_down(self):
         if self._expect_mark_down:
-            # Wait for error.log to appear then verify it contains the mark-down entry.
-            tr = Test.AddTestRun(f"policy={self._policy}: check error.log for mark-down")
-            tr.Processes.Default.Command = (
-                os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' +
-                os.path.join(self._ts.Variables.LOGDIR, 'error.log'))
+            tr = Test.AddAwaitFileContainsTestRun(
+                f"policy={self._policy}: check error.log for mark-down",
+                os.path.join(self._ts.Variables.LOGDIR, 'error.log'),
+                "marking down",
+            )
             self._ts.Disk.error_log.Content = Testers.ContainsExpression(
                 "marking down", f"policy={self._policy}: origin should be marked down after inactive timeout")
         else:
diff --git a/tests/gold_tests/dns/dns_host_down.test.py b/tests/gold_tests/dns/dns_host_down.test.py
@@ -65,11 +65,11 @@ def _test_host_mark_down(self):
 
     # Verify error log marking host down exists
     def _test_error_log(self):
-        tr = Test.AddTestRun()
-        tr.Processes.Default.Command = (
-            os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' +
-            os.path.join(self._ts.Variables.LOGDIR, 'error.log'))
-
+        tr = Test.AddAwaitFileContainsTestRun(
+            'Await error.log mark-down entry.',
+            os.path.join(self._ts.Variables.LOGDIR, 'error.log'),
+            "/dns/mark/down' fail_count='1' marking down",
+        )
         self._ts.Disk.error_log.Content = Testers.ContainsExpression(
             "/dns/mark/down' fail_count='1' marking down", "host should be marked down")
 
diff --git a/tests/gold_tests/h2/httpbin.test.py b/tests/gold_tests/h2/httpbin.test.py
@@ -128,8 +128,9 @@
 test_run.Processes.Default.Streams.stderr = Testers.GoldFile("gold/httpbin_3_stderr.gold", case_insensitive=True)
 test_run.StillRunningAfter = httpbin
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-test_run = Test.AddTestRun()
-test_run.Processes.Default.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + os.path.join(ts.Variables.LOGDIR, 'access.log'))
-test_run.Processes.Default.ReturnCode = 0
+# Wait for the POST transaction to be logged.
+Test.AddAwaitFileContainsTestRun(
+    'Await POST access log entry.',
+    os.path.join(ts.Variables.LOGDIR, 'access.log'),
+    r'POST .*?/post',
+)
diff --git a/tests/gold_tests/logging/custom-log.test.py b/tests/gold_tests/logging/custom-log.test.py
@@ -83,9 +83,10 @@
 tr.MakeCurlCommand('"http://127.123.32.243:{0}" --verbose'.format(ts.Variables.port), ts=ts)
 tr.Processes.Default.ReturnCode = 0
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-test_run = Test.AddTestRun()
-test_run.Processes.Default.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' +
-    os.path.join(ts.Variables.LOGDIR, 'test_log_field.log'))
-test_run.Processes.Default.ReturnCode = 0
+# Wait for all expected log lines to be written.
+Test.AddAwaitFileContainsTestRun(
+    'Await custom log lines.',
+    os.path.join(ts.Variables.LOGDIR, 'test_log_field.log'),
+    r'^127\.',
+    8,
+)
diff --git a/tests/gold_tests/logging/log-field-json.test.py b/tests/gold_tests/logging/log-field-json.test.py
@@ -111,9 +111,10 @@
     '--verbose --header "Host: test-2" --header "Foo: ab\x80d/ef" http://localhost:{0}/test-4'.format(ts.Variables.port), ts=ts)
 tr.Processes.Default.ReturnCode = 0
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-test_run = Test.AddTestRun()
-test_run.Processes.Default.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' +
-    os.path.join(ts.Variables.LOGDIR, 'field-json-test.log'))
-test_run.Processes.Default.ReturnCode = 0
+# Wait for all expected log lines to be written.
+Test.AddAwaitFileContainsTestRun(
+    'Await field-json log lines.',
+    os.path.join(ts.Variables.LOGDIR, 'field-json-test.log'),
+    r'^\{"foo":',
+    4,
+)
diff --git a/tests/gold_tests/logging/log-field.test.py b/tests/gold_tests/logging/log-field.test.py
@@ -106,8 +106,10 @@
 tr.MakeCurlCommand('--verbose --header "Host: test-3" http://localhost:{0}/test-3'.format(ts.Variables.port), ts=ts)
 tr.Processes.Default.ReturnCode = 0
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-test_run = Test.AddTestRun()
-test_run.Processes.Default.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + os.path.join(ts.Variables.LOGDIR, 'field-test.log'))
-test_run.Processes.Default.ReturnCode = 0
+# Wait for all expected log lines to be written.
+Test.AddAwaitFileContainsTestRun(
+    'Await field-test log lines.',
+    os.path.join(ts.Variables.LOGDIR, 'field-test.log'),
+    r'^Transfer-Encoding:',
+    3,
+)
diff --git a/tests/gold_tests/logging/log-filenames.test.py b/tests/gold_tests/logging/log-filenames.test.py
@@ -100,16 +100,17 @@ def __configure_traffic_server(self, log_data):
 
     def __configure_await_TestRun(self, log_path):
         ''' Configure a TestRun that awaits upon the provided log_path to
-        exist.
+        contain the sentinel log entry.
 
         Args:
             log_path (str): The log file upon which we will wait.
         '''
         description = self.__description
-        tr = Test.AddTestRun(f'Awaiting log files to be written for: {description}')
-        condwait_path = os.path.join(Test.Variables.AtsTestToolsDir, 'condwait')
-        tr.Processes.Default.Command = f'{condwait_path} 60 1 -f {log_path}'
-        tr.Processes.Default.ReturnCode = 0
+        Test.AddAwaitFileContainsTestRun(
+            f'Awaiting log files to be written for: {description}',
+            log_path,
+            r'^http://127\.0\.0\.1:\d+/: 502$',
+        )
 
     def __configure_traffic_TestRun(self, description):
         ''' Configure a TestRun to run the expected transactions.
diff --git a/tests/gold_tests/logging/log-filter.test.py b/tests/gold_tests/logging/log-filter.test.py
@@ -84,11 +84,13 @@
 tr.Processes.Default.StartBefore(ts)
 tr.AddVerifierClientProcess("client-1", replay_file, http_ports=[ts.Variables.port])
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-test_run = Test.AddTestRun()
-test_run.Processes.Default.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + os.path.join(ts.Variables.LOGDIR, 'filter-test.log'))
-test_run.Processes.Default.ReturnCode = 0
+# Wait for all expected log lines to be written.
+Test.AddAwaitFileContainsTestRun(
+    'Await filtered log lines.',
+    os.path.join(ts.Variables.LOGDIR, 'filter-test.log'),
+    r'^http://example\.com/test-',
+    5,
+)
 
 # We already waited for the above, so we don't have to wait for this one.
 test_run = Test.AddTestRun()
diff --git a/tests/gold_tests/logging/log-mstsms.test.py b/tests/gold_tests/logging/log-mstsms.test.py
@@ -114,8 +114,6 @@ def check_lines(path):
 
 logpath = os.path.join(ts.Variables.LOGDIR, 'field-mstsms.log')
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-tr = Test.AddTestRun()
-tr.Processes.Default.Command = (os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + logpath)
-#tr.Processes.Default.ReturnCode = 0
+# Wait for all expected log lines to be written.
+tr = Test.AddAwaitFileContainsTestRun('Await mstsms log lines.', logpath, r'^mstsms:', 3)
 tr.Streams.All.Content = Testers.Lambda(lambda info, tester: check_lines(logpath))
diff --git a/tests/gold_tests/logging/new_log_flds.test.py b/tests/gold_tests/logging/new_log_flds.test.py
@@ -102,13 +102,13 @@
         ts=ts)
     tr.Processes.Default.ReturnCode = 0
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
+# Wait for the final log line to be written.
 #
-test_run = Test.AddTestRun()
-test_run.Processes.Default.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' +
-    os.path.join(ts.Variables.LOGDIR, 'test_new_log_flds.log'))
-test_run.Processes.Default.ReturnCode = 0
+Test.AddAwaitFileContainsTestRun(
+    'Await new log field output.',
+    os.path.join(ts.Variables.LOGDIR, 'test_new_log_flds.log'),
+    r'reallyreallyreallyreallylong\.com$',
+)
 
 # Validate generated log.
 #
diff --git a/tests/gold_tests/logging/pqsi-pqsp.test.py b/tests/gold_tests/logging/pqsi-pqsp.test.py
@@ -78,10 +78,8 @@
 
 log_filespec = os.path.join(ts.Variables.LOGDIR, 'field-test.log')
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-tr = Test.AddTestRun()
-tr.Processes.Default.Command = (os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + log_filespec)
-tr.Processes.Default.ReturnCode = 0
+# Wait for the cache-hit line to be written.
+Test.AddAwaitFileContainsTestRun('Await pqsi/pqsp cache-hit line.', log_filespec, r'^0 0$')
 
 tr = Test.AddTestRun()
 tr.Processes.Default.Command = "sed '1s/^127.0.0.1 [1-6][0-9]*$$/abc/' < " + log_filespec
diff --git a/tests/gold_tests/pluginTest/money_trace/money_trace.test.py b/tests/gold_tests/pluginTest/money_trace/money_trace.test.py
@@ -197,9 +197,10 @@ def maketrace(name):
     tr.StillRunningAfter = ts
     tr.StillRunningAfter = server
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
+# Wait for the final log line to be written.
 # 11 Test
-tr = Test.AddTestRun()
-ps = tr.Processes.Default
-ps.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + os.path.join(ts.Variables.LOGDIR, 'remap.log'))
+Test.AddAwaitFileContainsTestRun(
+    'Await final money_trace remap log line.',
+    os.path.join(ts.Variables.LOGDIR, 'remap.log'),
+    r'^cqh: not a trace header - trace-id=.* pqh: trace-id=.* - psh: not a trace header -$',
+)
diff --git a/tests/gold_tests/pluginTest/money_trace/money_trace_global.test.py b/tests/gold_tests/pluginTest/money_trace/money_trace_global.test.py
@@ -98,9 +98,9 @@
 tr.StillRunningAfter = ts
 tr.StillRunningAfter = server
 
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-tr = Test.AddTestRun()
-ps = tr.Processes.Default
-ps.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + os.path.join(ts.Variables.LOGDIR, 'global.log'))
-#ps.ReturnCode = 0
+# Wait for the final log line to be written.
+Test.AddAwaitFileContainsTestRun(
+    'Await final money_trace global log line.',
+    os.path.join(ts.Variables.LOGDIR, 'global.log'),
+    r'^cqh: - trace-id=.* pqh: trace-id=.* psh: -$',
+)
diff --git a/tests/gold_tests/pluginTest/prefetch/prefetch_cmcd.test.py b/tests/gold_tests/pluginTest/prefetch/prefetch_cmcd.test.py
@@ -273,8 +273,6 @@
 tr.MakeCurlCommand(f"--verbose --proxy 127.0.0.1:{ts0.Variables.port} \'http://ts0/{crr_name}\' -H \'{crr_header}\'", ts=ts0)
 tr.Processes.Default.ReturnCode = 0
 
-condwaitpath = os.path.join(Test.Variables.AtsTestToolsDir, 'condwait')
-
 ts0log = os.path.join(ts0.Variables.LOGDIR, 'transaction.log')
 Test.AddAwaitFileContainsTestRun('Await ts transactions to finish logging.', ts0log, 'crr.txt')
 
diff --git a/tests/gold_tests/pluginTest/slice/slice_crr_ident.test.py b/tests/gold_tests/pluginTest/slice/slice_crr_ident.test.py
@@ -210,8 +210,6 @@
 ps.Streams.stdout.Content = Testers.ContainsExpression("404", "expected 404 Not Found response")
 tr.StillRunningAfter = ts
 
-condwaitpath = os.path.join(Test.Variables.AtsTestToolsDir, 'condwait')
-
 tslog = os.path.join(ts.Variables.LOGDIR, 'transaction.log')
 Test.AddAwaitFileContainsTestRun('Await ts transactions to finish logging.', tslog, '404.txt')
 
diff --git a/tests/gold_tests/pluginTest/slice/slice_ident.test.py b/tests/gold_tests/pluginTest/slice/slice_ident.test.py
@@ -177,7 +177,6 @@
 tr.StillRunningAfter = ts
 
 # 7 - wait for logs
-condwaitpath = os.path.join(Test.Variables.AtsTestToolsDir, 'condwait')
 tslog = os.path.join(ts.Variables.LOGDIR, 'transaction.log')
 Test.AddAwaitFileContainsTestRun('Await ts transactions to finish logging.', tslog, '404.txt')
 
diff --git a/tests/gold_tests/pluginTest/slice/slice_prefetch.test.py b/tests/gold_tests/pluginTest/slice/slice_prefetch.test.py
@@ -174,8 +174,10 @@
 
 # 6 Test - All requests (client & slice internal) logs to see background fetches
 cache_file = os.path.join(ts.Variables.LOGDIR, 'cache.log')
-# Wait for log file to appear, then wait one extra second to make sure TS is done writing it.
-test_run = Test.AddTestRun("Checking debug logs for background fetches")
-test_run.Processes.Default.Command = (os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + cache_file)
+# Wait for the final cache log line to be written.
+test_run = Test.AddAwaitFileContainsTestRun(
+    "Checking debug logs for background fetches",
+    cache_file,
+    r'\*/18 hit-fresh, none$',
+)
 ts.Disk.File(cache_file).Content = "gold/slice_prefetch.gold"
-test_run.Processes.Default.ReturnCode = 0
diff --git a/tests/gold_tests/proxy_protocol/proxy_protocol.test.py b/tests/gold_tests/proxy_protocol/proxy_protocol.test.py
@@ -94,13 +94,12 @@ def checkAccessLog(self):
         """
         Test.Disk.File(os.path.join(self.ts.Variables.LOGDIR, 'access.log'), exists=True, content=f"gold/access-{self.name}.gold")
 
-        # Wait for log file to appear, then wait one extra second to make sure
-        # TS is done writing it.
-        tr = Test.AddTestRun()
-        tr.Processes.Default.Command = (
-            os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' +
-            os.path.join(self.ts.Variables.LOGDIR, 'access.log'))
-        tr.Processes.Default.ReturnCode = 0
+        Test.AddAwaitFileContainsTestRun(
+            f'Await PROXY protocol access log lines. {self.name}',
+            os.path.join(self.ts.Variables.LOGDIR, 'access.log'),
+            r'^127\.0\.0\.1 0 127\.0\.0\.1$',
+            2,
+        )
 
     def run(self):
         self.runTraffic()
diff --git a/tests/gold_tests/tls/tls_sni_host_policy.test.py b/tests/gold_tests/tls/tls_sni_host_policy.test.py
@@ -187,10 +187,12 @@
 tr.Processes.Default.ReturnCode = 0
 tr.Processes.Default.Streams.All = Testers.ExcludesExpression("Access Denied", "Check response")
 
-# Wait for the error.log to appaer.
-test_run = Test.AddTestRun()
-test_run.Processes.Default.Command = (
-    os.path.join(Test.Variables.AtsTestToolsDir, 'condwait') + ' 60 1 -f ' + os.path.join(ts.Variables.LOGDIR, 'error.log'))
+# Wait for the error.log entry to be written.
+test_run = Test.AddAwaitFileContainsTestRun(
+    'Await SNI mismatch error log entry.',
+    os.path.join(ts.Variables.LOGDIR, 'error.log'),
+    "SNI/hostname mismatch: connecting to .* for host='bob' sni='dave', returning a 403",
+)
 
 ts.Disk.diags_log.Content += Testers.ContainsExpression(
     "WARNING: SNI/hostname mismatch sni=dave host=bob action=terminate", "Should have warning on mismatch")
