Documentation
¶
Overview ¶
Package calllog is codeaf's always-on record of the model calls it makes.
It exists because of what debugging one used to cost. A headless run that sits on "still waiting" for fifteen minutes writes nothing anywhere that says which call is in flight, what shape it had, or how it ended, and the last three wire bugs — a thinking pass eating the answer ceiling on GLM 5.3, encrypted reasoning replayed to a model that did not produce it after a /model switch, a bare leaf that never filed its artifacts — were each found by standing a logging proxy in front of OpenRouter. A proxy is not something a person running codeaf on their own laptop can be asked to build, so the record is built in.
ONE LINE PER CALL, JSON Lines, appended under a mutex. The provider adapter writes it, because every outbound call in the process passes through that one door — the chat's turn, `codeaf do`, plan briefs and contracts, the delivery gate, reflexes, the document route.
WHAT IS NEVER IN IT: the prompts. A transcript is the person's own data and their own files, and a debug log that quietly accumulates it is a liability rather than a tool. The record carries the SHAPE of a request — how many messages, how many tools, which knobs, which ceiling — and the bodies only when someone deliberately asks for them with CODEAF_CALL_LOG_BODIES.
A WRITE FAILURE IS NEVER A FAILED CALL. Anything that goes wrong here — a read-only home, a full disk, a path that is a directory — silences the log for the rest of the process and prints one line naming the path it could not write. A model call that failed because its log could not be written would be the worst possible trade for a debugging convenience.
AND A ROW IS NEVER LOST OVER A VALUE. A number JSON has no spelling for — the wait controller's +Inf when it holds no alternative lane — is taken off the row and named in words on it rather than costing the row, because a row that vanishes is a call that reads as in flight forever (finite.go).
Index ¶
Constants ¶
const ( // EnvVar switches the log off or moves it. It is exported so the manual, // the settings footer and `codeaf logs` can all say the same word the code // reads. EnvVar = "CODEAF_CALL_LOG" // BodiesEnvVar adds the request and response bodies to every record. It is // a separate pin and not a value of EnvVar because the two answer different // questions — where the log goes, and how much of the person's own data it // is allowed to hold. BodiesEnvVar = "CODEAF_CALL_LOG_BODIES" // OffValue is what EnvVar is set to to write nothing at all. OffValue = "off" // DirName is the folder the log lives in, beside the quirks memo rather // than under it: both are things this process learned about its provider, // and "where does codeaf keep what it wrote down" has one answer. DirName = "logs" // FileName is the live log; PreviousFileName is the one predecessor kept // across a rotation. FileName = "calls.jsonl" PreviousFileName = "calls.1.jsonl" // MaxBytes is where the live file rotates when the bodies pin is off. // Thirty-two megabytes is a few hundred thousand shape-only records — // weeks of ordinary use, and still small enough that a person can grep // the whole thing — and the predecessor doubles the history without // letting the pair grow without bound. MaxBytes = 32 << 20 // BodiesMaxBytes is where the live file rotates when BodiesEnvVar is on. // A body-bearing record is tens to hundreds of kilobytes, and MaxBytes // then turns over after a few dozen calls — too soon for the session // that asked for the bodies. Two hundred and fifty-six megabytes is the // same figure the debug record keeps per run, and it is hours of a real // debug session rather than minutes, while still bounding the pair. BodiesMaxBytes = 256 << 20 )
const MaxErrorChars = 400
MaxErrorChars bounds Record.Error. It is a sentence beside a status code, not a report: the provider's own words fit, and an upstream that answered with a page does not get to own a line of the log.
const PhaseStart = "start"
PhaseStart is the value Record.Phase carries on the row written as a call goes out. There is deliberately no PhaseEnd: an end row omits the field, so the common case costs nothing and "no phase" has exactly one meaning.
Variables ¶
This section is empty.
Functions ¶
func Append ¶
func Append(record Record)
Append writes one record. It never returns an error and never blocks on anything but the mutex and the write itself: its callers are model calls, and nothing about a model call may depend on a disk.
func Bodies ¶
func Bodies() bool
Bodies reports whether this process was asked to record the request and response bodies as well as the shape of a call.
func CallsFor ¶
CallsFor is how many model calls one run has made. Zero for a run that has made none, and for a run this process never opened — which is the same answer, and the caller that publishes it is the one that knows whether the run is its own.
func ClipError ¶
ClipError is how a provider's message becomes a record's Error field. It is here rather than at the call site so that every writer clips the same way and a reader can trust what a trailing ellipsis means.
func Close ¶
func Close()
Close releases the file. It is called on the way out of a process that opened one; a process that forgets loses nothing, because every record is written and flushed as it happens.
func NewID ¶
func NewID() string
NewID mints the token that pairs one attempt's two rows. Four bytes is eight hex characters — enough that two live calls in one file will not collide, and short enough to sit on a line a person is reading.
func Open ¶
func Open(dir string)
Open points the log at a profile directory and is called once at startup, beside the quirks memo it lives next to. It opens nothing: the file is opened by the first record, so a process that makes no model call leaves no file and no empty logs directory behind.
func Path ¶
func Path() string
Path is where records are going, or "" when the log is off. It is what `codeaf logs --path` and `codeaf doctor` read.
func PathFor ¶
PathFor names the log for one profile directory, and returns "" when the log is switched off.
It resolves exactly the way the quirks memo beside it does — the profile directory when there is one, the state root otherwise — with the environment pin on top, so a person debugging one run can put its log somewhere they can watch without moving anything else codeaf owns.
UNDER `go test` it answers "" for anything that would land inside the state root the environment named, so that a test binary cannot write into the ledger of the person who started it (undertest.go says why, and what a test that wants a log does instead).
Types ¶
type LastCall ¶
LastCall is the newest call this process has heard back from: the model that answered and the moment it did. It is the in-memory half of the log, kept whether or not the file is being written.
type Record ¶
type Record struct {
// Time is when this row was written, RFC3339 with milliseconds: the moment
// an attempt went out on a start row, the moment it came back on an end row.
Time string `json:"ts"`
// ID pairs the two rows one attempt writes. It is short and random rather
// than a counter because several agents in one process append to one file,
// and a counter would need a lock that says nothing a random token does not.
ID string `json:"id,omitempty"`
// Run is the invocation this call belongs to — the id internal/trace mints
// at every door, and the same id that names the debug record's folder.
//
// IT IS WHAT MAKES THIS FILE JOINABLE. A developer who wanted the call
// count and the round count of one `codeaf do` came here to reconstruct
// them, and found rows carrying a tag, a node and a timestamp and nothing
// at all naming the run — so attribution was by clock alone, in a file
// several runs on one machine append to. The run id is on the row and in
// the `--json` envelope the same run printed, and the two are joined by
// looking at them.
//
// It is on BOTH rows of a pair rather than only the start: the end row is
// the one that carries the cost and the finish reason, and a reader
// filtering the file to one run must not have to pair every row first to
// keep the halves that matter.
Run string `json:"run,omitempty"`
// Phase is "start" on the row written the moment a call goes out, and
// ABSENT on the row written when it comes back. One word rather than two,
// because the pair is what a reader is looking for: a start with no end
// beside it is a call that is still in flight, and that is exactly the state
// that used to be invisible — a planning call four minutes into a
// 65,536-token ceiling looked identical to an idle process.
Phase string `json:"phase,omitempty"`
// Tag is what the call was for — "turn", "leaf", "compile", "brief" — set
// by whoever made it (provider.WithCallTag). Empty for a call this lane did
// not locate, which is honest: an untagged row is still a row.
Tag string `json:"tag,omitempty"`
// Node is the work the call belongs to, where the caller knows one: a plan
// node's key or a task's id.
Node string `json:"node,omitempty"`
// Model is what was asked for; Served is who the router says answered,
// which is the difference between "GLM is slow" and "one endpoint serving
// GLM is slow".
Model string `json:"model,omitempty"`
Served string `json:"served,omitempty"`
// Effort is the reasoning word or budget that actually travelled, in the
// shape the wire carried it: a word, "NNN tokens" for a budget, or "off"
// when the request asked for no thinking pass at all. It is what was SENT
// and not what the caller wanted, because the two differ on every model
// whose endpoint refuses a disable.
Effort string `json:"effort,omitempty"`
// EffortPin is the client's pinned reasoning word when this call carried
// something else. Empty means there was no pin or the pin itself travelled,
// so an ordinary row gains no placeholder under the emptiness law.
EffortPin string `json:"effort_pin,omitempty"`
// MaxTokens is the ceiling that TRAVELLED — the caller's answer plus the
// room the thinking pass in front of it is allocated (the provider's
// ceilingFor) — and not the figure the caller started from. The gap between
// the two is exactly the bug a thinking pass eating an answer produces.
MaxTokens int `json:"max_tokens,omitempty"`
// Messages and Tools are the request's shape. Counts and not content: see
// the package comment on why the transcript is not in here.
Messages int `json:"messages,omitempty"`
Tools int `json:"tools,omitempty"`
Stream bool `json:"stream,omitempty"`
// Attempt is 1-based over the transport's retry loop, so a call that was
// paced four times leaves four rows that can be told apart.
Attempt int `json:"attempt,omitempty"`
// Relaxed is which rungs of the endpoint-refusal ladder this body had
// already climbed — "reasoning", "max_tokens", "tools" — so a degraded
// request is never mistaken for the one the caller wrote.
Relaxed []string `json:"relaxed,omitempty"`
Status int `json:"status,omitempty"`
Millis int64 `json:"ms,omitempty"`
Finish string `json:"finish,omitempty"`
// Ended is on the row NOBODY ON THE PATH WROTE.
//
// EVERY START ROW GETS A ROW UNDER IT. That is the law this field exists to
// keep, and it was not kept: 527 of 16,921 attempts over the ten days to
// 2026-09-10 had a start row and nothing beside it, which every reader of
// this file — a person, `codeaf logs`, the census — reads as a call that is
// still in flight. Six of them were one turn on a model the catalog holds no
// endpoints for, where the ladder ran out and returned without writing
// anything.
//
// So the transport closes whatever it left open, and this word says who
// closed it and why: "hopped" when another attempt began before this one's
// row was written, "cancelled" and "deadline" when the caller's own context
// ended the call, and "abandoned" when the call simply returned and nothing
// wrote the row. It is ABSENT on every row a path wrote for itself, which is
// almost all of them.
Ended string `json:"ended,omitempty"`
// TTFTms is the wait before the first token, in milliseconds, on a streamed
// call. It is absent on a call that was not streamed — where the first
// token and the last arrive together and no endpoint's queue is separable
// from its writing — and absent is honest there rather than instant.
TTFTms int64 `json:"ttft_ms,omitempty"`
// HazardCeilingMs is when the watch was going to start thinking about a
// second request, derived at send time from the belief about the lane
// expected to serve rather than from any constant. It is on the row because
// a hedge that fired is only half a story: the rows where the ceiling was
// set and NOT reached are what say it was set in the right place.
//
// IT WAS CALLED `deadline_ms` UNTIL 2026-09-10 AND IT WAS NEVER A DEADLINE.
// Nothing ends a call when it passes; it is the moment the wait controller
// starts pricing a rescue. Under the old name the census read it as the
// bound that applied to the attempt and found the field "fiction" — 7,937
// rows saying 10,000 beside an `ms` that ran to 937,777, and 2,720 finishes
// apparently running past twice their own deadline. Every one of those was
// a healthy call outliving a hazard ceiling, which is the ordinary case. The
// figure was right and the NAME was the lie, so the name moved
// (docs/design/recovery/DESIGN.md §7, wave R0).
HazardCeilingMs int64 `json:"hazard_ceiling_ms,omitempty"`
// AppliedMs is THE BOUND THAT ACTUALLY ENDED THIS ATTEMPT and AppliedWord is
// what to call it. HazardCeilingMs above says what was PLANNED; these two say
// what HAPPENED, and the row may honestly carry both.
//
// They are the other half of the `deadline_ms` repair. Separating them is
// what lets a reader ask the only question that matters about a cut call —
// which bound cut it — instead of inferring one from a ceiling that never
// cut anything. Six hundred rows in the 2026-09-10 census were cut by a
// bound set OUTSIDE the provider package and were read as the stream wall
// cutting live streams, which the wall never did.
//
// BOTH ARE ABSENT ON EVERY ATTEMPT NO BOUND OF OURS ENDED — an answer, a
// refusal, the caller leaving — because absent is the honest reading of
// "nothing here cut this". The guard fills them in when one of its bounds
// fires (internal/provider, wave R4).
AppliedMs int64 `json:"applied_ms,omitempty"`
AppliedWord string `json:"applied,omitempty"`
// Exhaust marks the row of an arm that was cancelled because another arm of
// the same hedge answered first.
//
// IT IS THE DIFFERENCE BETWEEN EXHAUST AND FAILURE, and no reading of this
// file could tell them apart before it existed. A losing arm's request
// really was made and really was cut off, so its row says `context
// canceled` like any abandoned call: 1,204 of 3,906 bad rows in the
// 2026-09-10 census, the single largest cause family in it, and not one of
// them is a thing that went wrong. They are the price of a race this build
// chose to run and WON. A census that counts them as failures is measuring
// its own hedging policy and calling it provider health.
Exhaust bool `json:"exhaust,omitempty"`
// Lane is the machine the preference named — the first entry of the
// `provider.order` this request carried, or the pin it carried instead.
// Empty for a call to an endpoint that is not a router, and for one sent
// with no preference at all.
Lane string `json:"lane,omitempty"`
// Hedged marks the row of a call that was rescued by a second request to
// another lane. Both halves of the pair leave their own rows; this is what
// says they were a pair.
Hedged bool `json:"hedged,omitempty"`
// RetryAfterS is the comeback instruction a refusal carried, in seconds —
// the `Retry-After` header, or the wait the router named in its own body.
//
// IT IS THE ONE NUMBER THAT MAKES A SAME-MACHINE RETRY LEGAL. The rule the
// recovery design states is that the same bytes go back to the same machine
// only when there is nowhere else to send them and then only for as long as
// that machine itself asked — so a log that never recorded what was asked
// for could not say whether a single one of eleven hundred paced retries
// obeyed it. Over the ten days to 2026-09-10 the field was never present on
// any row, because nothing wrote it.
RetryAfterS float64 `json:"retry_after,omitempty"`
// ConnReused is whether this attempt rode a connection the pool already
// had. It is the single most useful field of the four, and it is spelled
// as a bool rather than inferred from a zero handshake because "the pool
// was warm" and "nothing was measured" are different facts.
//
// FALSE IS WRITTEN OUT. The emptiness law leaves an unknown blank, and a
// cold connection is not unknown — it is the finding. So the row carries
// `conn_reused:false` where a fresh connection was opened, and carries the
// field not at all where no trace was taken (a probe, a document post).
ConnReused *bool `json:"conn_reused,omitempty"`
// DNSms, ConnectMs and TLSms are the three parts of opening one, in
// milliseconds, and every one of them is absent on a reused connection
// because none of them happened.
DNSms int64 `json:"dns_ms,omitempty"`
ConnectMs int64 `json:"connect_ms,omitempty"`
TLSms int64 `json:"tls_ms,omitempty"`
// SilenceMs is how long the stream had been silent — nothing visible, and
// for a first token nothing at all — at the moment something was done about
// it.
SilenceMs int64 `json:"silence_ms,omitempty"`
// Action is what was done: "hedge", "ask", "report", "escalate" or
// "commit", in the controller's own words. Absent on a call that was never
// acted on.
Action string `json:"action,omitempty"`
// Reason is the controller's own machine word for what it decided on. It is
// absent when nothing was acted on.
Reason string `json:"reason,omitempty"`
// Refused is why a hedge the controller called for never reached the wire:
// "plan cannot pay", "no alt" or "no room". It is absent when nothing was
// refused.
//
// IT USED TO SAY `budget` AND THAT NAMED THE WRONG THING. The rail was a
// rolling process-wide allowance until 2026-09-11 — two rescues in any twenty
// requests — so the word said "some other request spent this one's rescue",
// which is a fact about arrival order and not about this call. What may
// refuse now is the call's own budget (internal/lane/control's
// Plan.SpendUSD), and the word names it.
Refused string `json:"refused,omitempty"`
// Arms is how many requests this one question put on the wire, counting the
// original. One is the ordinary case and is left off the row.
Arms int `json:"arms,omitempty"`
// WasteUSD is what the arms that did not answer cost, by the router's own
// figure where one arrived and by the frontier's estimate where the arm was
// cancelled before its usage frame.
WasteUSD float64 `json:"waste_usd,omitempty"`
// WaitS and CostS are the two numbers the decision was actually made on:
// the expected remaining wait, and what acting was expected to cost, both
// in seconds at the moment of the act. A row that recorded the action
// without them could only ever confirm what somebody already suspected.
WaitS float64 `json:"wait_s,omitempty"`
CostS float64 `json:"cost_s,omitempty"`
// Note is one sentence, in words, about something this call decided that no
// other field can say — "pinned lane coreweave was silent for 10s —
// borrowing auto for this answer". It is empty on almost every row, and it
// is where a decision taken with nobody watching leaves its account.
Note string `json:"note,omitempty"`
PromptTokens int `json:"prompt_tokens,omitempty"`
CompletionTokens int `json:"completion_tokens,omitempty"`
ReasoningTokens int `json:"reasoning_tokens,omitempty"`
CachedTokens int `json:"cached_tokens,omitempty"`
Cost float64 `json:"cost,omitempty"`
// Error is the provider's own sentence, clipped. Clipped rather than whole
// because a provider that answers with a stack trace or an HTML error page
// would otherwise put a screenful into every line of the log.
Error string `json:"error,omitempty"`
// Learned is the quirk this answer taught the adapter, by the memo's own
// names: reasoning_mandatory, reasoning_disable_ignored,
// cache_control_refused, reasoning_budget_refused, reasoning_replay_refused.
// It is a list because one 400 can name more than one refused field.
Learned []string `json:"learned,omitempty"`
// EmptyAtCeiling is the thinking-ate-the-answer signature: no text, a
// "length" finish, and the whole ceiling spent.
EmptyAtCeiling bool `json:"empty_at_ceiling,omitempty"`
// RequestBody and ResponseBody are present ONLY under BodiesEnvVar. They
// are whole and unclipped, because the reason to turn them on is that
// something in the exact bytes is what is wrong.
RequestBody string `json:"request_body,omitempty"`
ResponseBody string `json:"response_body,omitempty"`
}
Record is one model call as it happened: what was asked, what came back, and what the answer taught. Every field is omitempty, because the emptiness law applies to files as much as to screens — a record of a call that never reached an endpoint says nothing about tokens, and a zero in that place would be a figure somebody could read as a measurement.
Source Files