Skip to content

dastest: a hung sweep names the program that hung - flushed, timestamped start lines, run_tests targets streamed through Ninja - and the first hang they named, the debug-agent threadlock test, fixed on a new try_invoke_in_context - #3949

Merged
borisbat merged 1 commit into
masterfrom
bbatkin/dastest-start-lines
Sep 6, 2026

Conversation

@borisbat

@borisbat borisbat commented Sep 5, 2026

Copy link
Copy Markdown
Collaborator

Why. The mac Debug cells hung twice today in their interpreter sweep and the log ended in silence: --failures-only prints nothing for a passing file, and the sweep runs through cmake --build --target run_tests_interpreter, where Ninja holds a command's output until it finishes - a cancelled sweep loses everything it printed, including what would have named the hang. Once the lines existed they named it on this PR's own JIT lane: tests/debug_agent/test_callback_threadlock.das, whose hook waits on a thread that cannot start while the hook runs.

What changes.

  • log::started prints a timestamped line (iso8601_now()) to stderr and flushes it at once, in every mode; the sequential sweep logs run N/M: <file> before each program, the isolated dispatcher logs worker K starts: <files> before each batch, and a batch's child prints its own run lines into the stderr the parent folds in on any abnormal exit, timeout included. stdout stays clean for --bench-format json and the isolated result protocol.
  • Every run_tests_* custom target carries USES_TERMINAL, so Ninja runs it in the console pool and streams its output.
  • The hang: the tick holds the agent registry (g_DebugAgentMutex) for the whole callback, and every context construction walks that registry for onCreateContext, so a new_thread started while the hook blocks never begins; the main thread waited on it, the hook waited on the main thread. A 16-core box always won that race, a 3-core runner did not.
  • The test wanted to assert "a pinvoke is blocked while the callback runs", and nothing in the language could observe that - invoke_in_context waits - so every shape of it leaned on a second thread and a sleep window. New try_invoke_in_context(ctx, "fn", args...) : bool (debugapi) is the non-blocking invoke_in_context: try_lock on the context mutex, false with nothing run when another thread holds it. The test now proves the serialization from one thread: refused while onTick holds the lock, runs once the tick returned. No second thread, no timing window. pinvoke_impl and try_pinvoke_impl share one core (pinvoke_named).
  • The contract lands on DapiDebugAgent and in daslib/ARCHITECTURE.md section 24.1, and tests/debug_agent/REVIEW.md (new) binds it for the folder where agents with working hooks live.

Observable behavior.

  • A sweep cancelled mid-hang -> a log ending at the Ninja COMMENT line -> a log ending at <time> run N/M: <the file that hung>.
  • A green --failures-only sweep -> summary only -> one stderr line per program (the sequential mac Debug sweep grows by about 1,600 lines).
  • test_callback_threadlock.das on a small runner -> hangs when the tick reaches the callback before the second thread's context clone -> no second thread exists to race.
  • try_invoke_in_context on a context another thread holds -> (new) returns false at once; the same call on a free context runs the function and returns true.

Where to look. dastest/log.das (started), the two call sites in dastest/dastest.das, tests/CMakeLists.txt, tests/dastest/test_start_lines.das, pinvoke_named / try_pinvoke_impl in src/builtin/module_builtin_debugger.cpp, and tests/debug_agent/test_callback_threadlock.das.

Validation, claims, ledger

Validation

  • tests/dastest/test_start_lines.das runs dastest as a child in both modes with --failures-only, asserts the child's exit code and the start line naming the fixture; removing the sequential line fails it. dastest/tests (61) passes.
  • The deadlock was reproduced deterministically: the old test ordering with the tick started first and the second thread created only after entered hangs on both tiers (alarm-killed at 60 s); the original ordering passes 40 of 40 on the 16-core box, which is why it never showed here.
  • The rewritten threadlock test asserts both directions - refused during the callback, run after it, overlap == 0 - and passes interpreted and 21 of 21 under JIT; tests/debug_agent (54) passes on the shared pinvoke_named core.
  • das2rst regenerated clean (no Uncategorized), the new handmade entry filled, sphinx -W green.
  • USES_TERMINAL was not reconfigured locally (the build dir belongs to another branch); CI's configure is the check.

Not done

  • Ticking outside the registry mutex (snapshot agent and context, call onTick after releasing) would make a blocking hook legal; no agent in the tree needs one, so it stays a proposal.
  • A timeout-minutes on the build matrix job, so a hung cell fails inside the budget instead of holding a runner for hours.
  • try_invoke_in_context takes a function name only; the function-pointer and lambda forms of invoke_in_context have no try_ twin yet.

Copilot AI lite review requested due to automatic review settings September 5, 2026 23:44
@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from b2616cf to d297a12 Compare September 5, 2026 23:45

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The changes are small, consistent with existing patterns (e.g., prior USES_TERMINAL usage), and directly address the stated CI output-buffering problem without altering test semantics.

Pull request overview

Improves test-sweep debuggability by emitting and flushing per-program (and per-batch) “started” progress lines so a hung/cancelled CI run still identifies the last test file/batch executed, and by making Ninja stream test-target output via USES_TERMINAL.

Changes:

  • Add log::started(...) in dastest to always print+flush an immediate progress line (including under --failures-only).
  • Emit progress lines in both sequential sweeps (run N/M: ...) and isolated workers (worker K starts: ...).
  • Mark run_tests_* CMake custom targets with USES_TERMINAL so Ninja doesn’t buffer output until command completion; document the change in CHANGELIST.md.
File summaries
File Description
tests/CMakeLists.txt Adds USES_TERMINAL to test-run custom targets so Ninja streams output during runs.
dastest/log.das Introduces log::started to print+flush progress lines immediately (bypassing --failures-only suppression).
dastest/dastest.das Logs per-file and per-batch start lines via log::started to pinpoint hangs/timeouts.
CHANGELIST.md Records the behavioral change for users/CI maintainers.
Review details
  • Files reviewed: 5/5 changed files
  • Comments generated: 0
  • Review effort level: Lite

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Copilot AI review requested due to automatic review settings September 5, 2026 23:47

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The new isolated-mode test currently assumes worker 1 runs the batch, which can be scheduler-dependent and make the test flaky.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Review details
  • Files reviewed: 5/5 changed files
  • Comments generated: 1
  • Review effort level: Lite

Comment thread tests/dastest/test_start_lines.das
Copilot AI review requested due to automatic review settings September 5, 2026 23:50
@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from d297a12 to f9e2fa4 Compare September 5, 2026 23:50

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The new progress output can break existing machine-readable stdout modes (e.g., --bench-format json), and the new test helper currently ignores the spawned process exit code.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Review details
  • Files reviewed: 5/5 changed files
  • Comments generated: 2
  • Review effort level: Lite

Comment thread dastest/log.das
Comment thread tests/dastest/test_start_lines.das
Copilot AI review requested due to automatic review settings September 5, 2026 23:56
@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from f9e2fa4 to dea591d Compare September 5, 2026 23:56

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The changes are targeted, validated by a new regression test, and align with the stated goal of preserving actionable progress output during hangs.

Review details
  • Files reviewed: 5/5 changed files
  • Comments generated: 0 new
  • Review effort level: Lite

@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from dea591d to f5646f3 Compare September 6, 2026 00:54
Copilot AI review requested due to automatic review settings September 6, 2026 00:54

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The changes are cohesive, low-risk, and include targeted regression coverage validating the new stderr start-line behavior in both execution modes.

Review details
  • Files reviewed: 5/5 changed files
  • Comments generated: 0 new
  • Review effort level: Lite

@borisbat borisbat changed the title dastest: a hung sweep names the program that hung - flushed start lines per program and per batch, and the run_tests targets stream through Ninja dastest: a hung sweep names the program that hung - flushed, timestamped start lines, run_tests targets streamed through Ninja - and the first hang they named, the debug-agent threadlock test, fixed Sep 6, 2026
Copilot AI review requested due to automatic review settings September 6, 2026 01:23
@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from f5646f3 to 06e0d3a Compare September 6, 2026 01:23
@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from 06e0d3a to e04d739 Compare September 6, 2026 01:27

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The updated deadlock regression test still depends on a fixed sleep window that can allow false-positive passes on slow/loaded runners (see stored review comment).

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Review details
  • Files reviewed: 9/9 changed files
  • Comments generated: 1
  • Review effort level: Lite

Comment thread tests/debug_agent/test_callback_threadlock.das Outdated
Copilot AI review requested due to automatic review settings September 6, 2026 01:28
@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from e04d739 to 5c8c170 Compare September 6, 2026 01:30

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The changes are cohesive, test-covered for the new “start line” behavior, and the deadlock fix is localized to test ordering/handshakes with documented rationale.

Review details
  • Files reviewed: 9/9 changed files
  • Comments generated: 1
  • Review effort level: Lite

Comment thread tests/dastest/test_start_lines.das Outdated
Copilot AI review requested due to automatic review settings September 6, 2026 01:30

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟢 Approval recommended

The changes are cohesive, include targeted regression coverage for the new logging behavior, and the concurrency fix is guarded by explicit synchronization to prevent the previously observed deadlock.

Review details
  • Files reviewed: 9/9 changed files
  • Comments generated: 0 new
  • Review effort level: Lite

@borisbat borisbat changed the title dastest: a hung sweep names the program that hung - flushed, timestamped start lines, run_tests targets streamed through Ninja - and the first hang they named, the debug-agent threadlock test, fixed dastest: a hung sweep names the program that hung - flushed, timestamped start lines, run_tests targets streamed through Ninja - and the first hang they named, the debug-agent threadlock test, fixed on a new try_invoke_in_context Sep 6, 2026
…ped start lines, run_tests targets streamed through Ninja - and the first hang they named, the debug-agent threadlock test, fixed on a new try_invoke_in_context

A mac Debug cell hung twice today in its interpreter sweep and the log ended
in silence: `--failures-only` prints nothing for a passing file, and the
sweep runs through `cmake --build --target run_tests_interpreter`, where
Ninja holds a command's output until it finishes - a killed sweep loses
everything it printed, including what would have named the hang.

- `log::started` prints a timestamped line to stderr and flushes it at
  once, in every mode; stdout stays clean for `--bench-format json` and the
  isolated result protocol. The sequential sweep logs `run N/M: <file>`
  before each program; the isolated dispatcher logs `worker K starts:
  <files>` before each batch, and the batch's own child prints its `run`
  lines into the stderr the parent folds in on any abnormal exit.
- Every `run_tests_*` custom target carries `USES_TERMINAL`, so Ninja runs
  it in the console pool and streams its output.
- `tests/dastest/test_start_lines.das` runs dastest as a child in both modes
  and asserts the exit code and the start line.

The lines named the hang on this branch's own JIT lane:
tests/debug_agent/test_callback_threadlock.das. Its onTick spins until the
main thread releases it, and the main thread waits for a second thread
started by new_thread. The tick holds the agent registry for the whole
callback, and a context clone walks that registry for onCreateContext, so
when the tick reaches onTick before the second thread's clone the clone
blocks, the release never comes, and the process deadlocks. A 16-core box
always wins that race; a 3-core runner does not.

The test wanted to assert "a pinvoke is blocked while the callback runs",
and nothing in the language could observe that: `invoke_in_context` waits,
so every shape of the test leaned on a second thread and a sleep window.
New `try_invoke_in_context(ctx, "fn", args...) : bool` is the non-blocking
form - `try_lock` on the context mutex, false with nothing run when another
thread holds it - and the test proves the serialization from one thread:
refused while onTick holds the lock, runs once the tick returned. No second
thread, no window. The contract lands on DapiDebugAgent, in the daslib
architecture doc, and as the one rule of tests/debug_agent/REVIEW.md: a hook
never waits on a thread that has yet to create a context.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Copilot AI review requested due to automatic review settings September 6, 2026 01:59
@borisbat
borisbat force-pushed the bbatkin/dastest-start-lines branch from 5c8c170 to c890341 Compare September 6, 2026 01:59

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔵 Needs a closer look

It changes concurrency-sensitive debugger cross-context invocation behavior in C++ and CI-critical test-runner output/streaming semantics, which warrants final human validation across platforms.

Review details
  • Files reviewed: 13/13 changed files
  • Comments generated: 0 new
  • Review effort level: Lite

@borisbat
borisbat merged commit dc70422 into master Sep 6, 2026
34 checks passed
@borisbat
borisbat deleted the bbatkin/dastest-start-lines branch September 6, 2026 02:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants