chore: record spawnpod hang report and local manifest

This commit is contained in:
Keisuke Hirata 2026-05-28 06:21:01 +09:00
parent 47cc6234be
commit 7cb1804504
2 changed files with 132 additions and 1 deletions

View File

@ -1,9 +1,11 @@
[scope]
allow = [
{ target = ".", permission = "write", recursive = true },
{ target = "<external-checkouts>", permission = "read", recursive = true },
]
[session]
record_event_trace = true
[memory]
extract_threshold = 50000

View File

@ -0,0 +1,129 @@
# SpawnPod 実行後に assistant 応答が返らなかった観測
## 対象セッション
Main Pod session log:
```text
<insomnia-sessions>/019e5d30-f7ad-7fb1-bdec-c592e888e290/019e5d30-f7ad-7fb1-bdec-c5a41394e6b1.jsonl
```
Session id:
```text
019e5d30-f7ad-7fb1-bdec-c592e888e290
```
Segment id:
```text
019e5d30-f7ad-7fb1-bdec-c5a41394e6b1
```
## 発生箇所
`tui-actionbar-transient-notice-api` の実装委譲で `SpawnPod` tool を呼んだ直後、tool result は session log に記録されているが、その後 assistant message が続かず、次の user message `okay?` まで約25分空いた。
Spawn した Pod:
```text
impl-tui-actionbar-transient-notice-api
```
Worktree:
```text
<repo>/.worktree/tui-actionbar-transient-notice-api
```
Socket:
```text
<runtime-dir>/impl-tui-actionbar-transient-notice-api/sock
```
## session log 上の時系列
該当 session log の行番号:
```text
4242: assistant_item tool_call SpawnPod
4243: tool_result for SpawnPod
4265: user message "okay?"
4266: assistant response to "okay?"
```
時刻:
```text
SpawnPod tool_call ts: 1779769846743 ms = 2026-05-26T13:30:46+09:00
SpawnPod tool_result ts: 1779769846957 ms = 2026-05-26T13:30:46+09:00
next user "okay?" ts: 1779771369887 ms = 2026-05-26T13:56:09+09:00
assistant response ts: 1779771389978 ms = 2026-05-26T13:56:29+09:00
```
Duration:
```text
SpawnPod tool_call -> tool_result: 214 ms
SpawnPod tool_result -> next user message: 1,522,930 ms = 25m22.930s
next user message -> assistant response: 20,091 ms = 20.091s
```
## SpawnPod tool_call payload
Tool call id:
```text
call_vzIr5gYbIPz3ey34gkkQ5s0X
```
Tool name:
```text
SpawnPod
```
Arguments summary:
```text
name: impl-tui-actionbar-transient-notice-api
scope:
read: <repo>
write: <repo>/.worktree/tui-actionbar-transient-notice-api
task: implementation request for tickets/tui-actionbar-transient-notice-api.md
```
## SpawnPod tool_result
The tool result is recorded immediately after the call and reports success:
```text
spawned pod `impl-tui-actionbar-transient-notice-api` listening on <runtime-dir>/impl-tui-actionbar-transient-notice-api/sock
```
This means the observed pause is not visible in the session log as a long-running `SpawnPod` tool call. The tool call/result pair itself is 214 ms apart.
## 観測事実
- `SpawnPod` returned a successful tool result in the main session log.
- No assistant message appears immediately after that tool result.
- The next recorded input is the user message `okay?` about 25 minutes later.
- After `okay?`, the assistant responded normally.
- Therefore, from the recorded main session log alone, the gap is after the `SpawnPod` tool result and before the next assistant message, not inside the recorded `SpawnPod` tool execution.
## 関連する実装状態
At this point `SpawnPod` had recently been changed so that initial task delivery uses confirmation (`send_run_and_confirm`) rather than fire-and-forget. However, this report does not establish that confirmation caused the pause; the log data above only shows that the `SpawnPod` tool result was recorded quickly.
## 調査に必要な追加データ
To identify the actual wait point next time, record or inspect:
- LLM request lifecycle immediately after the `SpawnPod` tool result.
- `LlmCallStart` / `LlmRetry` / `LlmCallEnd` if present.
- provider HTTP status / retry state if present.
- runtime log around the same timestamps for the main Pod.
- child Pod session log for `impl-tui-actionbar-transient-notice-api`.
- whether assistant generation was started after the tool result or never scheduled.