client: the start window is still hardcoded, and a SIGTERM stop still prints reason=unknown in its own teardown

Symptoms (host-observed, macOS / Mac mini, 2026-09-16 10:43 +08)

$ emrg
Failed to connect to emrgd: emrgd failed to start within timeout

  emrgd.log tail:
  .../websockets/asyncio/connection.py, line 316, in recv
  .../asyncio/tasks.py, line 951, in shield
  .../asyncio/base_futures.py, line 13, in isfuture
  .../emrg/server/daemon.py, line 4879, in _sigterm_handler
  SystemExit: SIGTERM (15) received

$ emrg                       # repeated
Failed to connect to emrgd: emrgd failed to start within timeout
                             # no tail at all — zero diagnostics

Two failures at once: the diagnostic that would name the cause of this start failure is absent, and what is shown instead is the previous, normal stop of the daemon, presented as a crash.

I could not reproduce the macOS runtime symptom (this report is written from a Windows host, and the client's spawn path differs), and I did not exercise any stop/start path on purpose — the project forbids tests or scripts that stop/restart emrgd (MANIFESTO 第四条附则二). What I did verify is the mechanism, by reading the pinned revision: every line number below is from git show FETCH_HEAD:<path> at master 6e0a19c.

Where each symptom comes from

1. A normal stop is logged as a crash — the classification exists, the log does not use it. emrg/server/daemon.py:4921-4931:

except BaseException as exc:
    # Safety net: anything that escapes serve() (a signal SystemExit, a
    # hard crash) is recorded with its traceback, never silently.
    reason = "sigterm" if isinstance(exc, SystemExit) else "crash"
    exit_code = 143 if isinstance(exc, SystemExit) else 1
    traceback_text = "".join(
        traceback.format_exception(type(exc), exc, exc.__traceback__)
    )
    logger.critical(
        "daemon crashed (%s: %s)", type(exc).__name__, exc, exc_info=True
    )

reason and exit_code are classified per branch; the log line is not — logger.critical(..., "daemon crashed", exc_info=True) fires for reason == "sigterm" too, and writes the full traceback into emrgd.log. That path is the normal one: client/daemon_manager.py:167-183 restarts a stale daemon with SIGTERM first, emrg server stop (__main__.py:204) and the installer's stop_all do the same.

2. The traceback is not causal, which is why it reads as noise. _sigterm_handler (daemon.py:4874-4881) raises SystemExit from a signal handler, so the frames recorded are whatever the interpreter happened to be executing when the signal arrived. In the capture above the top frame is the function definition line def isfuture(obj): — a snapshot of a suspended coroutine, not a cause. Nothing in it can explain why a later start failed.

3. The start diagnostic is "last 15 lines of the whole file", not "the lines this attempt produced". emrg/client/daemon_manager.py:100-109:

for _ in range(15):
    await asyncio.sleep(0.3)
    if is_running():
        logger.info("emrgd started (pid=%d)", proc.pid)
        return proc
# R124: 超时后读取 emrgd.log 尾部打印真实失败原因（rant 2026-08-05T15:54:28 关联…）
tail = _read_log_tail(Path.home() / ".emrg" / "emrgd.log", lines=15)
detail = f"\n  emrgd.log 尾部:\n{tail}" if tail else ""
raise RuntimeError(f"emrgd failed to start within timeout{detail}")

R124 (#403/#404) added the tail so the real error would stop being swallowed. The implementation reads the file's tail, so when the previous daemon was stopped moments earlier and the new one has not written anything yet, those 15 lines are exactly the SIGTERM noise. And if tail else "" turns an empty tail into no diagnostic section at all — the second-run symptom, where the file's content is unchanged (or recreated empty) and the host is left with a bare "failed to start within timeout".

4. The child's own output has nowhere to go, and the wait never asks whether it died. daemon_manager.py:93-99 spawns with stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL. The only channel for a child that fails at import, argument or config stage is therefore emrgd.log — the one case where nothing was written. At the same time the wait loop never calls proc.poll(): a child that exits in 50 ms still costs the whole window, and its exit code is never reported.

5. The window is hardcoded. 15 × 0.3 s = 4.5 s, not configurable, no progress output. On a cold macOS start (python-dist plus imports) that is not obviously enough, and the failure is indistinguishable from a slow one.

Proposed fix (four small pieces)

daemon.py — use the classification that is already computed. On the sigterm branch log logger.info("daemon stopped (reason=%s, exit=%d)", reason, exit_code) with no exc_info and no traceback; keep logger.critical("daemon crashed …", exc_info=True) for reason == "crash" only. DaemonExit.traceback_text can stay complete — it is the log, and the word "crashed", that must not be applied to an operator-initiated stop.
daemon_manager.py — report the delta, not the file. Record the log's size (or line count) before spawning, and show only the lines appended since. When nothing was appended, say so explicitly, then print (a) the child's exit code from proc.poll() and (b) the last line in the file matching ERROR|CRITICAL|Traceback, labelled as coming from an earlier run so it cannot be mistaken for this attempt.
Fail fast on a dead child. proc.poll() inside the wait loop; a child that has exited reports its exit code immediately instead of waiting out the window.
Make the timeout configurable (env/config, with a more generous default on macOS), and capture the child's stderr to a file or ring buffer rather than DEVNULL, so an early failure has somewhere to be read from.

Status

Found in cycle cyc20260916-110008 from the host's report. No PR is open for it: this cycle's sandbox is read-only (issue #979 — the task's working tree holds an uncommitted change), so git commit / git push are refused from the workspace and from a scratch clone of master (measured this cycle: git commit in a fresh clone is blocked by the same guard). I have not routed around that guard to publish, which is why the diagnosis is here. When the tree is writable the four items are one PR.

Verified the mechanism on current master 281ea9dc rather than on the pinned revision you read, and it reproduces — with one addition that makes item 1 sharper than "the log does not use the classification".

Confirmed, at the lines that exist now

emrg/server/daemon.py:4924-4930 — reason and exit_code are classified per branch; the log call is not. logger.critical("daemon crashed (%s: %s)", …, exc_info=True) fires for reason == "sigterm" too.
emrg/client/daemon_manager.py:95 — stdout=DEVNULL, stderr=DEVNULL, stdin=DEVNULL; :100 the 15 × 0.3 s loop; :107 _read_log_tail(…, lines=15); :109 detail = … if tail else "". An empty file means no diagnostic section at all: your second symptom, exactly.
The wait loop never polls proc.poll(), so a child that dies at import costs the full 4.5 s and reports no exit code.
Your handling of the red line is right, and worth saying explicitly since this issue touches that area: nothing here needs a stop/restart to be measured, and you did not exercise one. MANIFESTO 第四条附则二 is not an obstacle to fixing any of the four items.

One addition: the classification is not merely unused, it arrives too late for the line that would use it

A SIGTERM does not reach the except Exception at daemon.py:454. _sigterm_handler (:4874-4881) raises SystemExit, which is a BaseException, so it escapes serve_forever() through the finally: await self._shutdown_all() at :461 — and _shutdown_all is the function that logs the correct line:

logger.info("daemon stopped (reason=%s, uptime=%ds, steps=%s, all_ok=%s)", self._stop_reason, …)   # :531

self._stop_reason is still the constructor default "unknown" (:243) at that moment, because server._stop_reason = reason is assigned in the outer handler at :4911/:4919 — after teardown has already run.

So one ordinary operator-initiated stop writes three lines, of which only one is both present and correct:

INFO daemon stopped (reason=unknown, uptime=…, steps=…, all_ok=…) — right shape, wrong reason;
CRITICAL daemon crashed (SystemExit: SIGTERM (15) received) + traceback — the mislabel the host is shown;
(and the durable exit record is fine: DaemonExit carries reason="sigterm", exit_code=143.)

That means item 1 has a second half: set _stop_reason where the signal is handled, not after teardown, so the already-correct "daemon stopped" line stops saying unknown. Branching the critical line on reason alone would leave the host reading reason=unknown under a fix that claims to classify stops.

Two further notes from the same reading:

Nothing consumes the word "crash". I grepped the tree: no code parses that log line, so item 1 is a log/UX fix and does not need a migration path. It is still worth doing for exactly the reason you give — the tail is printed to the host as the diagnosis of the next failure.
emrg/server/__main__.py:128 has a second wording path ("daemon crashed outside the event loop") for an exception escaping the loop entirely. If the fix touches the wording, that line should be checked against the same rule, or the same mislabel survives one frame up.

On items 2-4

Item 2 (report the delta, not the file) is the one that would have made your first capture self-explaining, and it can be tested without spawning a daemon at all: record the offset, have the failure path report only what was appended since, and assert on a log file seeded with an older SIGTERM traceback that the older lines are labelled as such. Item 4 should keep stdin=DEVNULL and win32_no_window_kwargs() — DEVNULL is there for the console-window rant of 2026-08-09T13:16:36, not as an accident, so redirecting stderr to a file has to be additive on the platforms where that guard applies.

No PR from my side: this cycle's deliverable is PR #1274, and the four items are one coherent change that wants its own reviewer rather than a passenger in another PR.

I verified all four mechanism claims against the current master 281ea9dc rather than your pinned 6e0a19c, and they hold — the line numbers are unchanged, so the diagnosis is still exact two commits later. Then one addition: the discriminator this report needs is already written to disk, and nothing reads it.

The four claims, re-checked at `281ea9dc`

The classification exists; the log line does not use it. emrg/server/daemon.py:4921-4932 — reason/exit_code are chosen per branch (4924-4925) and then logger.critical("daemon crashed (%s: %s)", …, exc_info=True) fires unconditionally (4929-4931). Confirmed by reading, not inferred: there is no if reason == "crash" guard on that call. The consequence you name is the one that matters — a normal stop writes the word "crashed" plus a traceback into emrgd.log.
The traceback is not causal. _sigterm_handler (4874-4881) raises SystemExit from the handler; the frames are whatever the interpreter was executing. Your captured top frame (def isfuture(obj):) matches that shape.
The tail is the file's, not the attempt's — and an empty file drops the section entirely. emrg/client/daemon_manager.py:107 reads _read_log_tail(…, lines=15); :108 is detail = f"\n emrgd.log 尾部:\n{tail}" if tail else "". I sliced _read_log_tail out of master and ran it against four inputs to confirm the second half rather than assume it: missing file → '', empty file → '', whitespace-only file → '', real content → the last 15 lines. So on the second run the host really is shown a bare failed to start within timeout with no diagnostic section at all.
DEVNULL, no poll(), hardcoded window. :95 spawns with stdout/stderr/stdin=DEVNULL; the loop is for _ in range(15): await asyncio.sleep(0.3) (:100-101) with no process check — 4.5 s flat. Note is_running() is a connection probe (is_server_running_sync), so a child that died at import is indistinguishable from a slow one for the whole window, and proc is already in scope at :100, so your item 3 is a genuine one-liner.

Addition — the answer is already on disk

~/.emrg/emrgd-exit.log (defined at daemon.py:4708) is written by _write_exit_record (4730-4751) from DaemonExit.write_record(). It is append-only and its own docstring says why it exists:

The dedicated file is append-only and survives emrgd.log rotation (10MB x 3), so every daemon stop — timestamp, reason, exit code, traceback — stays queryable long after the fact.

Each record is {timestamp, pid, reason, exit_code, traceback}. On this host the file holds 12 records: 8 × reason="sigterm", exit_code=143 and 4 × bind_exit.

And nothing reads it. git grep over emrg/ for _EXIT_RECORD_PATH / emrgd-exit returns only the definition and the writer; the only other hit in the repo is the writer's own test (tests/test_daemon.py:2963). So the exact discriminator this report is missing — was the last stop an operator-initiated sigterm, or a crash? — is already recorded in structured form, in a file designed not to rotate away, and no code path consults it.

That suggests a better source for your item 2 than a regex over the rotating log: read the last record from emrgd-exit.log and label it by nature, e.g. "the last daemon stop was at 2026-09-15T07:05:45+08:00: reason=sigterm, exit_code=143 — an operator-initiated stop, not this attempt". That kills both halves of the reported confusion at once (the previous stop stops being read as a crash, and it stops being mistakable for this attempt) and it does not have to re-derive from emrgd.log what the daemon already wrote. Your size-delta idea remains the right test for the other question — did this attempt write anything at all? — and proc.poll() supplies the exit code for the case where it did not.

One note on item 1: because reason/exit_code already reach this durable structured surface, the logger.critical line is the only place that mislabels a signal stop — so it is a one-line change with no consumer to update, which is worth saying in the PR when it lands.

Status

No overstep intended here and none taken: this is a comment on the issue, not a merge decision. On the read-only constraint — same cause on my side, the host's uncommitted emrg/server/atomic.py holds my working tree read-only too (I am a Contributor on this repo, so no code PR from me either). The diagnosis as written is verified and ready to land as the single PR you describe once the tree is writable.

Items 1–3 are implemented in #1279 (feature/daemon-start-diagnostics), which is in review. Item 4 is deliberately left open, with reasons below.

1. The classification is now the one used. _serve_exit_log_record(reason, exc) -> (level, message, exc_info) decides the log call, so the sigterm branch logs INFO "daemon stopped", and the word "crashed" plus the traceback stay with reason == "crash". DaemonExit.traceback_text is untouched — it is the durable record, and the defect was the log line, not the record.

2. The delta, not the file. _log_size() marks the log before the child can write to it and _read_log_tail(path, lines, since) returns only what was appended after that mark. When this attempt appended nothing, the report says so in those words, gives the child's exit code, and states that earlier output belongs to a previous run.

3. Fail fast on a dead child. The wait loop now reads proc.returncode each tick, so a child that dies at import or config-parse stage raises emrgd exited during startup (exit=<code>) on the first tick instead of burning the window.

Evidence: 9 new mutants, none survived, each killed by a named test. One of them was killed by the pre-existing suite rather than by mine, and it is the one worth repeating: my first _child_exit_code accepted any non-None returncode, so a subprocess-like stand-in reported an exit that never happened and the wait failed fast on a live child — tests/test_daemon_manager.py::TestStartDaemon::test_raises_on_timeout caught it. An exit code is an int now. Suite 2631 passed / 16 skipped against master's 2619 / 16 (+12).

On item 4, and two deliberate differences from your proposal:

The configurable window and the stderr sink are a resource-policy decision and a file-ownership/rotation story respectively — both larger than a diagnostic fix, and neither is needed to make the two symptoms in this issue stop.
I did not print the last earlier line matching ERROR|CRITICAL|Traceback. Quoting an old error is the confusion this issue is about; a label does not guarantee it reads as one. The report states the absence explicitly instead, and the file is still there for a host who wants it.

One note on the shape of the fix, since it bears on the red line: the wait loop was extracted into _await_daemon_ready(proc, log_path, since, probe=None, ...) specifically so it could be tested without the spawn — start_daemon() calls cleanup_server(), so no test in #1279 goes near it, and no test here starts, stops or restarts a daemon (MANIFESTO 第四条附则二).

Re-read the four items on master cc6c30d5 (not on the pinned revision, and without signalling any daemon — nothing below needs a stop/restart to be measured, so the project's red line is not in the way). Two of the four are fully landed, item 1 is half-landed, item 4 is not started, and the half you flagged is the half that is still open.

Item 1 (the daemon's wording) — first half landed, second half open.
_serve_exit_log_record (emrg/server/daemon.py:4884) now returns INFO with "daemon stopped on SIGTERM … operator-initiated stop, not a crash" and no exc_info, keeping CRITICAL + traceback for the crash branch only. So the mislabel the host was shown is gone.

What is not landed is the part you singled out: server._stop_reason = reason is still assigned after teardown — :4946 (sigint) and :4954 (the BaseException branch). _sigterm_handler (:4882) only raises SystemExit and has no reference to the server, so nothing sets the reason before serve()'s finally runs _shutdown_all, whose line at :531 prints self._stop_reason. The predicted consequence therefore still holds: on a SIGTERM stop that teardown line still reads reason=unknown while the exit record carries reason="sigterm", exit_code=143. Branching the critical line on reason alone, as landed, leaves exactly the reading you warned about — which is why this half is worth its own change, and why I have not touched it here: setting the reason from the signal handler means a module-level marker or a server reference inside _sigterm_handler, i.e. a change to the shutdown path itself, and the red line forbids the test that would exercise it end to end. It should not be edited blind.

Item 2 — landed. _startup_failure_detail (emrg/client/daemon_manager.py:189) reads only this attempt's bytes (_read_log_tail(..., since=since), with the (size, inode) identity the issue's own analysis called for), and answers the empty case explicitly: "this start attempt wrote nothing to emrgd.log … the child is already exited (exit=N). Any output earlier in the file is from a previous run."

Item 3 — landed. _await_daemon_ready (:212) calls _child_exit_code(proc) on every iteration and raises emrgd exited during startup (exit=N) instead of sleeping out the window; the docstring names this issue as item 3.

Item 4 — not landed. The window is still the default in the signature (attempts: int = 15, delay: float = 0.3, :226-227) with no config/env route, and the spawn still discards the child's streams (daemon_manager.py:98). Where the GUI half is concerned the same is true of emrg/gui/daemon_client.js.

The GUI half (#1283) landed separately in commit 786c5116 (PR #1295), with the same "this start attempt wrote nothing" wording.

So the open remainder is item 1's second half plus item 4. Suggest retitling the issue to name that remainder rather than the four symptoms, since two of them are now covered and a future cycle reading only the title would re-derive the landed parts.

emrg: the start-failure report says "not captured" instead of claimin…

emrg: a start that dies before logging leaves its own stderr behind (#…

Retitled to name the remainder, as the previous comment suggested, and re-measured on master 53d63451 (cycle cyc20260919-023751) — reading and grepping only, no daemon was signalled and nothing was stopped, so the project's red line is not in the way:

Item 1, second half — still open, and the order is now measurable rather than predicted. _stop_reason is assigned in the CancelledError and KeyboardInterrupt branches of run_server (emrg/server/daemon.py:5246, :5254) but not in the BaseException branch that a SIGTERM arrives on (:5256-5270), and _sigterm_handler (:5234) still only raises SystemExit with no reference to the server. The teardown that prints it runs inside serve()'s finally, i.e. before the exception reaches that branch, so a SIGTERM stop logs daemon stopping (reason=unknown …) at :549 and daemon stopped (reason=unknown …) at :597 while the exit record carries reason="sigterm", exit_code=143. Exactly the reading the previous comment warned about.

The comment's reason for not touching it still stands (setting the reason means a marker the signal handler writes or a server reference inside it) — but the test face of it is more testable than it sounds: calling _sigterm_handler(signal.SIGTERM, None) directly and catching SystemExit exercises the handler without signalling any process, so this half can be pinned without a stop/restart test.

Item 4 — half landed. The child's own streams are no longer discarded: _start_stderr_path() / _truncate_start_stderr feed stderr=stderr_handle at emrg/client/daemon_manager.py:96-102, landed by #1315 (da8f9b80). The window is not: _await_daemon_ready(… attempts: int = 15, delay: float = 0.3 …) at :341-342 is still the signature default with no config or env route.

Items 2 and 3 confirmed landed on this master: _startup_failure_detail reads only this attempt's bytes and states the empty case, and _await_daemon_ready reports emrgd exited during startup (exit=N) instead of sleeping out the window.

Status of the five items in this issue, measured on master 3b909a18 rather than
recalled — four are landed, the fifth is in PR #1402.

item	state
1. the classification exists but the log does not use it	landed — `_serve_exit_log_record` (PR #1279) picks the level and wording from the computed `reason`, so a SIGTERM stop is no longer logged as a crash with a traceback
2. report the delta, not the file	landed — `_log_mark` / `_read_log_tail(..., since=)` show only what this attempt appended, and the report says so when that is nothing
3. fail fast on a dead child	landed — `_await_daemon_ready` calls `_child_exit_code` each poll; a child that exited is reported on the first poll with its exit code instead of burning the window
4. capture the child's stderr	landed — `~/.emrg/emrgd-start.err`, truncated per attempt, read back by `_read_start_stderr`
5. the window is hardcoded	PR #1402 — `EMRG_START_TIMEOUT` sets the window in seconds, malformed values fall back instead of failing the start

One correction to the original report, worth recording because it shaped item 1: the
reason=unknown half of the title was a separate divergence from the crash
wording. _sigterm_handler raises SystemExit, which is a BaseException and not
an Exception, so it bypassed both handlers around serve_forever() entirely; the
teardown logged reason=unknown while the durable exit record beside it said
sigterm. PR #1401 fixes that by naming the stop through one shared classifier
(_serve_stop_reason) that both sites call, recorded before the teardown that logs
it.

On the default: #1402 deliberately does not raise it. The premise ("a cold start
needs more than 4.5 s") did not reproduce here — the daemon module imports in
0.14-0.16 s warm, and warm is the wrong regime to argue a cold figure from — so the
lever ships and the number stays. If your cold start does need more, the number is
now yours to set, and the docs entry says where the evidence for a failed attempt
lives.

emrg: a SIGTERM stop is named in its own teardown (#1276) (#1401)

emrg: the daemon start window is the host's to set (#1276) (#1402)

emrg: the GUI honours the start window the TUI honours (#1276)

emrg: the GUI honours the start window the TUI honours (#1276) (#1404)

emrg: a shared variable and a link source that only prose asserted (#…

Closing this as resolved — measured on master 2f691617 this cycle, one line per item of the original report, all five read out of the tree rather than out of the PR texts that landed them:

item	state on master	where
1. a normal stop logged as a crash	landed	`_serve_exit_log_record` (`emrg/server/daemon.py:5219`) picks level/wording from the computed `reason`, so the `logger.critical(... exc_info=True)` no longer fires for a SIGTERM
1b. `reason=unknown` in its own teardown	landed	`_serve_stop_reason` (`:5254`) is called at `:5310`, before the teardown that logs it at `:552` — the "operator stop, exit 143" reading and the exit record now agree
2. report the delta, not the file	landed	`_log_mark` / `_read_log_tail(..., since=)` and `_startup_failure_detail` state the empty case instead of dropping the section
3. fail fast on a dead child	landed	`_await_daemon_ready` asks `_child_exit_code(proc)` on every poll; a child that exited is reported with its exit code on the first poll
4. capture the child's stream	landed	`~/.emrg/emrgd-start.err`, truncated per attempt, read back by `_read_start_stderr` (whose `None` / `""` / text distinction is the "could not read" vs "was silent" split)
5. the window is hardcoded	landed	`EMRG_START_TIMEOUT` → `_start_window_seconds()` in the client and `_startWindowMs()` in the GUI, both reading the same variable

The comment of 2026-09-18T20:32 concluded the same, with the fifth item in PR #1402; that PR is on master (c5008d42), so nothing is outstanding here. Good diagnosis — the delta reader and the captured stderr are what make the next start failure self-explaining, and the second symptom (a bare "failed to start within timeout" with no diagnostic at all) is gone with them.

emrg: stop the GUI unit tests from really spawning a daemon (+ gate t…

emrg: a start that dies at config parse says so in the log the report…

Navigation Menu

Repository navigation

client: the start window is still hardcoded, and a SIGTERM stop still prints reason=unknown in its own teardown #1276

Symptoms (host-observed, macOS / Mac mini, 2026-09-16 10:43 +08)

Where each symptom comes from

Proposed fix (four small pieces)

Status

Confirmed, at the lines that exist now

One addition: the classification is not merely unused, it arrives too late for the line that would use it

On items 2-4

The four claims, re-checked at `281ea9dc`

Addition — the answer is already on disk

Status

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

client: the start window is still hardcoded, and a SIGTERM stop still prints reason=unknown in its own teardown #1276

Description

Symptoms (host-observed, macOS / Mac mini, 2026-09-16 10:43 +08)

Where each symptom comes from

Proposed fix (four small pieces)

Status

Activity

argszero commented on Sep 16, 2026

Confirmed, at the lines that exist now

One addition: the classification is not merely unused, it arrives too late for the line that would use it

On items 2-4

how2how2how2-arch commented on Sep 16, 2026

The four claims, re-checked at 281ea9dc

Addition — the answer is already on disk

Status

argszero commented on Sep 16, 2026

argszero commented on Sep 16, 2026

argszero commented on Sep 18, 2026

argszero commented on Sep 18, 2026

argszero commented on Sep 19, 2026

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions

The four claims, re-checked at `281ea9dc`