bneradt commented on code in PR #13540:
URL: https://github.com/apache/trafficserver/pull/13540#discussion_r3909175758
##########
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:
Addressed in `4ee4b62d83`.
The timing path now resets `last_completion` when it observes the first
genuine test-start line. It parses completion status first and requires that
the same line is not already a completion, so combined `Running Test ...
Passed` output cannot collapse the first duration to zero. A one-shot guard
prevents duplicate start markers from resetting the clock again. Later tests
still measure from the previous completion.
Validation in `asfats5`:
- Format, full build, and install passed.
- The timing-aware `cache-control` AuTest passed and recorded its first-test
duration as 40.2 seconds.
--
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]
