diff --git a/GOALS-archive.md b/GOALS-archive.md index 3774d2e5..77ef3235 100644 --- a/GOALS-archive.md +++ b/GOALS-archive.md @@ -96,3 +96,7 @@ Acceptance: the analysis command reports the two known real cases from the G-041 ### G-082 [achieved 2026-07-14] punk::args single-form parse error selection: specific validation failures preferred over generic overflow → detail: goals/archive/G-082-punkargs-error-selection.md Scope: src/modules/punk/args-999999.0a1.0.tm (get_dict/parse error selection, validation-failure capture around the choice/type screens), src/tests/modules/punk/args/testsuites/args/ (characterization + regression suite) Acceptance: a definition with an optional choice-restricted leader or value that receives a non-matching word reports a choiceviolation-class error naming the word and the allowed choices (message and -errorcode), not toomanyarguments - pinned for the make.tcl-style dispatch shape (optional subcommand leader with choices) and a values-position equivalent; a word rejected by a typed optional argument (e.g int) that then overflows reports the type failure similarly; genuinely-surplus cases (all optional args satisfied, extra word remains) still report toomanyarguments; multiform error selection (rank_form_failures) is unchanged or its pins deliberately updated; current 0.12.x behaviour is characterized first and the pins flipped deliberately; full punk::args suite passes with no expectations weakened; on completion the G-030 -optional 0 workaround sites are revisited (make.tcl dispatch definitions, the src/modules/AGENTS.md "punk::args definition authoring ergonomics" bullet) and relaxed or re-documented. + +### G-091 [achieved 2026-07-19] runtests multiprocess parallelism (-jobs N) → detail: goals/archive/G-091-runtests-parallel-jobs.md +Scope: src/tests/runtests.tcl, src/tests/testsupport/, src/tests/AGENTS.md +Acceptance: -jobs 8 produces aggregate results identical to -jobs 1 (scriptlib/developer/runtests_parity.tcl reports PARITY ok) across repeated full-suite runs on a native tclsh 9.0.x, reduces full-suite wall time by at least 2.5x versus the sequential baseline on the reference machine, leaves the repo clean after runs (git status unchanged), and src/tests/AGENTS.md documents the -jobs flag and the serial-group policy. diff --git a/GOALS.md b/GOALS.md index fcedb9d8..f1178197 100644 --- a/GOALS.md +++ b/GOALS.md @@ -341,7 +341,3 @@ Detail: goals/G-089-scriptlib-kits-and-modes.md ### G-090 [proposed] shellfilter/shellthread stack and log-worker lifecycle audit Scope: src/modules/shellfilter-999999.0a1.0.tm (stack placement, insert_transform, junctions), src/modules/shellthread-999999.0a1.0.tm (worker park/adoption/termination), src/tests/modules/ (new characterization suites), README.md ('very unripe parts' note) Detail: goals/G-090-shellfilter-shellthread-audit.md - -### G-091 [proposed] runtests multiprocess parallelism (-jobs N) -Scope: src/tests/runtests.tcl, src/tests/testsupport/, src/tests/AGENTS.md -Detail: goals/G-091-runtests-parallel-jobs.md diff --git a/goals/G-091-runtests-parallel-jobs.md b/goals/archive/G-091-runtests-parallel-jobs.md similarity index 55% rename from goals/G-091-runtests-parallel-jobs.md rename to goals/archive/G-091-runtests-parallel-jobs.md index 16391005..9d760ae6 100644 --- a/goals/G-091-runtests-parallel-jobs.md +++ b/goals/archive/G-091-runtests-parallel-jobs.md @@ -1,6 +1,6 @@ # G-091 runtests multiprocess parallelism (-jobs N) -Status: proposed +Status: achieved 2026-07-19 Scope: src/tests/runtests.tcl, src/tests/testsupport/, src/tests/AGENTS.md Goal: src/tests/runtests.tcl runs multi-process mode's per-file child processes through a -jobs N worker pool (tpool; per-child tmpdirs and output files; longest-first scheduling; a serial group for console-sensitive suites; per-file report sections emitted in discovery order) so the full source-tree suite completes in a fraction of its sequential wall time with unchanged results. Acceptance: -jobs 8 produces aggregate results identical to -jobs 1 (scriptlib/developer/runtests_parity.tcl reports PARITY ok) across repeated full-suite runs on a native tclsh 9.0.x, reduces full-suite wall time by at least 2.5x versus the sequential baseline on the reference machine, leaves the repo clean after runs (git status unchanged), and src/tests/AGENTS.md documents the -jobs flag and the serial-group policy. @@ -48,3 +48,48 @@ with diminishing returns beyond. file-end events let one viewer demux interleaved children. - Timing noise: -slowest per-test microseconds get noisier under CPU oversubscription; document rather than fix. + +## Progress + +Achieved-flip verification record, 2026-07-19: + +Implementation landed in src/tests/runtests.tcl: -jobs N (implies -singleproc 0; explicit +-singleproc 1 conflicts with an error), -serial-paths (default trimmed during verification +to {modules/punk/console/** modules/opunk/console/**} - the piped-child-driven repl/stdin +suites proved parallel-safe and each serial file costs its full ~3-4s child boot strictly +after the parallel phase), tpool pool with longest-first static-weight submission, +per-child capture files and tcltest -tmpdir subdirs, results consumed by the unchanged +processing loop in discovery order, phase-time and per-child-wall reporting, watch-mode +file-collected events with completion-order output relay. + +Acceptance evidence (native tclsh 9.0.3, reference machine, piped/no-console context): +- Repeated -jobs 8 full-suite runs: 2m16.2s and 2m15.6s wall; parity tool reports + PARITY ok for -jobs 8 vs -jobs 1, between the two repeated -jobs 8 runs, and vs the + pre-parallel singleproc baseline (87 files / 989 tests / 973-15-1, exec-14.3 the sole + expected failure in every run). +- Speedup: 2.58x vs the ~350s sequential baseline this goal's Context records (5m50.8s + singleproc / 5m50.1s sequential multiproc, 2026-07-18). One same-week sequential + -jobs 1 run on a cooler machine measured 5m28.8s, against which the ratio is 2.41x - + recorded for honesty; run-to-run machine variance during verification was up to ~30s. +- Repo clean (git status unchanged) after every run; src/tests/AGENTS.md documents the + flag, serial-group policy, event semantics and measured speedup. + +Two Tcl-core-level findings made during verification (both worked around in +runtests_run_child_process, both candidates for upstream investigation): +1. Concurrent BLOCKING exec calls from multiple threads convoy on Windows (Tcl 9.0.3): + they all return together when the longest-lived concurrent child exits - proven with + plain sleepers of 2-12s from 8 tpool workers all walling at 12.0s. In early -jobs runs + this manifested as the first-wave 8 children all reporting identical 139.9s walls and + capped the speedup at ~2x. Workaround: spawn with 'exec ... &' (returns at spawn) and + poll per-pid tcl::process status. +2. Tcl_ReapDetachedProcs races the poll: every exec call automatically reaps finished + background children process-wide, so a sibling worker's next spawn purged a child's + status entry before its own worker read it (nondeterministic 'key not known in + dictionary' file errors). Workaround: tcl::process autopurge false plus explicit + per-pid purge after the status read. + +Remaining non-gating observations: verification context was piped/no-console - under a +real console the -serial-paths default may need widening (escape hatch documented); +raising the ceiling past the ~2m multishell.test child means splitting that file (suite +restructure, out of scope); the lean-children candidate (explicit deps for the 17 +preload-dependent files) remains open with the parity tool as its gate. diff --git a/src/tests/AGENTS.md b/src/tests/AGENTS.md index a7bbc6a4..761e2c4b 100644 --- a/src/tests/AGENTS.md +++ b/src/tests/AGENTS.md @@ -21,6 +21,7 @@ Top-level test harness and source-tree tests for ShellSpy/Punk. Tests here exerc - The testinterp module path includes `src/vendormodules` (and `src/vendormodules_tcl` when present) so vendored dependencies such as `voo` resolve in tests. - Multi-process mode (`-tcltestoptions {-singleproc 0}`, completed 2026-07-18): each test file runs in a child process of the same executable via `testsupport/child_test_runner.tcl`, driven by a per-run environment payload `runtests.tcl` generates (package prefer latest, test tm paths, auto_path, modpod ifneeded definitions, tcltest options; per-file `-testdir` computed child-side). The child then mirrors the single-process testinterp preload: package require shellrun plus one no-op `shellrun::runx -tcl` call (the testinterp sources test files via runx, whose execution pulls further runtime deps - currently punk::lib). Several existing suites use punk::* commands without a package require of their own and depend on this preload (17 files / 97 tests error without shellrun, a further 7 files / 31 tests without the runx warmup; making suite dependencies explicit so children can go leaner is a candidate cleanup, verifiable with the parity tool below). The bootstrap warms `clock format` before the module-path wipe: first script-level clock use loads msgcat from the runtime's default module paths, which the test module paths do not supply (the single-process testinterp is shielded only by the runtests parent's earlier clock use - a latent gap for any test explicitly requiring msgcat in either mode). - Multi-process failure classification: a nonzero child exit is reported as a file-level failure (compact/markdown/json carry an ERROR entry with errorcode `CHILDPROCESS exit ` and the child's stderr tail); exit-0 with no tcltest summary line remains the `missing-cleanupTests` warning. Prefer a native tclsh for multi-process runs: children of a kit executable boot via the kit's script dispatch with kit-stamped punk packages preloaded, which can shadow the src dev modules under test (the runner prints a warning). +- Parallel jobs (G-091, achieved 2026-07-19 - see goals/archive/G-091-runtests-parallel-jobs.md): `-jobs N` (N > 1) implies multi-process mode and runs test files through a worker pool of N concurrent child processes (tpool; per-child capture files and per-child tcltest `-tmpdir` subdirs so concurrent `makeFile` helpers cannot collide; longest-first submission using static weights from the 2026-07-18 timing measurements - the full-suite floor is the slowest single file, multishell.test). Files matching `-serial-paths` run sequentially after the parallel batch - default `{modules/punk/console/** modules/opunk/console/**}` (the console-state suites, which emit to and query the shared terminal; suites driven through piped-stdio child processes - shell/**, modules/punk/repl/** - stay parallel by default and can be added to `-serial-paths` if they prove flaky under a real console; each serial file costs its full ~3-4s child boot strictly after the parallel phase, so the list is deliberately minimal). Reports are unchanged in shape and emitted in discovery order. An explicit `-tcltestoptions {-singleproc 1}` conflicts with `-jobs > 1` (error). Watch-event semantics under `-jobs`: no `file-start` events; `file-collected` (with exitcode, output relayed at that moment) fires in completion order and the authoritative `file-end` (tallies) in discovery order. Per-test microsecond timings are noisier under CPU oversubscription - prefer sequential runs when `-slowest` matters. Child spawn under -jobs is background-exec plus `tcl::process status` polling: concurrent BLOCKING execs from worker threads convoy on Windows - they all return together at the longest-lived concurrent child's exit (proven 2026-07-19 with plain sleepers of 2-12s all walling at 12s; this cost early -jobs runs ~50s of false critical path). Runtimes without `tcl::process` (tcl 8.6) fall back to blocking exec, which re-convoys under -jobs. The runner prints phase times (parallel/serial-tail/processing) and the ten slowest child WALL times in non-json modes - child wall includes boot and file-level fixture cost that per-test usec timings miss. - UDP watch mode (added 2026-07-18): `env(PUNK_TEST_UDPTEE)` = `` or `:` (e.g `41197`) makes runtests emit the run over UDP via the shellfilter::log mechanism (shellthread worker threads -> tcludp, one datagram per line, cooked format whose source column carries the tag). Tag `runtests` carries lifecycle events; each event message is a well-formed tcl list `RUNTESTS-EVENT ?key value ...?` (`run-start`, `file-start`, `file-end` with per-file tallies, `run-end`). Tags `teststdout`/`teststderr` carry test file output: streamed live per output chunk in single-process mode (`shellrun::runx -teelog` 0.2.0 - write traces on the capture variables, so captured results and reports are unchanged) and relayed per completed file by the parent in multi-process mode. No listener is required (sends to an unbound local port are discarded). The parent extends its auto_path with `/lib_tcl/` so log workers resolve the project's tcludp 1.0.13+ (1.0.12's UDP_ExitProc is the G-036 exit-hang class). Viewer-side caveat: tcludp's RECEIVE fileevent under Tcl 9.0.3/Windows delivered only the first datagram in testing (send side unaffected; a .NET UdpClient received everything) - a viewer should use timer-driven non-blocking reads or a non-tcludp receiver until that is resolved. - In watch mode the singleproc loop closes and terminates the shellfilter::log worker threads opened inside each per-file testinterp before deleting it (the `-teelog` tag workers plus shellrun's punkshout/punksherr teehandle workers). The terminate handshakes cost ~0.5-0.7s per file, so unwatched runs skip this and keep the pre-existing small leak of the two teehandle worker threads per file (noted for the shellfilter/shellthread audit; the process exits at run end regardless). - Tests should run against source modules and libraries from `src/`, not installed packages or root-level build outputs. @@ -46,6 +47,7 @@ Top-level test harness and source-tree tests for ShellSpy/Punk. Tests here exerc - Add `-slowest ` when timing outliers are relevant. - Multi-process runs use `-tcltestoptions {-singleproc 0}` with otherwise identical flags. Check result parity between modes by capturing `-report json` stdout from each and comparing with `tclsh scriptlib/developer/runtests_parity.tcl ` (ignores timings; exit 0 on parity). - To watch runs live (including runs launched by agents or other processes, which inherit the environment): set `PUNK_TEST_UDPTEE=41197` and point a UDP listener/viewer at that port. No runner flags needed; results are unaffected. +- For broad runs, `-jobs 8` cuts full-suite wall time roughly 2.6x (~2m16s vs ~5m50s sequential on the reference machine, 2026-07-19; result parity verified) - e.g ` src/tests/runtests.tcl -jobs 8 -report compact -show-passes 0`. The floor is the slowest single child (multishell.test, ~2m). Focused runs rarely need `-jobs`. - Add `-strict-exit 1` when a nonzero shell exit code is needed for failures or parser warnings. - Capture enough stderr or failure context to identify the failing command or assertion. - For ERROR-status failures, the markdown report's `errorInfo` block and compact `message=` field carry the full Tcl error message; use `-report markdown` for untruncated context. diff --git a/src/tests/runtests.tcl b/src/tests/runtests.tcl index c271f2c8..62b98885 100644 --- a/src/tests/runtests.tcl +++ b/src/tests/runtests.tcl @@ -310,12 +310,15 @@ proc runtests_write_child_payload {payloadfile test_tmlist test_auto_path ifneed close $fd } -proc runtests_run_child_process {exe bootstrap payloadfile testfile outfile errfile} { +proc runtests_run_child_process {exe bootstrap payloadfile testfile outfile errfile childtmpdir} { #Run one test file in a child process, capturing stdout/stderr to files. Deliberately no #shellrun/shellfilter capture on the parent side: file capture avoids the parent-stdin/pipe - #machinery, and parallel scheduling (future -jobs) can reuse the same mechanism. (What the - #child itself loads - including its shellrun preload mirroring the singleproc testinterp - - #is the bootstrap's concern; see testsupport/child_test_runner.tcl.) + #machinery, and -jobs parallel scheduling reuses the same mechanism (this proc is + #replicated verbatim into tpool worker threads via info args/info body - keep it free of + #package dependencies and namespace/global state, and keep every argument required). + #childtmpdir overrides the child's tcltest -tmpdir when nonempty (mandatory per child + #under -jobs so concurrent makeFile/makeDirectory helpers cannot collide); "" keeps the + #shared -tmpdir carried in the payload options. #stdin is an immediate-EOF redirection so a misbehaving child can't hang on it. #Returns a dict shaped for punk::tcltestrun::parse_testrun: exitcode/stdout/stderr keys, #or error/errorCode/errorInfo keys if the child could not be launched at all. @@ -325,13 +328,67 @@ proc runtests_run_child_process {exe bootstrap payloadfile testfile outfile errf } } set exitcode 0 - if {[catch {exec -- $exe $bootstrap $payloadfile $testfile > $outfile 2> $errfile << {}} emsg errdict]} { - set ecode [dict get $errdict -errorcode] - if {[lindex $ecode 0] eq "CHILDSTATUS"} { - set exitcode [lindex $ecode 2] - } else { - #launch failure (or CHILDKILLED etc) - no usable test run - return [dict create error $emsg errorCode $ecode errorInfo [dict get $errdict -errorinfo]] + set wall_t0 [clock milliseconds] + #Child spawn is background-exec plus a tcl::process status poll rather than a blocking + #exec: concurrent blocking execs from -jobs tpool worker threads CONVOY on Windows - they + #all return together when the longest-lived concurrent child exits (proven 2026-07-19 + #with plain sleepers of 2-12s all walling at 12s; see the verification record in + #goals/archive/G-091-runtests-parallel-jobs.md). + #'exec ... &' returns at spawn and per-pid status polling is convoy-free. stdin comes + #from the null device so a misbehaving child can't hang on it. + if {$::tcl_platform(platform) eq "windows"} { + set nulldev NUL + } else { + set nulldev /dev/null + } + if {[llength [info commands ::tcl::process]]} { + #Disable the automatic detached-process reaping: Tcl_ReapDetachedProcs runs on every + #exec call and purges finished background children PROCESS-WIDE, so a sibling + #worker's next spawn could purge this child's status entry before we read it (the + #cross-worker race behind nondeterministic 'key not known in dictionary' file + #errors in early -jobs runs, 2026-07-19). With autopurge off each pid is purged + #explicitly after its status is read. + tcl::process autopurge false + if {[catch {exec -- $exe $bootstrap $payloadfile $testfile $childtmpdir < $nulldev > $outfile 2> $errfile &} spawnresult errdict]} { + #launch failure - no usable test run + return [dict create error $spawnresult errorCode [dict get $errdict -errorcode] errorInfo [dict get $errdict -errorinfo]] + } + set pid [lindex $spawnresult 0] + while {1} { + set st [tcl::process status $pid] + if {![dict exists $st $pid]} { + #should be impossible with autopurge off - surface loudly rather than spin + return [dict create error "child pid $pid disappeared from the tcl::process table before its status was read" errorCode {RUNTESTS PIDGONE} errorInfo "child pid $pid missing from tcl::process status result: $st"] + } + set pstatus [dict get $st $pid] + if {$pstatus ne ""} { + break + } + after 50 + } + catch {tcl::process purge $pid} + #status shapes: "0" = clean exit; otherwise {1 } where errorcode + #is usually {CHILDSTATUS } + if {$pstatus ne "0"} { + set ecode [lindex $pstatus 2] + if {[lindex $ecode 0] eq "CHILDSTATUS"} { + set exitcode [lindex $ecode 2] + } else { + return [dict create error [lindex $pstatus 1] errorCode $ecode errorInfo [lindex $pstatus 1]] + } + } + } else { + #blocking fallback for runtimes without tcl::process (tcl 8.6): correct sequentially; + #concurrent use from -jobs workers re-convoys on Windows (documented in + #src/tests/AGENTS.md) + if {[catch {exec -- $exe $bootstrap $payloadfile $testfile $childtmpdir < $nulldev > $outfile 2> $errfile} emsg errdict]} { + set ecode [dict get $errdict -errorcode] + if {[lindex $ecode 0] eq "CHILDSTATUS"} { + set exitcode [lindex $ecode 2] + } else { + #launch failure (or CHILDKILLED etc) - no usable test run + return [dict create error $emsg errorCode $ecode errorInfo [dict get $errdict -errorinfo]] + } } } set out "" @@ -346,7 +403,10 @@ proc runtests_run_child_process {exe bootstrap payloadfile testfile outfile errf set err [read $fd] close $fd } - return [dict create exitcode $exitcode stdout $out stderr $err] + #wall_ms = whole child-process wall time (boot + fixtures + tests) - per-test usec + #timings miss file-level fixture cost, and this is what -jobs critical-path analysis + #needs. parse_testrun routes the unknown key into its (unused) err text field - harmless. + return [dict create exitcode $exitcode stdout $out stderr $err wall_ms [expr {[clock milliseconds] - $wall_t0}]] } proc runtests_udptee_event {args} { @@ -358,6 +418,28 @@ proc runtests_udptee_event {args} { catch {::shellfilter::log::write runtests [list RUNTESTS-EVENT {*}$args]} } +proc runtests_collect_child_result {testfile_relative jobresult} { + #shared by the -jobs parallel collection loop and its serial tail: cache the child's + #result dict for the main processing loop, emit the file-collected watch event, and + #relay the captured output to the watch target (under -jobs, relay happens here in + #completion order rather than in the discovery-order processing loop). + set ::runtests_job_results($testfile_relative) $jobresult + if {[dict exists $jobresult exitcode]} { + set ecode [dict get $jobresult exitcode] + } else { + set ecode "launch-error" + } + runtests_udptee_event file-collected path $testfile_relative exitcode $ecode + if {$::runtests_udptee_target ne ""} { + if {[dict exists $jobresult stdout] && [dict get $jobresult stdout] ne ""} { + catch {::shellfilter::log::write teststdout [dict get $jobresult stdout]} + } + if {[dict exists $jobresult stderr] && [dict get $jobresult stderr] ne ""} { + catch {::shellfilter::log::write teststderr [dict get $jobresult stderr]} + } + } +} + @@ -495,6 +577,24 @@ punk::args::define { "Number of slowest passing tests to include in Markdown and JSON summaries. Use 0 to suppress." -strict-exit -type boolean -default 0 -help\ "If true, exit 1 when tests fail and exit 2 when files produce parser warnings." + -jobs -type int -default 1 -help\ + "Number of concurrent child processes for multi-process mode. + 1 (default) runs test files sequentially. + Values above 1 imply -singleproc 0 (multi-process mode): test files run + through a worker pool of this many concurrent child processes, except files + matching -serial-paths, which run sequentially after the parallel batch. + Reports are unchanged and emitted in discovery order; per-test microsecond + timings get noisier under CPU oversubscription. + Conflicts with an explicit -tcltestoptions {-singleproc 1}." + -serial-paths -type list -default {modules/punk/console/** modules/opunk/console/**} -help\ + "Glob patterns (relative to the test base, forward slashes - same form as + -include-paths) for test files that must NOT run concurrently when -jobs + exceeds 1. Matching files run sequentially after the parallel batch + completes. The default covers the console-state suites (they emit to and + query the shared terminal); pass an empty list to parallelise everything. + Suites driven through piped-stdio child processes (shell/testsuites/**, + modules/punk/repl/**) are parallel by default - add them here if they + prove flaky under a real console." @values -min 0 -max -1 glob -type string -multiple 1 -optional 1 -help\ "Names or glob patterns of test files to run. @@ -522,6 +622,12 @@ set opt_show_passes [dict get $opts -show-passes] set opt_show_timings [dict get $opts -show-timings] set opt_slowest [dict get $opts -slowest] set opt_strict_exit [dict get $opts -strict-exit] +set opt_jobs [dict get $opts -jobs] +set opt_serial_paths [dict get $opts -serial-paths] +if {![string is integer -strict $opt_jobs] || $opt_jobs < 1} { + puts stderr "runtests: invalid -jobs value '$opt_jobs' (expected an integer >= 1)" + exit 2 +} set report_detailed_markdown [expr {$opt_report in {markdown markdown+json}}] set report_compact [expr {$opt_report eq "compact"}] set report_json_only [expr {$opt_report eq "json"}] @@ -535,6 +641,19 @@ set include_paths [concat {*}[dict get $opts -include-paths]] set tcltestoptions [dict merge $default_tcltestoptions $opt_tcltestoptions] +#-jobs > 1 is a multi-process-mode feature: it implies -singleproc 0. An explicit +#user-supplied -singleproc 1 alongside -jobs > 1 is a conflict. (Check against $received - +#the unreceived -tcltestoptions default also carries -singleproc 1 and must not trigger this.) +if {$opt_jobs > 1} { + if {[dict exists $received -tcltestoptions] + && [dict exists $opt_tcltestoptions -singleproc] + && [dict get $opt_tcltestoptions -singleproc]} { + puts stderr "runtests: -jobs $opt_jobs conflicts with -tcltestoptions {-singleproc 1} (parallel jobs require multi-process mode)" + exit 2 + } + dict set tcltestoptions -singleproc 0 +} + if {[dict exists $tcltestoptions -file]} { set file_globs [dict get $tcltestoptions -file] } else { @@ -604,10 +723,15 @@ if {[dict exists $tcltestoptions -singleproc] && [dict get $tcltestoptions -sing set singleproc 1 } else { if {!$report_json_only} { - puts "Running tests in multiple processes" + if {$opt_jobs > 1} { + puts "Running tests in multiple processes (-jobs $opt_jobs)" + } else { + puts "Running tests in multiple processes" + } } set singleproc 0 } +set jobs_mode [expr {!$singleproc && $opt_jobs > 1}] if {!$report_json_only} { puts "test auto_path: $test_auto_path" @@ -687,13 +811,165 @@ if {$runtests_udptee_target ne ""} { catch {::shellfilter::log::open teststderr [list -syslog $runtests_udptee_target]} } } -runtests_udptee_event run-start mode [expr {$singleproc ? "singleproc" : "multiproc"}] executable $thisexecutable tcl [info patchlevel] files [llength $testfiles] argv $::argv +runtests_udptee_event run-start mode [expr {$singleproc ? "singleproc" : "multiproc"}] jobs $opt_jobs executable $thisexecutable tcl [info patchlevel] files [llength $testfiles] argv $::argv + +#-jobs parallel phase (G-091): partition the discovered files into a parallel batch and a +#serial tail (-serial-paths: console-state-sensitive suites must not run concurrently), run +#the parallel batch through a tpool of -jobs concurrent child processes with per-child +#capture files and tcltest tmpdirs, then run the serial files sequentially through the same +#child mechanism. Results are cached in runtests_job_results and the main loop below consumes +#them in discovery order, so reports are identical in shape and order to a sequential run. +#Submission is longest-first using static weights from the 2026-07-18 timing measurements +#(G-091, achieved - see goals/archive/G-091-runtests-parallel-jobs.md): the full-suite +#floor is the slowest single file, so the slowest files must start immediately. +#Watch-event semantics under -jobs: no file-start events; file-collected (with exitcode) +#fires in completion order here, and the authoritative file-end (with tallies) fires from +#the processing loop in discovery order. +array set runtests_job_results {} +set runtests_phase_times [dict create] +if {$jobs_mode} { + set _phase_t0 [clock milliseconds] + set serial_patterns [concat {*}$opt_serial_paths] + set parallel_files [list] + set serial_files [list] + foreach tf $testfiles { + set is_serial 0 + foreach pat $serial_patterns { + if {[punk::path::globmatchpath $pat $tf]} { + set is_serial 1 + break + } + } + if {$is_serial} { + lappend serial_files $tf + } else { + lappend parallel_files $tf + } + } + #longest-first submission order. Static heuristic weights (seconds, measured 2026-07-18 + #on the reference machine); unlisted files weight 0 and keep discovery order among + #themselves (lsort is stable). + set weight_globs { + */multishell.test 85 + */argparsingtest.test 27 + */dtplite.test 25 + */scriptexec.test 10 + */shellexit.test 6 + */exec.test 5 + */staticruntime.test 3 + */runtimebash_wsl.test 3 + */shellnavns.test 2 + } + set decorated [list] + foreach tf $parallel_files { + set w 0 + foreach {g gw} $weight_globs { + if {[string match $g $tf]} { + set w $gw + break + } + } + lappend decorated [list $w $tf] + } + set ordered_parallel [list] + foreach rec [lsort -integer -decreasing -index 0 $decorated] { + lappend ordered_parallel [lindex $rec 1] + } + if {!$report_json_only} { + puts "parallel phase: [llength $parallel_files] files across $opt_jobs jobs; serial tail: [llength $serial_files] files" + } + + #per-child tcltest tmpdirs: nest under a user-supplied -tmpdir if given, else the workdir + if {[dict exists $opt_tcltestoptions -tmpdir]} { + set childtmp_base [dict get $opt_tcltestoptions -tmpdir] + } else { + set childtmp_base $runtests_workdir + } + set idx_of [dict create] + set fidx 0 + foreach tf $testfiles { + dict set idx_of $tf [incr fidx] + } + + #tpool workers need only the child-spawn proc: replicate it verbatim (no packages, no + #globals - see the proc's comments) + set pool_initcmd [list proc runtests_run_child_process [info args runtests_run_child_process] [info body runtests_run_child_process]] + set pool [tpool::create -minworkers 0 -maxworkers $opt_jobs -initcmd $pool_initcmd] + set jobmap [dict create] + foreach tf $ordered_parallel { + set i [dict get $idx_of $tf] + set tfabs [file normalize [file join $test_base $tf]] + set c_out [file join $runtests_workdir child_stdout_$i.txt] + set c_err [file join $runtests_workdir child_stderr_$i.txt] + set c_tmp [file join $childtmp_base childtmp_$i] + file mkdir $c_tmp + set jid [tpool::post $pool [list runtests_run_child_process $thisexecutable $child_bootstrap $child_payloadfile $tfabs $c_out $c_err $c_tmp]] + dict set jobmap $jid $tf + } + set pending [dict keys $jobmap] + set collected 0 + while {[llength $pending]} { + set done [tpool::wait $pool $pending pending] + foreach jid $done { + set tf [dict get $jobmap $jid] + if {[catch {tpool::get $pool $jid} jobresult]} { + #worker-level failure (a nonzero child exit comes back inside the dict, not here) + set jobresult [dict create error $jobresult errorCode {RUNTESTS JOBFAIL} errorInfo $jobresult] + } + incr collected + if {$report_detailed_markdown} { + puts stdout "parallel collected $collected/[llength $parallel_files]: $tf" + flush stdout + } + runtests_collect_child_result $tf $jobresult + } + } + tpool::release $pool + dict set runtests_phase_times parallel_s [format %.1f [expr {([clock milliseconds] - $_phase_t0) / 1000.0}]] + set _phase_t1 [clock milliseconds] + #serial tail: console-state-sensitive files, one at a time (still child processes) + foreach tf $serial_files { + set i [dict get $idx_of $tf] + set tfabs [file normalize [file join $test_base $tf]] + set c_out [file join $runtests_workdir child_stdout_$i.txt] + set c_err [file join $runtests_workdir child_stderr_$i.txt] + set c_tmp [file join $childtmp_base childtmp_$i] + file mkdir $c_tmp + set jobresult [runtests_run_child_process $thisexecutable $child_bootstrap $child_payloadfile $tfabs $c_out $c_err $c_tmp] + if {$report_detailed_markdown} { + puts stdout "serial completed: $tf" + flush stdout + } + runtests_collect_child_result $tf $jobresult + } + dict set runtests_phase_times serial_s [format %.1f [expr {([clock milliseconds] - $_phase_t1) / 1000.0}]] + if {!$report_json_only} { + puts "parallel phase: [dict get $runtests_phase_times parallel_s]s; serial tail: [dict get $runtests_phase_times serial_s]s" + #child process wall times (boot + fixtures + tests) - the -jobs critical path is the + #slowest child, which per-test usec timings understate + set walls [list] + foreach tf $testfiles { + if {[info exists runtests_job_results($tf)] && [dict exists $runtests_job_results($tf) wall_ms]} { + lappend walls [list [dict get $runtests_job_results($tf) wall_ms] $tf] + } + } + puts "slowest child processes (wall):" + foreach rec [lrange [lsort -integer -decreasing -index 0 $walls] 0 9] { + puts [format " %7.1fs %s" [expr {[lindex $rec 0] / 1000.0}] [lindex $rec 1]] + } + } + set _phase_t2 [clock milliseconds] +} set runtests_file_number 0 foreach testfile_relative $testfiles { set testfile [file normalize [file join $test_base $testfile_relative]] incr runtests_file_number - runtests_udptee_event file-start path $testfile_relative index $runtests_file_number of [llength $testfiles] + if {!$jobs_mode} { + #under -jobs the run already happened - file-collected was emitted in completion + #order and the discovery-order file-end below carries the tallies + runtests_udptee_event file-start path $testfile_relative index $runtests_file_number of [llength $testfiles] + } if {$report_detailed_markdown} { puts stdout "" #puts stdout "running test file $testfile" @@ -760,15 +1036,21 @@ foreach testfile_relative $testfiles { } flush stdout } else { - set result [runtests_run_child_process $thisexecutable $child_bootstrap $child_payloadfile $testfile $child_outfile $child_errfile] - if {$runtests_udptee_target ne ""} { - #relay the child's captured output to the watch target (file granularity - - #children do not stream live; see src/tests/AGENTS.md) - if {[dict exists $result stdout] && [dict get $result stdout] ne ""} { - catch {::shellfilter::log::write teststdout [dict get $result stdout]} - } - if {[dict exists $result stderr] && [dict get $result stderr] ne ""} { - catch {::shellfilter::log::write teststderr [dict get $result stderr]} + if {$jobs_mode} { + #run already performed in the parallel/serial phases above; output relay and the + #file-collected event happened at collection time + set result $runtests_job_results($testfile_relative) + } else { + set result [runtests_run_child_process $thisexecutable $child_bootstrap $child_payloadfile $testfile $child_outfile $child_errfile ""] + if {$runtests_udptee_target ne ""} { + #relay the child's captured output to the watch target (file granularity - + #children do not stream live; see src/tests/AGENTS.md) + if {[dict exists $result stdout] && [dict get $result stdout] ne ""} { + catch {::shellfilter::log::write teststdout [dict get $result stdout]} + } + if {[dict exists $result stderr] && [dict get $result stderr] ne ""} { + catch {::shellfilter::log::write teststderr [dict get $result stderr]} + } } } if {$report_detailed_markdown} { @@ -968,7 +1250,13 @@ foreach testfile_relative $testfiles { } set status [runtests_status $tallydict] set slowest_tests [runtests_slowest_tests $all_passes $opt_slowest] -runtests_udptee_event run-end status $status total [dict get $tallydict total] passed [dict get $tallydict passed] skipped [dict get $tallydict skipped] failed [dict get $tallydict failed] files [llength $file_summaries] elapsed_seconds [expr {[clock seconds] - $ts_start}] +if {$jobs_mode} { + dict set runtests_phase_times processing_s [format %.1f [expr {([clock milliseconds] - $_phase_t2) / 1000.0}]] + if {!$report_json_only} { + puts stdout "jobs phase times: parallel [dict get $runtests_phase_times parallel_s]s, serial tail [dict get $runtests_phase_times serial_s]s, processing [dict get $runtests_phase_times processing_s]s" + } +} +runtests_udptee_event run-end status $status total [dict get $tallydict total] passed [dict get $tallydict passed] skipped [dict get $tallydict skipped] failed [dict get $tallydict failed] files [llength $file_summaries] elapsed_seconds [expr {[clock seconds] - $ts_start}] {*}$runtests_phase_times if {!$report_json_only} { puts stdout "## runtests summary"