Merge pull request #2969 from square/debug-follow-along

Log the full agent traffic, and which way in each message came

Author: pyricau

.claude/skills/shark-dive/SKILL.md

@@ -54,6 +54,9 @@ was built debuggable or the whole device build is; `list_devices` says which.
 ```
 
 An investigation somebody already ran is either the answer or the half of the dump not worth doing again.
+Adding `session=<id>` reads one of them call by call, each with the exact text it sent and read back — which
+is how you tell a step that read an answer from one that misread it, and a long answer for that reason, so
+reach for it when a run went wrong rather than as a matter of course.
 
 ## The command line
 

docs/shark-dive-changelog.md

@@ -80,8 +80,18 @@ uses, without the one for a newly recognized library leak:
   one is everything that agent did — what each call did, which object it did it to, and the sentence it gave
   for making it, with the refusals in red. A row leads where the call went, so reading what an agent did and
   going to look at it are one move — including a row about a heap dump this window hasn't got, which opens
-  that dump, and whose link is there to copy like every other. Kept in `~/.shark-dive/agents/sessions`,
-  one file per session and the newest hundred kept, so a session outlives the window it was worked in.
+  that dump, and whose link is there to copy like every other. **And every row unfolds onto the call itself**,
+  what was sent and what came back, as the text each of them was and never a first line of it: a reason is
+  what an agent *said* it was doing, and a step taken on an answer that said nothing reads exactly like one
+  taken on an answer that said everything until you open both. The `▸ {}` under a row is what opens it, and
+  what was sent names the tool the agent called as well as what it sent to it — `describe_object` beside the
+  window's own word for it, which is the pair worth having when a step doesn't follow. **The full traffic, not
+  only the calls that worked**: the handshake, a call naming a tool that doesn't exist and a line that wasn't
+  JSON are rows too, a refusal and an error are under `answered:` as the agent was handed them, and each row
+  says whether it came in over MCP or from `--agent` at a shell — because what this screen gets opened for is
+  often why *nothing* happened. `agent_log` hands an agent the same text, so one agent can work out where
+  another went wrong. Kept in `~/.shark-dive/agents/sessions`, one file per session and the newest hundred
+  kept, so a session outlives the window it was worked in.
   See [Hand it to an agent](shark-dive.md#hand-it-to-an-agent).
 * ✨ **The chain marks the faulty reference**: the one step going from an `Expected` object straight to a
   `Stuck` one reads `Holder.activity · faulty reference`, which is the leak itself rather than one of the

docs/shark-dive.md

@@ -371,7 +371,7 @@ press, because a surface with less than that is one whose answer is "ask your hu
 | --- | --- |
 | `open_heap_dumps` | Every heap dump open, by the file name the other tools take, with the method to follow. |
 | `list_leaks` | The **Leaks** screen: what this heap dump says shouldn't be there. |
-| `agent_log` | The **Agent logs** screen: what has already been tried on this dump, and what it came to. |
+| `agent_log` | The **Agent logs** screen: what has already been tried on this dump, and what it came to — and, for one session, every call it made with the text it sent and read back. |
 | `chain_from_gc_root` | One chain, every step with its labels and its verdict. |
 | `describe_object` | What an object is: its class, fields, labels, size. |
 | `ways_held` | Every way an object is held, rather than the one chain — the *X ways from here* list. |
@@ -419,11 +419,14 @@ unexplained steps cannot report a root cause, however sure it is, and what it ge
 objects to go and read.
 
 **What it did is on the *Agent logs* screen**, one row per agent that has connected to the app. Open a row
-and there is every call that agent made, in order and in words — what it did, which object it did it to, and
-the sentence it gave for doing it:
+and there is everything that agent sent, in order and in words — what each call did, which object it did it
+to, and the sentence it gave for doing it:
 
 ```
-08:23:04 ▸ Asked which heap dumps are open
+08:23:01  Connected
+08:23:01  Sent the notification notifications/initialized
+08:23:02  Asked what the tools are
+08:23:04  Asked which heap dumps are open
           because: Seeing what there is to read before asking anything about it.
 08:23:11  Listed the leaks
           because: Starting from what the heap dump already says shouldn't be here.
@@ -440,8 +443,8 @@ the sentence it gave for doing it:
 *0x12d368b8* on *Read the chain to 0x12d368b8* and the window opens that object, so reading what an agent did
 and going to look at it are one move. A call that named nothing went somewhere all the same — *leaks* on
 *Listed the leaks* is the leaks screen, and *dominator tree* on *Read the dominator tree* is the tree from its
-root. The one row that leads to several places unfolds instead: *Asked which heap dumps are open* opens into
-the dumps that were open, each of them a window away.
+root. The one row that leads to several places keeps them behind its fold instead: *Asked which heap dumps are
+open* opens into the dumps that were open, each of them a window away.
 
 **A refused call is a row too**, in red, under the reason the agent gave for making it — and those are the
 half of a session worth reading, since a refusal is where the method sent an agent back to the heap dump
@@ -454,10 +457,81 @@ rather than on to an answer:
           reference: the rules can only name one once something below it is known not to belong. […]
 ```
 
+**And so is every other line that arrived** — the three at the top of that session are the handshake. A call
+naming a tool that doesn't exist, a line that wasn't JSON at all, a read that failed: each is a row, and the
+ones nothing could answer say *Failed* rather than *Refused*, which is the opposite claim. A refusal is the
+method working; this is Shark Dive not working.
+
+```
+08:24:02  Called solve_the_leak 0x12d368b8
+          because: Trying my luck.
+          Failed: There is no tool called "solve_the_leak". This server has open_heap_dumps, […]
+08:24:09  Sent something this app could not read
+          Failed: That is not JSON: Unexpected JSON token at offset 0
+```
+
+Which is the point of keeping them: what this screen gets opened for is often why *nothing* happened, and a
+screen holding only the calls that worked is the one screen that can't answer that. It shows in the shape of a
+session — one sent from a shell is a *Connected* per call, `--agent` being a process per call — and the
+`n call(s)` above the rows counts the calls rather than the lines.
+
+**And every row unfolds onto the call itself** — the `▸ {}` under a row opens what the agent sent and what it
+read back, as the text each of them was, so a step you don't follow is one question rather than a dead end:
+
+```
+11:37:31  Looked at 0x12d368b8
+          because: The one App leak: a MainActivity the app watched. Reading what it is before the chain.
+          ▾ {}
+            sent over MCP:
+              describe_object {
+                  "object": "0x12d368b8",
+                  "reason": "The one App leak: a MainActivity the app watched. Reading what it is
+                             before the chain."
+              }
+            answered:
+              {
+                  "object": "0x12d368b8",
+                  "label": "MainActivity",
+                  "className": "com.example.leakcanary.MainActivity",
+                  "kind": "INSTANCE",
+                  "strength": "STRONG",
+                  "shallowBytes": 214,
+                  "retainedBytes": 210978,
+                  "verdict": "STUCK",
+                  "verdictReason": "ObjectWatcher was watching this and Activity#mDestroyed is true",
+                  […]
+              }
+```
+
+What it sent is the tool's own name and then the arguments under it, which is the call as the model wrote it:
+*Looked at* is this window's word for `describe_object`, and the pair is worth having side by side exactly
+when a step doesn't follow from the one before it. And *over MCP* is which way in it came — a client holding a
+connection open, or `--agent` typed at this window — which is the one thing about a call that nothing else on
+the screen can tell you, since by the time anything answers one the two are the same protocol on the same
+socket.
+
+Whole, never a first line of it: what you open a call for is the part the sentence left out, so an answer cut
+to fit would be one where the field that misled the agent is the part that got cut. And a session recorded by
+an older Shark Dive says so rather than opening onto a gap.
+
+**Including the calls that came to nothing**, which is what this is most worth opening for. A refusal is
+under `answered:` as the agent was handed it, as well as in red on the row; so is an error, if a read failed
+or this app has a bug; so is the answer to a call naming a tool that doesn't exist. The only row with nothing
+under `answered:` is a notification, which is the one kind of message the protocol forbids answering.
+
+The mark is under the row rather than on the verb because a row is a sentence with one link in it, and a fold
+over its first words made hovering light up the half that isn't the link.
+
+**Reading it is what makes the reasons worth anything**, since a reason is what an agent *said* it was doing:
+a step that reads as sound and was taken on an answer that said nothing looks exactly like a step taken on
+one that said everything, until you open both. Select and copy either half — into an issue, into a message to
+whoever handed you the dump, into a diff of two runs.
+
 A session is kept in `~/.shark-dive/agents/sessions`, one file per agent that connected and the newest
-hundred kept, a line of JSON per call — so it outlives the window and can be read by something other than
-this app. **And the reads each call cost are in the run's log**, in `~/.shark-dive/logs`, where the reason
-it gave is followed by the work it caused:
+hundred kept, a line of JSON per message, each carrying that message's `input` and `output` — so it outlives
+the window and can be read by something other than this app. `agent_log` hands an agent the same text, which
+is how one agent works out where another went wrong. **And the reads each call cost are in the run's log**, in
+`~/.shark-dive/logs`, where the reason it gave is followed by the work it caused:
 
 ```
 18:19:48.035 [shark-dive-agents] An agent called chain_from_gc_root(object=0x12d368b8, window=zvphq4r3)

shark/shark-dive/notes/agent-surface.md

@@ -25,6 +25,36 @@ mitigations that shipped in 2026 (Anthropic's tool search, code execution over M
 **This surface is not where a context window goes to die**, and a per-tool cost of ~300 tokens is what buys
 descriptions that say when to reach for a tool. Re-measure it if the count doubles again.
 
+## And what reading somebody else's session costs
+
+`agent_log` without a session id is a line per session and cheap. With one, it is now every *message* of that
+session with what each one sent and read back, which is the only form that answers "why did it do that
+next" — and the numbers are worth knowing before reaching for it. Measured against a packaged run on
+`leak_asynctask_o.hprof`: four calls typed at `--agent` (two `list_leaks`, a refused `conclude`, a
+`solve_the_leak` that is no tool) and four messages pushed at the socket by hand (a line that is not JSON, a
+`resources/list`, a `tools/call` with no name, a notification):
+
+| | Measured |
+| --- | --- |
+| The four tool-call rows | 8,783 + 8,775 + 1,750 + 987 characters — the answer is nearly all of each |
+| The four protocol rows | 37,313 characters, of which **32,976 is four `initialize` answers** |
+| The whole `agent_log session=…` answer | 57,693 characters, ≈14,400 tokens |
+
+So **a tool call is one to two thousand tokens** and a thirty-call investigation read in full is most of a
+small context window. That is the tool being used for what it is for rather than a leak — it is the one call
+on this surface whose subject is somebody else's whole investigation.
+
+**The handshakes are the surprise, and they are a command line's.** `initialize` answers with
+`AgentMethod.INSTRUCTIONS`, and `--agent` is a process per call, so a session of typed calls carries the
+method once per call: 57% of the answer above, handed to a reader that already has the same text in its own
+context. An MCP session pays it once. Nothing about that is a reason to record less — a session that keeps
+only what reached a tool cannot say why nothing did, which is the whole point of keeping the traffic — but if
+`agent_log` needs to be cheaper, **the handshake answers are where to look first**, and the shape to reach
+for is a way to ask for one message's exchange rather than a shorter version of every message's.
+
+Nothing truncates it, deliberately: a session cut to fit is one where the answer that misled an agent is the
+part that got cut.
+
 ## What the command line costs, now that there is one
 
 `--agent <tool> name=value …` is a process per call, and the thing to know is what that *doesn't* cost.

shark/shark-dive/shark-dive-agent/AGENTS.md

@@ -85,6 +85,41 @@ heap dump read on every call to answer a question the reader already has the dum
 can open a second dump, and a call about one this window hasn't got is a row it leaves as the address, saying
 which file, and opens that dump when clicked.
 
+**A call keeps the exchange as well as this app's reading of it.** `input` is the tool's own name and then
+the arguments as they arrived, formatted, and `output` is the answer as the text that reached the model — the
+same string `toolResult` puts in `content[0].text`, formatted once and then both answered with and written
+down, so that a session can be compared against a client's own transcript character for character. Everything
+else on a call is derived, and a derived field is the one thing that is no use when the question is why an
+investigation went wrong: a step made on an answer that said nothing reads exactly like a step made on one
+that said everything.
+
+**`output` is what went back, whatever that was.** A refusal is in it as well as in `refused`, and an error as
+well as in `error`, and the two are not the same field said twice: `refused` and `error` are this app's
+reading — the method said no, this app could not answer — and `output` is the text the agent was handed. The
+first version left `output` null for a refusal on the grounds that the refusal was already written down, and
+what that looked like from outside was a call that got no answer at all. **Null on `output` means nothing went
+back**, which is a notification and nothing else.
+
+**And a line goes down for every message, not only the ones that reached a tool.** The handshake, a
+`tools/list`, a ping, a notification, a method this build has never heard of, a `tools/call` with no name or a
+name nothing answers to, and a line that was not JSON: all of them. `tool` is null for the ones that reached
+no tool and `method` says what arrived instead, `AgentSession.toolCalls` is the subset that got as far as a
+tool, and **that distinction is not cosmetic** — the eval counts calls, and a run scored on lines sent would
+have a number that moved with the transport. `AgentSessionCall.over` is which way in a line came, told to
+`McpSession` at construction because a command line and an MCP client are indistinguishable from the moment
+the handshake is past, which is the point of them. The word travels as the last field of `AgentServer`'s
+handshake line, and a connection that says nothing is MCP.
+
+The name is in `input` even though `tool` has it, and that is not an oversight: this field is read as one
+thing, and a set of arguments lifted away from what they are arguments *to* is the one form of a call nobody
+can read on its own.
+
+Two things follow. The window's *Agent logs* screen unfolds **every** row onto this, not only the one that
+answers with a list, and does it from a mark under the row rather than from the verb, so a row stays a
+sentence with one link in it. And `agent_log` with a session id hands the same text over, which makes it the
+one expensive call on this surface — `notes/agent-surface.md` has the measurement. Neither of them truncates:
+a session cut to fit is one where the answer that misled an agent is the part that got cut.
+
 **Two fields come off the answer instead.** What an agent asked is what it typed, and what it concluded is
 what the heap dump *agreed to* — so `outcomeOfTool` reads the reference out of `conclude`'s answer. Both
 readers need that one and neither can work it out: the screen's last row is what a session came to, and the
@@ -95,8 +130,10 @@ answer printed twice.
 
 **The verbs are here rather than in the app.** `verbOfTool` is beside the tool names, so that a screen never
 spells them itself and drift is one list rather than two. `AgentSessionFileTest` asserts every tool in the
-registry has one; a tool added without a verb reads as its own name, which is the protocol showing through on
-the screen that exists to not show it.
+registry has one — **which is what makes the fallback mean something**: a name `verbOfTool` has no verb for is
+a name this build has no tool for, so a row reading `Called solve_the_leak` is a typo or a tool from a newer
+build, and the name is left exactly as it arrived because that string is what somebody is looking for. A
+message that reached no tool at all reads through `verbOfMethod` instead.
 
 **A verb stops where the thing it was about starts**, which is why several of them end mid-sentence: a row of
 that screen is prose with one link in it, and the link is the thing. So `list_leaks` is "Listed the" and
@@ -133,10 +170,10 @@ to one adapter and not the other is the mistake this shape exists to make imposs
 `notes/agent-surface.md`, which also has what a call costs.
 
 **A process per call would otherwise be a session per call**, and a session is what somebody reads afterwards.
-So the handshake is `token[ sessionName]` on one line, `AgentSessionFile.continuing` appends to the newest file
-whose name carries that id, and a command line defaults to `cli<the shell's pid>` — an agent's calls come out
-of one shell the way its MCP calls come out of one connection. A client that says nothing gets a session of
-its own, which is what every MCP client does.
+So the handshake is `token[ sessionName[ over]]` on one line, `AgentSessionFile.continuing` appends to the
+newest file whose name carries that id, and a command line defaults to `cli<the shell's pid>` — an agent's
+calls come out of one shell the way its MCP calls come out of one connection. A client that says nothing gets
+a session of its own, which is what every MCP client does, and its lines are recorded as MCP.
 
 **The name is checked at both ends**, because it becomes part of a file name: the command line refuses one
 that isn't letters and digits before calling anything, and `AgentServer` serves the connection anyway with a

shark/shark-dive/shark-dive-agent/src/main/java/shark/dive/agent/AgentCommandLine.kt

@@ -164,9 +164,11 @@ object AgentCommandLine {
   ): Int {
     val toApp = PrintWriter(OutputStreamWriter(socket.getOutputStream(), Charsets.UTF_8), true)
     val fromApp = BufferedReader(InputStreamReader(socket.getInputStream(), Charsets.UTF_8))
-    // The token, and then which session this call is one of: one line, because the alternative is a
-    // handshake that has to be answered before the protocol can start. See [AgentServer].
-    toApp.println("${run.token} $sessionName")
+    // The token, then which session this call is one of, then that it was typed rather than sent by a
+    // client: one line, because the alternative is a handshake that has to be answered before the protocol
+    // can start. Saying so here is the only chance there is — from the next line on this is indistinguishable
+    // from an MCP client, which is the point of it. See [AgentServer] and [AgentTransport].
+    toApp.println("${run.token} $sessionName ${AgentTransport.CLI.recorded}")
     if (fromApp.readLine() != AgentServer.ACCEPTED) {
       say("Shark Dive run ${run.pid} refused the token in ${run.file}, so it is not the run that wrote it")
       return NOTHING_ANSWERED