Make autest ts shutdown tests more reliable (#9391)

This is a second iteration to further improve some of the autests that
exercise ATS shutting down during test execution. See #9372 for the
previous patch. The previous update improved reliability, but still had
a race condition between autest recognizing ATS process shutdown and ATS
writing the expected error log. If it detected the ts process ending
before the log was written, the autest would fail because the framework
thought the process ended before the Ready condition was satisfied. This
patch addresses this by using a separate process to wait upon the log
entry instead of making the ts Ready condition the content of the log
file.

Author: bneradt

tests/gold_tests/remap/remap_load_empty_failure.test.py

@@ -24,9 +24,19 @@
 ts.Disk.remap_config.AddLine(f"")  # empty file
 ts.Disk.records_config.update({'proxy.config.url_remap.min_rules_required': 1})
 ts.ReturnCode = 33  # expect to Emergency fail due to empty "remap.config".
-ts.Ready = When.FileContains(ts.Disk.diags_log.Name, "remap.config failed to load")
+ts.Ready = 0
 
 tr = Test.AddTestRun("test")
+
+# We have to wait upon TS to emit the expected log message, but it cannot be
+# the ts Ready criteria because autest might detect the process going away
+# before it detects the log message. So we add a separate process that waits
+# upon the log message.
+watcher = Test.Processes.Process("watcher")
+watcher.Command = "sleep 1"
+watcher.Ready = When.FileContains(ts.Disk.diags_log.Name, "remap.config failed to load")
+watcher.StartBefore(ts)
+
 tr.Processes.Default.Command = "echo howdy"
 tr.TimeOut = 5
-tr.Processes.Default.StartBefore(ts)
+tr.Processes.Default.StartBefore(watcher)

tests/gold_tests/shutdown/emergency.test.py

@@ -40,14 +40,23 @@
 # Load plugin
 Test.PrepareTestPlugin(os.path.join(Test.Variables.AtsTestPluginsDir, 'emergency_shutdown.so'), ts)
 
-# www.example.com Host
 tr = Test.AddTestRun()
+
+# We have to wait upon TS to emit the expected log message, but it cannot be
+# the ts Ready criteria because autest might detect the process going away
+# before it detects the log message. So we add a separate process that waits
+# upon the log message.
+watcher = Test.Processes.Process("watcher")
+watcher.Command = "sleep 1"
+watcher.Ready = When.FileContains(ts.Disk.diags_log.Name, "testing emergency shutdown")
+watcher.StartBefore(ts)
+
 tr.Processes.Default.Command = 'printf "Emergency Shutdown Test"'
 tr.Processes.Default.ReturnCode = 0
-tr.Processes.Default.StartBefore(ts)
-tr.Timeout = 5
+tr.Processes.Default.StartBefore(watcher)
 
+tr.Timeout = 5
 ts.ReturnCode = 33
-ts.Ready = When.FileContains(ts.Disk.traffic_out.Name, "testing emergency shutdown")
+ts.Ready = 0
 ts.Disk.traffic_out.Content = Testers.ExcludesExpression('failed to shutdown', 'should NOT contain "failed to shutdown"')
 ts.Disk.diags_log.Content = Testers.IncludesExpression('testing emergency shutdown', 'should contain "testing emergency shutdown"')

tests/gold_tests/shutdown/fatal.test.py

@@ -40,14 +40,23 @@
 # Load plugin
 Test.PrepareTestPlugin(os.path.join(Test.Variables.AtsTestPluginsDir, 'fatal_shutdown.so'), ts)
 
-# www.example.com Host
 tr = Test.AddTestRun()
+
+# We have to wait upon TS to emit the expected log message, but it cannot be
+# the ts Ready criteria because autest might detect the process going away
+# before it detects the log message. So we add a separate process that waits
+# upon the log message.
+watcher = Test.Processes.Process("watcher")
+watcher.Command = "sleep 1"
+watcher.Ready = When.FileContains(ts.Disk.diags_log.Name, "testing fatal shutdown")
+watcher.StartBefore(ts)
+
 tr.Processes.Default.Command = 'printf "Fatal Shutdown Test"'
 tr.Processes.Default.ReturnCode = 0
-tr.Processes.Default.StartBefore(ts)
-tr.Timeout = 5
+tr.Processes.Default.StartBefore(watcher)
 
+tr.Timeout = 5
 ts.ReturnCode = 70
-ts.Ready = When.FileContains(ts.Disk.traffic_out.Name, "testing fatal shutdown")
+ts.Ready = 0
 ts.Disk.traffic_out.Content = Testers.ExcludesExpression('failed to shutdown', 'should NOT contain "failed to shutdown"')
 ts.Disk.diags_log.Content = Testers.IncludesExpression('testing fatal shutdown', 'should contain "testing fatal shutdown"')