# G-036 Root-cause the Tcl 9 console+udp worker-thread event-loop wedge; minimal repro for possible upstream reporting Status: active Scope: src/modules/shellthread-999999.0a1.0.tm, src/bootsupport/modules/shellthread-1.6.2.tm, src/modules/shellfilter-999999.0a1.0.tm (as characterised - no product-code changes required by this goal; the punkshell mitigations are separate fixes) Acceptance: a repro reduced to the smallest ingredient set demonstrates the wedge on Tcl 9 Windows and its absence on Tcl 8.6 under identical conditions (target: plain Tcl + Thread + tcludp with no punk modules; if a punk component proves essential, the repro thereby pins which one); the wedge mechanism is identified and written up in the detail file (which wait never returns and why - e.g. via native thread stacks of a wedged specimen); before any upstream report the repro is re-verified against a Tcl 9 built from current core sources (per G-005 build capability - the shipped kit's 9.0.2 may carry an already-fixed bug), with the outcome recorded in the detail file; upstream filing itself is the user's manual step and not gated on this goal; the in-context batch harness (hidden-console piped-stdin runs scoring worker heartbeats, listings in the detail file) is retained as the regression check, with the 2026-07-08 baseline (punk902z run-2 syslog workers wedged 4/4, punksys alive 4/4) reproduced before and resolved after any fix. ## Context Investigated 2026-07-07/08 from a user-visible symptom: piping a small script into shell mode (`'puts test' | punk902z shell` from pwsh), pressing Enter at the first interactive prompt (after the app-layer CONIN$ restart), then typing `exit` at the dim `P%` prompt intermittently froze the shell - the `exit` had no effect, one further command (e.g. `pwd`) echoed but never ran, then echo stopped entirely and only ctrl-c killed the process. Diagnosis chain (all confirmed by timestamped instrumentation; see Notes for instrumented sites): 1. `exit`/`quit` unwind the repl completely (both teardown phases finish, `repl::start` returns `exit 0`). 2. `shellfilter::run`'s tail then calls `::shellfilter::log::close` for the `shellfilter-run` log tag -> `shellthread::manager::unsubscribe` -> a **bare synchronous `thread::send`** (settings-reset when returning the worker to the free list) to that tag's worker thread. 3. That worker had silently stopped servicing its event queue ~1-2s after birth: scheduled `after` heartbeats never fired and queued async `send_info` events were never processed. The sync send therefore blocks the main thread forever -> dead event loop -> all repl symptoms downstream (the echoed-then-dead `pwd` line is the console driver's cooked read buffering one line that nobody consumes; no further read is posted so echo stops). 4. Only `exit`/`quit` touch that worker synchronously - every other command is unaffected, matching the observed "only exit/quit lock up". `exit` at the first prompt usually wins the race because the sync send happens ~600ms after the worker's first syslog write, before the wedge sets in; the Enter-then-exit detour adds the seconds the wedge needs. The wedge itself - a worker thread event loop that stops processing timers and cross-thread sends - is the residual unknown this goal exists to resolve. The punkshell hang is mitigated separately (unsubscribe robustness + un-hardcoding the syslog default), but syslog-to-localhost must remain a *supported* configuration, so the wedge must be understood, not just avoided. ## Evidence so far (2026-07-08, Windows 11, punk902z = Tcl 9.0.2, punksys = Tcl 8.6, tcludp 1.0.12, workers load bootsupport shellthread 1.6.2) Established by heartbeat scoring (each worker schedules `after` heartbeats at init; a worker with zero heartbeats that was not legitimately torn down is wedged): - Wedged workers are exactly those configured with `-syslog 127.0.0.1:514` (they open a tcludp socket and send datagrams on first log write). Workers without syslog never wedge. - **Tcl 9 only**: hidden-console batch (4 runs per shell, judging the post-restart run-2 workers, which live on): punk902z wedged 4/4; punksys (8.6) alive 4/4. One earlier punk902z hidden-console run came up clean, so treat it as near-deterministic, not absolute. - **Console required**: the same piped run with no console attached (harness/service context) never wedges - 8s-delayed-exit runs completed cleanly with heartbeats throughout. - Nothing listens on UDP 514 locally, so every datagram draws an ICMP port-unreachable. - CPU of a hung specimen stays near zero -> the wedged threads are blocked, not spinning. - Scoring caveat: each shell's run-1 workers are torn down in the run-1 -> run-2 transition before their heartbeats come due - their hb=0 is normal, judge run-2 workers only. - Diag-file caveat: the shared append-mode diag file loses/garbles occasional lines under concurrent writers; single missing lines are not evidence, multi-line absences are. Ingredients ruled out by standalone probes (all clean under a hidden console on Tcl 9): - udp_open + datagram send in a worker thread (plain probe) - + twapi loaded with a console-control handler registered in the main thread - + the punk worker package environment (punk::packagepreference + shellthread 1.6.2) - + 30 datagrams and a later send on the ICMP-flagged socket - + CONIN$ opened in the main thread with a readable handler armed - + twapi::SetStdHandle(-10, console) before worker creation - + main thread closing stdin and ADOPTING the CONIN$ channel into the stdin std-channel slot (channel name becomes 'stdin'), SetStdHandle, and an active gets-on-readable reader armed - i.e. the same visible stdin arrangement the restarted repl has ('adopt' probe variant, 2026-07-08) Upstream reconnaissance (2026-07-08, TEMP_REFERENCE fossil checkouts: Tcl core trunk-side branch @ 2026-07-07, tcludp trunk @ 2026-07-05): - core-9-0-branch has had NO tclWinConsole.c change since 9.0.2 beyond an include-hygiene commit (2025-10-24) - the wedge, if in the console driver, is likely still present in 9.0.x maintenance. Trunk has console-channel activity by apnadkarni (2025-12-29 metakey-notification change + revert; branch apn-winconsole-noreadahead) worth reading. - Current tclWinConsole.c architecture confirms a credible wedge surface: process-global gConsoleLock, a console-handle list SHARED ACROSS ALL Tcl THREADS, per-handle SRWLOCKs, reader/writer threads coordinated via CONDITION_VARIABLEs (consoleThreadCV / interpThreadCV "for awakening interp thread(s)"), and Tcl_ThreadAlert fan-out to interested channel-owning threads. A missed CV wakeup leaves an interp thread blocked inside a console-driver call - matching the observed "blocked not spinning, timers and thread::sends unserviced". - Sharpened worker-side ingredient hypothesis: a fresh thread's std channels initialize on its FIRST channel creation (udp_open, or a -file log open) - with the process stdin handle pointing at the console (post SetStdHandle), that first channel creation attaches the worker to the shared console machinery. Fits the data exactly: run-2 workers that never create any channel (-file {} -syslog {}) survive; channel-creating ones wedge; run-1 workers (stdin handle = dead pipe at creation) are immune. NOT yet reproduced by probes, so at least one more live-shell ingredient is still missing (candidates below). Untested ingredients (next candidates): - Real console *use*: main thread actually reading CONIN$ (gets/read pumping, as the repl reader does), console *output* channels (all probes redirected stdout/stderr to files), punk::console SetConsoleMode changes (VT input/output flags, raw/line flips) - The shellfilter tee stack: tcl::chan::fifo2 reflected channels + thread::transfer to pipe workers (cross-thread reflected-channel forwarding blocks in the owner thread's event loop) - The repl codethread; sheer thread/channel count - Anomaly to re-examine: probe workers created *from the codethread* inside a live shell wedged even without udp (both udp and control probes silent) - possibly artifact, possibly a lead Suggested tools for the mechanism write-up: native stacks of a wedged specimen (procdump / windbg on the hung punk902z), then map the blocked wait to tclWinConsole.c (Tcl 9 rewrite: per-handle reader/writer threads + gConsoleLock) or tcludp's Windows event source. ## Approach 1. Capture native thread stacks of a wedged in-context specimen and work backwards from the blocked wait - promoted to first step after seven single-ingredient probe variants all came up clean (ingredient bisection is guessing; the stack names the exact wait). Spawn a specimen via the hidden-console repro below (post-fix, punkshout/punksherr still wedge in run 2 - their syslog comes from the logging config, and they idle indefinitely as specimens). Needs a native tool: none installed as of 2026-07-08 (no procdump/cdb/windbg) - e.g. `winget install Microsoft.WinDbg` or Sysinternals procdump (user's call), or `rundll32 C:\Windows\System32\comsvcs.dll, MiniDump full` writes a dump without extra tools but analysis still needs a debugger. Read stacks against tclWinConsole.c's CV waits and tclWinNotify.c. 2. Continue minimal-repro construction guided by what the stacks reveal (remaining untried live-shell ingredients: codethread presence, fifo2 tee stack with thread::transfer'd halves, punk::console raw/line + VT SetConsoleMode churn and -inputmode queries, console output channels, multi-thread channel-creation concurrency). 3. Write up the mechanism here; reduce the repro accordingly. 4. Re-verify against a Tcl 9 built from current core sources before any upstream report (the kit's 9.0.2 may carry an already-fixed bug). Building Tcl 9 from source is G-005 territory; this step waits on that capability (or a manually obtained current build). 5. Upstream filing (Tcl core or tcludp) is the user's manual decision and step. ## Alternatives considered - Mitigate-only (make the sync send robust, default syslog off) - rejected as the *whole* answer: syslog-to-localhost must remain supported, and a worker that silently stops logging is still a bug in a supported configuration. The mitigations proceed independently. - Reporting upstream from the current evidence without a minimal repro - rejected: the wedge needs a named mechanism and a repro a maintainer can run; and it must first be shown to exist on current Tcl 9 sources, not just the shipped 9.0.2 kit. ## Notes ### Session instrumentation (temporary, all sites marked `#DIAG`) In the working tree during the investigation; remove once the mitigations are verified: - `src/modules/punk/repl-999999.0a1.0.tm` - lifecycle diag markers (start/vwait/teardowns, exit/quit writers, eval status-poll), deferred-reader arming via diag proc, and the EOF-branch `after 1 reopen_stdin` widened to `after 500` (race-determinism experiment; revert). - `src/modules/shellfilter-999999.0a1.0.tm` - `rundiag` markers through `shellfilter::run`'s teardown tail (flushes, stack removals, log close). - `src/modules/shellthread-999999.0a1.0.tm` - `unsubdiag` markers in unsubscribe/write_log/ new_worker/shutdown paths; init_script completion marker + 2s/5s heartbeats. - `src/bootsupport/modules/shellthread-1.6.2.tm` - `wdiag` markers in the worker procs the worker threads actually run (init, send_info, _initsock, terminate, bgerror). Note the version split: main thread runs the 999999 dev module, workers load bootsupport 1.6.2. - `src/lib/app-punkshell/punkshell.tcl` - markers at do_shell return, thread shutdown/release, and every `::exit` call site. Diag output appends to `%TEMP%\punkshell_rundiag.txt` (file first, stderr echo second, so the record survives a wedged stderr). ### In-context repro (the regression check) Pipe a short script into shell mode with a console attached but stdin file-redirected; the pipe EOF triggers app-punkshell's CONIN$ restart and the restarted run's syslog workers wedge: ```powershell Set-Content $env:TEMP\punkin2.txt "puts test" Start-Process cmd.exe -WindowStyle Hidden -ArgumentList '/c', 'c:\repo\jn\shellspy\bin\punk902z.exe src shell < %TEMP%\punkin2.txt > %TEMP%\punkout.txt 2>&1' # wait ~15s, then judge run-2 workers' heartbeats in %TEMP%\punkshell_rundiag.txt and kill the process ``` Interactively: `'puts test' | punk902z src shell`, Enter at the first prompt, `exit` at the dim prompt -> hang (main thread blocked in the unsubscribe sync send). ### Batch scorer - wedgebatch.ps1 ```powershell # Batch wedge-detector: run each shell N times under a hidden console with piped # 'puts test' (pipe EOF -> CONIN$ restart), wait for heartbeat window, then score # each syslog-configured worker (shellfilter-run/punkshout/punksherr) by whether # its heartbeats fired. Judge run-2 workers only (run-1 workers are torn down in # the run transition before heartbeats come due - their hb=0 is a false positive). $diag = "$env:TEMP\punkshell_rundiag.txt" foreach ($exe in @('punksys','punk902z')) { for ($i = 1; $i -le 4; $i++) { Remove-Item $diag -ErrorAction SilentlyContinue $null = Start-Process -FilePath 'cmd.exe' -ArgumentList '/c', "c:\repo\jn\shellspy\bin\$exe.exe src shell < %TEMP%\punkin2.txt > %TEMP%\punkout_batch.txt 2>&1" -WindowStyle Hidden -PassThru Start-Sleep -Seconds 15 Get-Process $exe -ErrorAction SilentlyContinue | Stop-Process -Force -Confirm:$false Start-Sleep -Milliseconds 500 if (-not (Test-Path $diag)) { Write-Output "$exe run$i : NO DIAG FILE (src instrumentation not loaded?)"; continue } $content = Get-Content $diag $created = $content | Select-String "CREATED new worker (tid\S+) for tag '(shellfilter-run|punkshout|punksherr)'" if (-not $created) { Write-Output "$exe run$i : no syslog-worker creation lines found"; continue } foreach ($m in $created) { $tid = $m.Matches[0].Groups[1].Value $tag = $m.Matches[0].Groups[2].Value $hb = ($content | Select-String "$tid\) heartbeat").Count $verdict = if ($hb -ge 1) { "alive (hb=$hb)" } else { "WEDGED (hb=0)" } Write-Output "$exe run$i : $tag $tid -> $verdict" } } } Write-Output "batch done" ``` 2026-07-08 baseline output: punksys run-2 workers alive 4/4 (hb=2 each); punk902z run-2 workers (shellfilter-run, punkshout, punksherr) WEDGED 4/4. ### Standalone probe - udpthread_test.tcl (all variants clean so far) Run: `punk902z src script udpthread_test.tcl [adopt|conin [setstd]] [twapi]` - directly (consoleless) or via hidden console. (`Start-Process cmd.exe -WindowStyle Hidden -ArgumentList '/c','...exe src script ...tcl conin setstd > out 2>&1'`). Diag appends to `%TEMP%\udpthread_diag.txt`. ```tcl # Minimal repro probe: does a udp_open + send inside a worker thread wedge that # thread's event loop when the process has a console attached? # Two workers: 'udp' (punk pkg env + udp socket + 30 datagrams + late send on the # ICMP-flagged socket) and 'ctrl' (no udp). Both schedule heartbeats. package require Thread set diagfile [file join $::env(TEMP) udpthread_diag.txt] proc d {msg} { set f [open $::env(TEMP)/udpthread_diag.txt a] puts $f "[clock milliseconds] (main) $msg" close $f } d "=== run start (tcl [info patchlevel]) argv:'$::argv' ===" # mimic punkshell's actual restart: close stdin so the CONIN$ channel is ADOPTED into the # stdin std-channel slot, then read it like the repl reader does if {"adopt" in $::argv} { if {[catch { close stdin set ::conin [open {CONIN$} r] package require twapi set h [twapi::get_tcl_channel_handle $::conin in] twapi::SetStdHandle -10 $h chan configure $::conin -blocking 0 chan event $::conin readable [list apply {{c} { if {[gets $c line] < 0 && [eof $c]} {chan event $c readable {}} }} $::conin] d "stdin closed, CONIN\$ adopted as '$::conin' (stdin slot), SetStdHandle done, reader armed" } err]} { d "adopt setup FAILED: $err" } } # mimic the restarted repl: main thread opens CONIN$ and arms a readable handler if {"conin" in $::argv} { if {[catch { set ::conin [open {CONIN$} r] chan configure $::conin -blocking 0 chan event $::conin readable {list} d "CONIN\$ opened as $::conin, readable handler armed ([chan configure $::conin])" if {"setstd" in $::argv} { package require twapi set h [twapi::get_tcl_channel_handle $::conin in] twapi::SetStdHandle -10 $h d "SetStdHandle -10 done: process stdin handle now the console" } } err]} { d "CONIN\$ setup FAILED: $err" } } # mimic punk::repl::init_signal_handlers - twapi console control handler in main thread if {"twapi" in $::argv} { if {[catch { package require twapi proc ::probe_ccc {args} {return 0} twapi::set_console_control_handler ::probe_ccc d "twapi console control handler registered (twapi [package provide twapi])" } err]} { d "twapi setup FAILED: $err" } } set workerbody { proc wd {msg} { set f [open $::env(TEMP)/udpthread_diag.txt a] puts $f "[clock milliseconds] (%NAME% [thread::id]) $msg" close $f } wd "worker up" if {"%NAME%" eq "udp"} { if {[catch { set ::auto_path [list %AP%] ::tcl::tm::add {*}[lreverse [list %MP%]] package require punk::packagepreference punk::packagepreference::install package require Thread package require shellthread wd "punk env loaded (shellthread [package provide shellthread])" package require udp wd "udp package [package provide udp] loaded" set s [udp_open] chan configure $s -buffering none -translation binary chan configure $s -remote [list 127.0.0.1 514] for {set i 0} {$i < 30} {incr i} { puts -nonewline $s "udpthread-test-datagram-$i [string repeat x 120]" } wd "30 datagrams sent to 127.0.0.1:514" after 1500 [list apply {{s} { catch {puts -nonewline $s "late-datagram [string repeat y 120]"} e wd "late datagram send result: '$e'" }} $s] } err]} { wd "udp setup FAILED: $err" } } after 1000 {wd "heartbeat 1s"} after 2000 {wd "heartbeat 2s"} after 5000 {wd "heartbeat 5s"} after 8000 {wd "heartbeat 8s"} } foreach name {udp ctrl} { set tid [thread::create -preserved] thread::send -async $tid [string map [list %NAME% $name %AP% $::auto_path %MP% [tcl::tm::list]] $workerbody] d "created worker '$name' $tid" } after 10000 {set ::done 1} vwait ::done d "=== main exiting ===" exit 0 ``` ### Related - Session memory: `piped-stdin-exit-hang` (agent memory dir) mirrors this state. - Adjacent prior art: the Tcl 8.6 console parked-read work (console 0.7.1 / repl 0.2.2) - same neighbourhood (Windows console driver vs event-driven readers), different mechanism. - Mitigations proceeding separately (not this goal): shellthread `unsubscribe` must not use a bare synchronous `thread::send` (async, or async + vwait-with-timeout as `shutdown_free_threads` already does); `shellfilter::run` must honor its `-syslog` option instead of the hardcoded `127.0.0.1:514` in `log::open` (debug leftover - the correct call sits commented out beside it).