This is an automated email from the ASF dual-hosted git repository.
bneradt pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/trafficserver.git
The following commit(s) were added to refs/heads/master by this push:
new 15e879bb97 sigusr2 autest: simplify Process and Ready objects (#13021)
15e879bb97 is described below
commit 15e879bb97a7f30efaabae808c3d4a8776fa55ea
Author: Brian Neradt <[email protected]>
AuthorDate: Fri Mar 27 17:35:42 2026 -0500
sigusr2 autest: simplify Process and Ready objects (#13021)
Rewrite the sigusr2 autest to drive each scenario from a single
shell helper script instead of a chain of AuTest Processes.
This removes the Ready-condition races from the old test, keeps the
signal and log rotation ordering in one place, and makes the log file
expectations easier to follow. This should address flakiness in the
test that has been seen in CI.
Co-authored-by: bneradt <[email protected]>
---
tests/gold_tests/logging/sigusr2.test.py | 263 ++++++++-------------
.../logging/sigusr2_rotate_custom_log.sh | 101 ++++++++
tests/gold_tests/logging/sigusr2_rotate_diags.sh | 79 +++++++
3 files changed, 281 insertions(+), 162 deletions(-)
diff --git a/tests/gold_tests/logging/sigusr2.test.py
b/tests/gold_tests/logging/sigusr2.test.py
index 397119ab2b..67f85c5a27 100644
--- a/tests/gold_tests/logging/sigusr2.test.py
+++ b/tests/gold_tests/logging/sigusr2.test.py
@@ -18,9 +18,12 @@ Verify support of external log rotation via SIGUSR2.
# limitations under the License.
import os
+import shlex
import sys
TS_PID_SCRIPT = 'ts_process_handler.py'
+ROTATE_DIAGS_SCRIPT = 'sigusr2_rotate_diags.sh'
+ROTATE_CUSTOM_LOG_SCRIPT = 'sigusr2_rotate_custom_log.sh'
class Sigusr2Test:
@@ -29,17 +32,29 @@ class Sigusr2Test:
"""
__ts_counter = 1
- __server = None
-
- def __init__(self):
- self.server = self.__configure_server()
- self.ts = self.__configure_traffic_server()
-
- def __configure_traffic_server(self):
- self._ts_name = "sigusr2_ts{}".format(Sigusr2Test.__ts_counter)
- Sigusr2Test.__ts_counter += 1
- self.ts = Test.MakeATSProcess(self._ts_name)
- self.ts.Disk.records_config.update(
+ __server_counter = 1
+
+ @classmethod
+ def _next_ts_name(cls):
+ ts_name = f"sigusr2_ts{cls.__ts_counter}"
+ cls.__ts_counter += 1
+ return ts_name
+
+ @classmethod
+ def _next_server_name(cls):
+ server_name = f"sigusr2_server{cls.__server_counter}"
+ cls.__server_counter += 1
+ return server_name
+
+ @staticmethod
+ def _make_script_command(script_name, *args):
+ quoted_args = ' '.join(shlex.quote(str(arg)) for arg in args)
+ return f"bash ./{script_name} {quoted_args}"
+
+ def _configure_traffic_server(self, tr):
+ ts_name = self._next_ts_name()
+ ts = tr.MakeATSProcess(ts_name)
+ ts.Disk.records_config.update(
{
'proxy.config.http.wait_for_cache': 1,
'proxy.config.diags.debug.enabled': 1,
@@ -50,18 +65,54 @@ class Sigusr2Test:
'proxy.config.log.rolling_enabled': 0,
'proxy.config.log.auto_delete_rolled_files': 0,
})
+ return ts, ts_name
- self.diags_log = self.ts.Disk.diags_log.AbsPath
+ def _configure_server(self):
+ server = Test.MakeOriginServer(self._next_server_name())
- # Add content handles for the rotated logs.
- self.rotated_diags_log = self.diags_log + "_old"
- self.ts.Disk.File(self.rotated_diags_log, id="diags_log_old")
+ for path in ['/first', '/second', '/third']:
+ request_header = {
+ 'headers': f'GET {path} HTTP/1.1\r\nHost:
does.not.matter\r\n\r\n',
+ 'timestamp': '1469733493.993',
+ 'body': ''
+ }
+ response_header = {
+ 'headers': 'HTTP/1.1 200 OK\r\n'
+ 'Connection: close\r\n'
+ 'Cache-control: max-age=85000\r\n\r\n',
+ 'timestamp': '1469733493.993',
+ 'body': 'xxx'
+ }
+ server.addResponse('sessionlog.json', request_header,
response_header)
+
+ return server
- self.log_dir = os.path.dirname(self.diags_log)
+ def add_system_log_test(self):
+ tr = Test.AddTestRun('Verify system logs can be rotated')
+ ts, ts_name = self._configure_traffic_server(tr)
- self.ts.Disk.remap_config.AddLine(
- 'map http://127.0.0.1:{0}
http://127.0.0.1:{1}'.format(self.ts.Variables.port,
self.server.Variables.Port))
- self.ts.Disk.logging_yaml.AddLine(
+ rotated_diags_log = f'{ts.Disk.diags_log.AbsPath}_old'
+ ts.Disk.File(rotated_diags_log, id='diags_log_old')
+
+ tr.Processes.Default.Command = self._make_script_command(
+ ROTATE_DIAGS_SCRIPT, sys.executable, f'./{TS_PID_SCRIPT}',
ts_name, ts.Disk.diags_log.AbsPath, rotated_diags_log)
+ tr.Processes.Default.ReturnCode = 0
+ tr.Processes.Default.StartBefore(ts)
+
+ ts.Disk.diags_log.Content += Testers.ExcludesExpression(
+ 'traffic server running', 'The new diags.log should not reference
the running traffic server')
+ ts.Disk.diags_log.Content += Testers.ContainsExpression(
+ 'Reseated diags.log', 'The new diags.log should indicate the newly
opened diags.log')
+ ts.Disk.diags_log_old.Content += Testers.ContainsExpression(
+ 'traffic server running', 'The rotated diags.log should keep the
original startup message')
+
+ def add_configured_log_test(self):
+ tr = Test.AddTestRun('Verify yaml.log logs can be rotated')
+ ts, ts_name = self._configure_traffic_server(tr)
+ server = self._configure_server()
+
+ ts.Disk.remap_config.AddLine(f'map
http://127.0.0.1:{ts.Variables.port} http://127.0.0.1:{server.Variables.Port}')
+ ts.Disk.logging_yaml.AddLine(
'''
logging:
formats:
@@ -71,155 +122,43 @@ class Sigusr2Test:
- filename: test_rotation
format: has_path
''')
- self.configured_log = os.path.join(self.log_dir, "test_rotation.log")
- self.ts.Disk.File(self.configured_log, id="configured_log")
-
- self.rotated_configured_log = self.configured_log + "_old"
- self.ts.Disk.File(self.rotated_configured_log, id="configured_log_old")
- self.ts.StartBefore(self.server)
- return self.ts
-
- def __configure_server(self):
- if Sigusr2Test.__server:
- return Sigusr2Test.__server
- server = Test.MakeOriginServer("server")
- Sigusr2Test.__server = server
- for path in ['/first', '/second', '/third']:
- request_header = {
- "headers": "GET {} HTTP/1.1\r\n"
- "Host: does.not.matter\r\n\r\n".format(path),
- "timestamp": "1469733493.993",
- "body": ""
- }
- response_header = {
- "headers": "HTTP/1.1 200 OK\r\n"
- "Connection: close\r\n"
- "Cache-control: max-age=85000\r\n\r\n",
- "timestamp": "1469733493.993",
- "body": "xxx"
- }
- server.addResponse("sessionlog.json", request_header,
response_header)
- return server
-
- def get_sigusr2_signal_command(self):
- """
- Return the command that will send a USR2 signal to the traffic server
- process.
- """
- return (f"{sys.executable} {TS_PID_SCRIPT} "
- f"--signal SIGUSR2 {self._ts_name}")
-
-
-Test.Summary = '''
-Verify support of external log rotation via SIGUSR2.
-'''
-Test.Setup.CopyAs(TS_PID_SCRIPT, Test.RunDirectory)
+ configured_log = os.path.join(ts.Variables.LOGDIR, 'test_rotation.log')
+ ts.Disk.File(configured_log, id='configured_log')
-#
-# Test 1: Verify SIGUSR2 behavior for system logs.
-#
-tr1 = Test.AddTestRun("Verify system logs can be rotated")
+ rotated_configured_log = f'{configured_log}_old'
+ ts.Disk.File(rotated_configured_log, id='configured_log_old')
-# Configure Server.
-diags_test = Sigusr2Test()
+ ts.StartBefore(server)
+ tr.Processes.Default.Command = self._make_script_command(
+ ROTATE_CUSTOM_LOG_SCRIPT, sys.executable, f'./{TS_PID_SCRIPT}',
ts_name, ts.Variables.port, configured_log,
+ rotated_configured_log)
+ tr.Processes.Default.ReturnCode = 0
+ tr.Processes.Default.StartBefore(ts)
-# Configure our rotation processes.
-rotate_diags_log = tr1.Processes.Process("rotate_diags_log", "mv {}
{}".format(diags_test.diags_log, diags_test.rotated_diags_log))
+ ts.Disk.configured_log.Content += Testers.ExcludesExpression(
+ '/first', 'The new test_rotation.log should not have the first GET
retrieval in it.')
+ ts.Disk.configured_log.Content += Testers.ExcludesExpression(
+ '/second', 'The new test_rotation.log should not have the second
GET retrieval in it.')
+ ts.Disk.configured_log.Content += Testers.ContainsExpression(
+ '/third', 'The new test_rotation.log should have the third GET
retrieval in it.')
-# Configure the signaling of SIGUSR2 to traffic_server.
-tr1.Processes.Default.Command = diags_test.get_sigusr2_signal_command()
-tr1.Processes.Default.Return = 0
-tr1.Processes.Default.Ready = When.FileExists(diags_test.diags_log)
+ ts.Disk.configured_log_old.Content += Testers.ContainsExpression(
+ '/first', 'test_rotation.log_old should have the first GET
retrieval in it.')
+ ts.Disk.configured_log_old.Content += Testers.ContainsExpression(
+ '/second', 'test_rotation.log_old should have the second GET
retrieval in it.')
+ ts.Disk.configured_log_old.Content += Testers.ExcludesExpression(
+ '/third', 'test_rotation.log_old should not have the third GET
retrieval in it.')
-# Configure process order.
-tr1.Processes.Default.StartBefore(rotate_diags_log)
-rotate_diags_log.StartBefore(diags_test.ts)
-tr1.StillRunningAfter = diags_test.ts
-tr1.StillRunningAfter = diags_test.server
-# diags.log should have been rotated. The old one had the reference to traffic
-# server running, this new one shouldn't. But it should indicate that the new
-# diags.log was opened.
-diags_test.ts.Disk.diags_log.Content += Testers.ExcludesExpression(
- "traffic server running", "The new diags.log should not reference the
running traffic server")
+Test.Summary = '''
+Verify support of external log rotation via SIGUSR2.
+'''
-diags_test.ts.Disk.diags_log.Content += Testers.ContainsExpression(
- "Reseated diags.log", "The new diags.log should indicate the newly opened
diags.log")
+Test.Setup.Copy(TS_PID_SCRIPT)
+Test.Setup.Copy(ROTATE_DIAGS_SCRIPT)
+Test.Setup.Copy(ROTATE_CUSTOM_LOG_SCRIPT)
-#
-# Test 2: Verify SIGUSR2 isn't needed for rotated configured logs.
-#
-tr2 = Test.AddTestRun("Verify yaml.log logs can be rotated")
-configured_test = Sigusr2Test()
-
-first_curl = tr2.Processes.Process(
- "first_curl", 'curl "http://127.0.0.1:{0}/first";
--verbose'.format(configured_test.ts.Variables.port))
-# Note that for each of these processes, aside from the final Default one, they
-# are all treated like long-running servers to AuTest. Thus the long sleeps
-# only allow us to wait until the logs get populated with the desired content,
-# the test will not wait the entire time for them to complete.
-first_curl_ready = tr2.Processes.Process("first_curl_ready", 'sleep 30')
-# In the autest environment, it can take more than 10 seconds for the log file
to be created.
-first_curl_ready.StartupTimeout = 30
-first_curl_ready.Ready = When.FileContains(configured_test.configured_log,
"/first")
-
-rotate_log = tr2.Processes.Process(
- "rotate_log_file", "mv {} {}".format(configured_test.configured_log,
configured_test.rotated_configured_log))
-
-second_curl = tr2.Processes.Process(
- "second_curl", 'curl "http://127.0.0.1:{0}/second";
--verbose'.format(configured_test.ts.Variables.port))
-
-second_curl_ready = tr2.Processes.Process("second_curl_ready", 'sleep 30')
-# In the autest environment, it can take more than 10 seconds for the log file
to be created.
-second_curl_ready.StartupTimeout = 30
-second_curl_ready.Ready =
When.FileContains(configured_test.rotated_configured_log, "/second")
-
-send_pkill = tr2.Processes.Process("Send_SIGUSR2",
configured_test.get_sigusr2_signal_command())
-send_pkill_ready = tr2.Processes.Process("send_pkill_ready", 'sleep 30')
-send_pkill_ready.StartupTimeout = 30
-send_pkill_ready.Ready = When.FileExists(configured_test.configured_log)
-
-third_curl = tr2.Processes.Process(
- "third_curl", 'curl "http://127.0.0.1:{0}/third";
--verbose'.format(configured_test.ts.Variables.port))
-third_curl_ready = tr2.Processes.Process("third_curl_ready", 'sleep 30')
-# In the autest environment, it can take more than 10 seconds for the log file
to be created.
-third_curl_ready.StartupTimeout = 30
-third_curl_ready.Ready = When.FileContains(configured_test.configured_log,
"/third")
-
-tr2.Processes.Default.Command = "echo waiting for test processes to be done"
-tr2.Processes.Default.Return = 0
-
-# Configure process order:
-# 1. curl /first. The entry should be logged to current log which will be
_old.
-# 2. mv the log to _old.
-# 3. curl /second. The entry should end up in _old log.
-# 4. Send a SIGUSR2 to traffic_server. The log should be recreated.
-# 5. curl /third. The entry should end up in the new, non-old, log file.
-#
-tr2.Processes.Default.StartBefore(third_curl_ready)
-third_curl_ready.StartBefore(third_curl)
-third_curl.StartBefore(send_pkill_ready)
-send_pkill_ready.StartBefore(send_pkill)
-send_pkill.StartBefore(second_curl_ready)
-second_curl_ready.StartBefore(second_curl)
-second_curl.StartBefore(rotate_log)
-rotate_log.StartBefore(first_curl_ready)
-first_curl_ready.StartBefore(first_curl)
-first_curl.StartBefore(configured_test.ts)
-tr2.StillRunningAfter = configured_test.ts
-
-# Verify that the logs are in the correct files.
-configured_test.ts.Disk.configured_log.Content += Testers.ExcludesExpression(
- "/first", "The new test_rotation.log should not have the first GET
retrieval in it.")
-configured_test.ts.Disk.configured_log.Content += Testers.ExcludesExpression(
- "/second", "The new test_rotation.log should not have the second GET
retrieval in it.")
-configured_test.ts.Disk.configured_log.Content += Testers.ContainsExpression(
- "/third", "The new test_rotation.log should have the third GET retrieval
in it.")
-
-configured_test.ts.Disk.configured_log_old.Content +=
Testers.ContainsExpression(
- "/first", "test_rotation.log_old should have the first GET retrieval in
it.")
-configured_test.ts.Disk.configured_log_old.Content +=
Testers.ContainsExpression(
- "/second", "test_rotation.log_old should have the second GET retrieval in
it.")
-configured_test.ts.Disk.configured_log_old.Content +=
Testers.ExcludesExpression(
- "/third", "test_rotation.log_old should not have the third GET retrieval
in it.")
+sigusr2_test = Sigusr2Test()
+sigusr2_test.add_system_log_test()
+sigusr2_test.add_configured_log_test()
diff --git a/tests/gold_tests/logging/sigusr2_rotate_custom_log.sh
b/tests/gold_tests/logging/sigusr2_rotate_custom_log.sh
new file mode 100644
index 0000000000..80b915f998
--- /dev/null
+++ b/tests/gold_tests/logging/sigusr2_rotate_custom_log.sh
@@ -0,0 +1,101 @@
+#!/usr/bin/env bash
+#
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+set -eu
+
+if [ "$#" -ne 6 ]; then
+ echo "Usage: $0 <python> <handler> <ts_name> <ats_port> <configured_log>
<rotated_configured_log>" >&2
+ exit 2
+fi
+
+python_bin="$1"
+handler="$2"
+ts_name="$3"
+ats_port="$4"
+configured_log="$5"
+rotated_configured_log="$6"
+base_url="http://127.0.0.1:${ats_port}";
+
+wait_for_file() {
+ path="$1"
+ tries="$2"
+ attempt=0
+
+ while [ "$attempt" -lt "$tries" ]; do
+ if [ -f "$path" ]; then
+ return 0
+ fi
+ sleep 1
+ attempt=$((attempt + 1))
+ done
+
+ echo "Timed out waiting for file: $path" >&2
+ return 1
+}
+
+wait_for_contains() {
+ path="$1"
+ needle="$2"
+ tries="$3"
+ attempt=0
+
+ while [ "$attempt" -lt "$tries" ]; do
+ if [ -f "$path" ] && grep -F "$needle" "$path" >/dev/null 2>&1; then
+ return 0
+ fi
+ sleep 1
+ attempt=$((attempt + 1))
+ done
+
+ echo "Timed out waiting for '$needle' in $path" >&2
+ return 1
+}
+
+request_path() {
+ path="$1"
+ attempt=0
+
+ while [ "$attempt" -lt 60 ]; do
+ if curl --fail --silent --show-error --output /dev/null --max-time 5
"${base_url}${path}"; then
+ return 0
+ fi
+ sleep 1
+ attempt=$((attempt + 1))
+ done
+
+ echo "Timed out requesting ${base_url}${path}" >&2
+ return 1
+}
+
+rm -f "$configured_log" "$rotated_configured_log"
+
+request_path "/first"
+wait_for_contains "$configured_log" "/first" 60
+
+mv "$configured_log" "$rotated_configured_log"
+
+request_path "/second"
+wait_for_contains "$rotated_configured_log" "/second" 60
+
+# Send the SIGUSR2 signal to the handler to trigger ATS to rotate the log.
+"$python_bin" "$handler" --signal SIGUSR2 "$ts_name"
+
+wait_for_file "$configured_log" 60
+
+request_path "/third"
+wait_for_contains "$configured_log" "/third" 60
diff --git a/tests/gold_tests/logging/sigusr2_rotate_diags.sh
b/tests/gold_tests/logging/sigusr2_rotate_diags.sh
new file mode 100644
index 0000000000..b45bf04ed7
--- /dev/null
+++ b/tests/gold_tests/logging/sigusr2_rotate_diags.sh
@@ -0,0 +1,79 @@
+#!/usr/bin/env bash
+#
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+set -eu
+
+if [ "$#" -ne 5 ]; then
+ echo "Usage: $0 <python> <handler> <ts_name> <diags_log>
<rotated_diags_log>" >&2
+ exit 2
+fi
+
+python_bin="$1"
+handler="$2"
+ts_name="$3"
+diags_log="$4"
+rotated_diags_log="$5"
+
+wait_for_file() {
+ path="$1"
+ tries="$2"
+ attempt=0
+
+ while [ "$attempt" -lt "$tries" ]; do
+ if [ -f "$path" ]; then
+ return 0
+ fi
+ sleep 1
+ attempt=$((attempt + 1))
+ done
+
+ echo "Timed out waiting for file: $path" >&2
+ return 1
+}
+
+wait_for_contains() {
+ path="$1"
+ needle="$2"
+ tries="$3"
+ attempt=0
+
+ while [ "$attempt" -lt "$tries" ]; do
+ if [ -f "$path" ] && grep -F "$needle" "$path" >/dev/null 2>&1; then
+ return 0
+ fi
+ sleep 1
+ attempt=$((attempt + 1))
+ done
+
+ echo "Timed out waiting for '$needle' in $path" >&2
+ return 1
+}
+
+rm -f "$rotated_diags_log"
+
+wait_for_file "$diags_log" 60
+wait_for_contains "$diags_log" "traffic server running" 60
+
+mv "$diags_log" "$rotated_diags_log"
+
+# Send the SIGUSR2 signal to the handler to trigger ATS to rotate the log.
+"$python_bin" "$handler" --signal SIGUSR2 "$ts_name"
+
+wait_for_file "$diags_log" 60
+wait_for_contains "$diags_log" "Reseated diags.log" 60
+wait_for_contains "$rotated_diags_log" "traffic server running" 60
