feat: record model thoughts

[dannykopping]

Required for coder/coder#22676
Closes #168

This PR adds recording of model "thoughts" (sometimes call "reasoning"). This is only available for /v1/messages and /v1/responses. We only track model thoughts in relation to tool use; all our thoughts are irrelevant in the same way that we don't store regular inference responses.

I've raised a PR downstack to allow parallel tool calls when there are no injected tools.

This leaves open the question of how we will associate model thoughts to these tools. Right now the two supported APIs do not "interleave" thoughts per tool use: all the thinking is done upfront which results in the multiple tool uses. Here are two examples:

/v1/messages

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":"The"}              }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":" user is asking me to get"}       }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":" stock prices for Apple and Google and compare"}           }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":" their"}               }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":" performance over the last week."}        }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":"\n\nLet me search"}    }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":" for both"}      }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":" stock prices in"}    }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":" parallel"} }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"thinking_delta","thinking":"."}       }

event: content_block_delta
data: {"type":"content_block_delta","index":0,"delta":{"type":"signature_delta","signature":"..."}      }

event: content_block_stop
data: {"type":"content_block_stop","index":0}

event: content_block_start
data: {"type":"content_block_start","index":1,"content_block":{"type":"tool_use","id":"toolu_01KLHTi1EnM4RxxG9VfFBwDt","name":"WebSearch","input":{},"caller":{"type":"direct"}}     }

...

event: content_block_start
data: {"type":"content_block_start","index":2,"content_block":{"type":"tool_use","id":"toolu_01T9we4nEzyv7WVoiazyK8VE","name":"WebSearch","input":{},"caller":{"type":"direct"}}          }

/v1/responses

{
    "type": "response.completed",
    "response": {
        ...
        "output": [
            {
                "id": "rs_0a139fe840c9c4640169b296e3eb088195886c12786026df1a",
                "type": "reasoning",
                "encrypted_content": "...",
                "summary": []
            },
            {
                "id": "msg_0a139fe840c9c4640169b296ebad1081958b3077bf7ae243ee",
                "type": "message",
                "status": "completed",
                "content": [
                    {
                        "type": "output_text",
                        "annotations": [],
                        "logprobs": [],
                        "text": "I’m reading both paths directly so I can return their contents or tell you if either one is missing or not a regular file."
                    }
                ],
                "phase": "commentary",
                "role": "assistant"
            },
            {
                "id": "fc_0a139fe840c9c4640169b296ed6ebc8195b5cc1641dac78918",
                "type": "function_call",
                "status": "completed",
                "arguments": "{\"cmd\":\"sed -n '1,250p' /tmp/foo\",\"yield_time_ms\":1000,\"max_output_tokens\":6000,\"workdir\":\"/home/coder/coder\"}",
                "call_id": "call_JmiKwclDrwqU1w2Ojk0E9wQB",
                "name": "exec_command"
            },
            {
                "id": "fc_0a139fe840c9c4640169b296ed6ecc819586447dbe18e23fff",
                "type": "function_call",
                "status": "completed",
                "arguments": "{\"cmd\":\"sed -n '1,250p' /home/bar\",\"yield_time_ms\":1000,\"max_output_tokens\":6000,\"workdir\":\"/home/coder/coder\"}",
                "call_id": "call_juUonJYUHxtCJb6ckr9tNTv5",
                "name": "exec_command"
            }
        ],
        "parallel_tool_calls": true,
        ...
    }
}

[dannykopping]

• feat: record model thoughts #203 👈 (View in Graphite)
• feat: only disable parallel tool calls when injectable tools are present #211
• main

This stack of pull requests is managed by Graphite. Learn more about stacking.

[pawbana]

How much space could ModelThoughts take?
Maybe we should consider configuring recording things not only due to compliance reasons but also to limit space usage.

[dannykopping]

It all depends on how many thinking tokens are given to the model, and even then we're only capturing a summary, so I suspect it won't be much. In any case, having this information will help provide insight into why agents take the course of action they do, which may end up being valuable for an audit scenario.

In any case, disk is cheap.

We can later add a flag to not store these conditionally.

[pawbana]

Maybe it is a bit out of scope but this is a bit confusing to me and it may be a good time for a small cleanup.

If I understand correctly clearing thoughtRecords should not matter right now as parallel tool calls are disabled but it is added just in case they are enabled in the future? Or it is just to make sure that same thoughts are not stored in 2 tool calls? In later case I think it would be better to have duplicated information in 2 calls then 1 call with none.

At the same time construction of thoughtRecords is not prepared for parallel case, it just concatenates all thinking blocks from Content. How about constructing thoughtRecords slice in this for loop and clearing it on each RecordToolUsage call?

I see later thoughtRecords are used in range pendingToolCalls loop but I think those calls should also be processed in this loop. Then it should be possible to aggregate thinking blocks per call properly (assuming thinking blocks are properly ordered with tool calls dividing them) and would make code a bit simpler. Maybe tool call processing could even be extracted to base struct.

[ssncferreira]

I think this is related to @pawbana comment, but just to clarify: IIUC we're storing all thinking records on the first tool call, and subsequent calls get none. Not sure how we're planning to present this in the UI, but all thinking would be associated with a single tool call, which might not be accurate.

Is the purpose of this mapping between tool calls and thinking to "understand why the model chose to use this tool"? If so, I like @pawbana suggestion of aggregating thinking blocks per call. Otherwise, I'm not sure this mapping of tool calls to thinking is the right approach 🤔

[dannykopping]

I've updated the description which should answer both of your questions 👍

[pawbana]

I think it would be better to merge this logic into getPendingInjectedToolCalls so it returns function call + thinking blocks related to that call.

[dannykopping]

I'd like to keep them separate so the different interceptors' implements look similar.
It's not just relevant for getPendingInjectedToolCalls in any case.

[pawbana]

Maybe I'm missing something but is there a reason thinking blocks are merged into RecordToolUsage and recorded only on tool call? (inner loop abstraction?)
I understand they are usually connected but I'd think there could be some reasoning without any tool call or provider could call tool directly.
Maybe thinking blocks should be part of RecordInterceptionEnded?

[ssncferreira]

nit: I would suggest keeping this fixture as it was, a simple fixture without any thinking blocks, and introducing this change as a new fixture. If a test using simple breaks, we'd want to know it's a basic request/response issue, not have to first rule out whether thinking blocks are involved.

[dannykopping]

I explicitly wanted to include thinking for the opposite reason: to make sure they don't interfere with existing tests.

Thinking is extraneous to the actual core functionality, so everything should still work as normal.

[ssncferreira]

I think this is related to @pawbana comment, but just to clarify: IIUC we're storing all thinking records on the first tool call, and subsequent calls get none. Not sure how we're planning to present this in the UI, but all thinking would be associated with a single tool call, which might not be accurate.

Is the purpose of this mapping between tool calls and thinking to "understand why the model chose to use this tool"? If so, I like @pawbana suggestion of aggregating thinking blocks per call. Otherwise, I'm not sure this mapping of tool calls to thinking is the right approach 🤔

[ssncferreira]

AFAIK, with streaming, the code waits until we get a stop block and processes all thinking blocks at that point, meaning they'll all have the same CreatedAt. I assume the ordering is still preserved by their position in the slice, so this probably doesn't matter, but worth noting that CreatedAt won't reflect when each block actually arrived. Could this be an issue?

[dannykopping]

This is actually true of tool usages as well which are recorded at this stage, as well.

Postgres is microsecond-precise, so some records may be persisted with the same timestamp.

The timestamp for thoughts doesn't really matter, though; as long as it's associated to a tool call it'll be displayed correctly (i.e. before the tool call).