Copilot commented on code in PR #13540:
URL: https://github.com/apache/trafficserver/pull/13540#discussion_r3908501157
##########
tests/autest-parallel.py.in:
##########
@@ -517,151 +574,181 @@ def run_worker(
existing = env.get('PYTHONPATH', '')
env['PYTHONPATH'] = ':'.join(pythonpath_dirs + ([existing] if existing
else []))
- if collect_timings:
- # Run tests one at a time to collect accurate timing
- all_output = []
- total_tests = len(tests)
- try:
- for idx, test in enumerate(tests, 1):
- test_name, duration, status, output = run_single_test(
- test, script_dir, sandbox, ats_bin, build_root,
extra_args, env)
- result.test_timings[test_name] = duration
- all_output.append(output)
-
- if status == "PASS":
- result.passed += 1
- elif status == "SKIP":
- result.skipped += 1
- else:
- result.failed += 1
- result.failed_tests.append(test_name)
+ # Keep all tests in one autest process so its shared port queue is not
+ # reset between tests. This is both faster and avoids reusing ports that a
+ # recently completed test may still hold.
+ cmd = [
+ 'uv',
+ 'run',
+ 'autest',
+ 'run',
+ '--directory',
+ '${CMAKE_GOLD_DIR}',
+ '--ats-bin',
+ ats_bin,
+ '--proxy-verifier-bin',
+ '${PROXY_VERIFIER_PATH}',
+ '--build-root',
+ build_root,
+ '--sandbox',
+ str(sandbox),
+ '--filters',
+ ]
+ cmd.extend(f'/{test}' for test in tests)
+ cmd.extend(extra_args)
- timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
- # Fixed-width format: date time status duration worker
progress test_name
- print(
- f"{timestamp} {status:4s} {duration:6.1f}s
Worker:{worker_id:2d} {idx:2d}/{total_tests:2d} {test}", flush=True)
- except KeyboardInterrupt:
- result.return_code = 130
+ timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
+ print(f"{timestamp} Worker:{worker_id:2d} Starting batch of {len(tests)}
tests (port offset {port_offset})", flush=True)
+ if verbose:
+ print(
+ f" Worker:{worker_id:2d} Tests: {', '.join(tests[:5])}"
+ f"{'...' if len(tests) > 5 else ''}",
+ flush=True)
- result.output = "\n".join(all_output)
- if result.return_code != 130:
- result.return_code = 0 if result.failed == 0 else 1
- else:
- # Run all tests in batch (faster but no per-test timing)
- cmd = [
- 'uv',
- 'run',
- 'autest',
- 'run',
- '--directory',
- '${CMAKE_GOLD_DIR}',
- '--ats-bin',
- ats_bin,
- '--proxy-verifier-bin',
- '${PROXY_VERIFIER_PATH}',
- '--build-root',
- build_root,
- '--sandbox',
- str(sandbox),
- ]
-
- # Add test filters
- cmd.append('--filters')
- cmd.extend(tests)
-
- # Add any extra arguments
- cmd.extend(extra_args)
-
- timestamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
- print(f"{timestamp} Worker:{worker_id:2d} Starting batch of
{len(tests)} tests (port offset {port_offset})", flush=True)
- if verbose:
- print(
- f" Worker:{worker_id:2d} Tests: {',
'.join(tests[:5])}"
- f"{'...' if len(tests) > 5 else ''}",
- flush=True)
+ try:
+ if verbose or collect_timings:
+ # Autest flushes each completed test line. Observe those lines to
+ # collect timings without changing how autest executes the batch.
+ proc = subprocess.Popen(
+ cmd,
+ cwd=script_dir,
+ stdout=subprocess.PIPE,
+ stderr=subprocess.STDOUT,
+ text=True,
+ env=env,
+ )
+ output_lines = []
+ output_queue: Queue[Optional[str]] = Queue()
+ output_reader = Thread(target=enqueue_process_output,
args=(proc.stdout, output_queue), daemon=True)
+ output_reader.start()
+ last_completion = time.monotonic()
+ completed_count = 0
+ pending_test = None
+ timed_out = False
+ try:
+ while True:
+ remaining = PER_TEST_TIMEOUT - (time.monotonic() -
last_completion)
+ if remaining <= 0:
+ timed_out = True
+ break
- try:
- if verbose:
- # Stream output in real-time so the user sees test progress.
- # We use Popen + line-by-line read so partial results are
visible
- # even if the overall run takes a long time.
- proc = subprocess.Popen(
- cmd,
- cwd=script_dir,
- stdout=subprocess.PIPE,
- stderr=subprocess.STDOUT,
- text=True,
- env=env,
- )
- output_lines = []
- try:
- for line in proc.stdout:
- output_lines.append(line)
- # Print lines that show test progress
- clean = strip_ansi(line).strip()
- if clean.startswith('Running Test') or 'Passed' in
clean or 'Failed' in clean:
- if clean.startswith('Running Test'):
- ts = datetime.now().strftime("%H:%M:%S")
- print(f" [{ts}] Worker:{worker_id:2d}
{clean}", flush=True)
- # stdout is exhausted, wait for process to finish
+ try:
+ line = output_queue.get(timeout=min(1.0, remaining))
+ except Empty:
+ continue
+
+ if line is None:
+ break
+
+ output_lines.append(line)
+ started_test = parse_test_start(line)
+ if started_test is not None:
+ pending_test = started_test
+ completion = parse_test_completion(line)
+ if completion is None and pending_test is not None:
+ status = parse_detached_test_status(line)
+ if status is not None:
+ completion = pending_test, status
+ if completion is None:
+ continue
+
+ test_name, status = completion
+ pending_test = None
+ now = time.monotonic()
+ duration = now - last_completion
+ last_completion = now
Review Comment:
The first recorded timing currently includes autest process startup/scanning
time because last_completion is initialized before any test starts and
durations are computed from last_completion. Since the timings file is used for
LPT load balancing, this can systematically overestimate whichever test happens
to be first in each worker batch. A low-risk improvement is to reset
last_completion when the first test start marker is observed (only when the
line is a start, not a completion), so the first duration measures from that
test’s start rather than from process launch.
--
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: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
