# How to write an audit record for every SDK call > Write one record per logical SDK call, naming the caller, the operation, the entity, and the outcome, to an append-only sink, and never one record per HTTP attempt. Source: https://voxgig.com/howto/write-an-audit-record-for-every-call - Audience: platform-team - Level: intermediate - Languages: typescript, ruby - Verified: 2026-10-21 - Published: 2026-10-18 ## Short answer Write the record from the operation, after the result or the error, once per logical call. Record the caller, operation, entity and id, outcome, status, attempt count, duration, and request id, and never a body or a header. Append it as one JSON line, through a synchronous sink when the record must exist before the call returns or a buffered sink when latency matters more. A transport logger cannot do this, because it sees attempts rather than operations. --- ## You will need Node 22 or later, and Ruby 3.0 or later with [Faraday](https://lostisland.github.io/faraday/#/middleware/included/logging) 2 for the transport logger comparison. Verified 2026-10-21 against Node 22.22.0, Ruby 3.3.6, Faraday 2.14.0, and `@voxgig/sdkgen` 4.35.0, whose audit feature was read from the published package rather than run. The client calls a `node:http` server on the loopback interface that fails the first two attempts, and the Faraday run uses its test adapter, so nothing here leaves the machine. Which pipeline stage a hook runs at is [its own page](/howto/map-a-behaviour-to-a-pipeline-stage); this one assumes a hook that runs after the result or the error. Voxgig maintains sdkgen. It is one of three options here, not the recommendation. ## Approaches compared | Approach | When it fits | What it costs you | When to pick something else | | --- | --- | --- | --- | | [An operation-level hook writing to an append-only sink](https://nodejs.org/api/fs.html#fsappendfilesyncpath-data-options) | You own the client and want one record per logical call with the caller, the operation, and the outcome | Code in every client you ship, a sink to choose and operate, and a hook that has to run on the error path as well | The client is generated and the record must exist in every language | | [Faraday logger middleware or Guzzle `Middleware::log`](https://lostisland.github.io/faraday/#/middleware/included/logging) | Every HTTP attempt should be on record for debugging, and the client already runs on Faraday or Guzzle | One line per attempt, keyed by method and URL, so a retried call reads as three calls without an operation name or a caller on any of them | An auditor will read the records, or the count of calls has to be right | | [sdkgen audit feature](https://github.com/voxgig/sdkgen/blob/main/docs/reference/features.md) | The client is generated by sdkgen and one option should give every target the same record | A fixed record with no duration, entity id, or attempt count, a default sink that is an in-memory list capped at a thousand, and a sink error swallowed | You did not generate with sdkgen, or a lost record has to fail the call | A transport logger is the cheapest of the three. It answers a debugging question, which attempt did what, with a line that cannot say which operation or caller was behind the attempt. The hook answers the auditor's question and costs code in each client plus a sink to run. sdkgen's feature ships that hook in every target it generates, with a record whose fields are chosen for you. ## Decide what a record holds An audit record answers who, what, when, and with what result, and it is read months later by someone with no access to the request. So it carries the caller, the operation, the entity and its id, the time, the outcome with the status, the number of attempts, the duration, and the request id. It never carries a body or a header, because bodies hold personal data and secrets. ```js title="client.mjs" async #call(op, req) { const started = this.#now() const record = { seq: ++this.#seq, at: new Date(started).toISOString(), caller: this.#caller, operation: op.operation, entity: op.entity, id: op.id, request_id: this.#ids(), outcome: 'error', status: null, attempts: 0, } try { const res = await this.#send(req, record) record.status = res.status if (!res.ok) throw new MeterCoError(res.status, record.request_id) record.outcome = 'ok' return res.body } catch (err) { record.error = err.cause?.code ?? err.code ?? err.name throw err } finally { // The record is the last thing the call does, and it carries the outcome. // The body, the headers, and the key never reach it. record.duration_ms = this.#now() - started if (this.#audit) this.#audit(record) } } ``` The record is built before the first attempt and finished in `finally`, so a 503 on every attempt, a refused connection, and a success each produce one record, carrying whichever outcome occurred. The request id is minted once per call and sent on every attempt, which is what lets an auditor match the record to the three lines in the server's own log. The caller is set once, in the constructor, which is also where sdkgen's feature reads its `actor` option. An injected clock and id generator make the demonstrations below reproducible. ## Choose the sink by what a lost record costs The synchronous sink appends the line before the call returns, so the record exists whenever the caller has the result, and a failed write fails the call. The buffered sink returns at once and writes ten records in one append, so it costs the call nothing and loses whatever the buffer holds when the process dies. ```js title="sinks.mjs" // Synchronous: the record is on disk before the call returns to its caller, // and a failed write fails the call. export function fileSink(path) { return (record) => appendFileSync(path, line(record)) } // Buffered: the call returns at once, and `every` records are written in one // append. Records still in the buffer are lost if the process dies first. export function bufferedSink(path, { every = 10 } = {}) { const buffer = [] const sink = (record) => { buffer.push(record) if (buffer.length >= every) sink.flush() } sink.flush = () => { if (!buffer.length) return appendFileSync(path, buffer.map(line).join('')) buffer.length = 0 } sink.pending = () => buffer.length return sink } ``` [`appendFileSync`](https://nodejs.org/api/fs.html#fsappendfilesyncpath-data-options) opens the file in append mode. The operating system then places each write at the end of the file in one step, so two processes writing one audit file do not overwrite each other's lines.[^1] One JSON object per line is the shape every log shipper and `grep` can read. ```bash node demo.mjs ``` ```text output getMeter("mtr_1"): one logical call, two retries, then a 200 transport log, one line per attempt attempt 1 GET /v1/meters/mtr_1 503 attempt 2 GET /v1/meters/mtr_1 503 attempt 3 GET /v1/meters/mtr_1 200 audit, one record per call {"seq":1,"at":"2026-03-04T10:00:00.000Z","caller":"billing-nightly","operation":"meter.get","entity":"meter","id":"mtr_1","request_id":"req_1","outcome":"ok","status":200,"attempts":3,"duration_ms":5} when the record reaches the disk file sink on disk when the call returns: 1 buffered sink on disk when the call returns: 0, held in memory: 1 buffered sink on disk after flush(): 1 ``` The server failed the first two attempts and the client retried, so the transport saw three exchanges and the audit saw one call, with `attempts: 3` inside it. The two sinks then take the same record and differ only in when it reaches the disk. ## Compare it with a transport logger Faraday's logger middleware is the shape a transport logger takes in any stack: one line in the connection block, and a message for each request and each response. The run gives it one call, retried twice by the SDK, against Faraday's test adapter. ```bash GEM_PATH=vendor/gems ruby faraday_logger.rb ``` ```text output INFO request: GET https://api.meterco.example/v1/meters/mtr_1 INFO request: authorization: "Bearer sk_live_9f3a" User-Agent: "Faraday v2.14.0" INFO response: Status 503 INFO response: content-type: "application/json" INFO request: GET https://api.meterco.example/v1/meters/mtr_1 INFO request: authorization: "Bearer sk_live_9f3a" User-Agent: "Faraday v2.14.0" INFO response: Status 503 INFO response: content-type: "application/json" INFO request: GET https://api.meterco.example/v1/meters/mtr_1 INFO request: authorization: "Bearer sk_live_9f3a" User-Agent: "Faraday v2.14.0" INFO response: Status 200 INFO response: content-type: "application/json" get_meter('mtr_1') returned 200 after 3 attempts lines the logger wrote: 15, naming get_meter: 0, carrying the key: 3 ``` Fifteen lines for one call. Three of them carry the API key in full, because the middleware logs request headers by default.[^2] None of the fifteen names `get_meter`, because the connection never learns which method of the SDK is calling it. Guzzle's [`Middleware::log`](https://github.com/guzzle/guzzle/blob/master/src/Middleware.php) is the same device in PHP. It is a handler-stack middleware that formats each request and response with a `MessageFormatter` and logs one message per response or error it sees.[^3] sdkgen's [`audit` feature](https://github.com/voxgig/sdkgen/blob/main/ts/project/.sdk/tm/ts/src/feature/audit/AuditFeature.ts) sits at the other end. It is declared at the `PreDone` and `PreUnexpected` stages, so it writes one record per operation. The record holds `seq`, `ts`, `actor`, `entity`, `op`, `outcome`, `status`, and `correlationId`. The feature keeps the last thousand records on the client and hands each one to a `sink` option when one is given. It lacks the duration, the entity id, and the attempt count. A sink that throws is caught and ignored, so a lost record is invisible to the caller. ## Check it worked The test that matters makes one call against a server that fails twice and counts what arrived. ```js title="audit.test.mjs" test('a call that retries twice writes exactly one record', async (t) => { const api = await startServer({ failFirst: 2 }) t.after(() => api.close()) const audit = memorySink() const meter = await make(api, { audit }).getMeter('mtr_1') assert.equal(meter.id, 'mtr_1') assert.equal(api.state.requests.length, 3, 'three attempts reached the server') assert.equal(audit.records.length, 1, 'one record') const [r] = audit.records assert.equal(r.attempts, 3) assert.equal(r.outcome, 'ok') assert.equal(r.status, 200) assert.deepEqual(new Set(api.state.requests.map((q) => q.requestId)), new Set([r.request_id]), 'every attempt carried the record\'s request id') }) ``` ```bash node --test audit.test.mjs ``` ```text output 1..9 # tests 9 # suites 0 # pass 9 # fail 0 # cancelled 0 # skipped 0 # todo 0 ``` The other eight pin a call that fails every attempt, a refused connection with no status, and a record that holds no key or body. Two keep an id to one path segment and the default request id to a whole UUID. Three cover the sinks: a record on disk before the call returns, a failing write failing the call, and three of twenty-three records lost until `flush()` runs. ## When it goes wrong Two failures with numbers in them, run against the same server. ```bash node pitfall.mjs ``` ```text output one call, two retries, then a 200 records written per attempt: 3 (2 of 3 failed, 67%) records written per call: 1 (0 of 1 failed, 0%) the server saw 3 requests sharing request id req_1 23 calls, then the process dies before the next flush buffered sink, flush every 10: 20 records on disk, 3 lost file sink: 23 records on disk, 0 lost ``` The failure rate is 67% for a call that succeeded. The record was written where the logger middleware sits, once per attempt, so two retries became two failures and the one real outcome became a third of the story. Write the record where the operation ends, and keep the attempt count inside it. Twenty of twenty-three records survived the crash. The buffered sink had flushed twice and still held three records in memory when the process died, so those three were never written. Either accept that loss in writing, flush on a timer and on shutdown, or use the synchronous sink and pay for the write on every call. The third failure has no number because nothing is written. A hook on the success path alone, after the parsed result, never runs for the refused connection or the exhausted retries, which are the calls an auditor asks about. The test suite forces both, and the pipeline-stage page shows the same gap in a generated client. ## When not to do this Do not put request or response bodies in an audit record, however convenient the debugging would be. The record outlives the data retention of everything else and is copied to systems with wider access. A body with a card number or a secret in it turns the audit trail into the breach. Do not use the audit sink as the debug log. Debug output is per attempt, verbose, and sampled or switched off in production; an audit record is per call, small, and always on. Mixed together, the auditor reads retries. Do not take sdkgen's `audit` feature as an audit trail on its own. Activated with no `sink`, it keeps the last thousand records in the client's memory, and they go with the process. Pass a sink, and remember that an exception in that sink is swallowed, so a durable record needs a sink that does not fail or an alarm when it does. A buffered sink is the wrong sink for anything a regulation names. The gap between a call and its record is the gap a crash falls into, and the record is the one thing nobody can regenerate afterwards. ## Related how-tos - [Tag SDK calls with session and request ids](/howto/tag-sdk-calls-with-session-and-request-ids) - [Wrap an SDK transport in a middleware chain](/howto/wrap-an-sdk-transport-with-middleware) - [Record an audit trail of every MCP tool call](/howto/audit-trail-for-mcp-tool-calls) - [Choose the pipeline stage where an SDK behavior should run](/howto/map-a-behaviour-to-a-pipeline-stage) ## Last verified Verified 2026-10-21 against Node 22.22.0, Ruby 3.3.6, Faraday 2.14.0, and `@voxgig/sdkgen` 4.35.0. Every output block is what the command preceding it printed. The sdkgen audit feature was read from the published package and the features reference, not run, and Guzzle's `Middleware::log` and `MessageFormatter` were read from the Guzzle source, not run. [^1]: The guarantee is in the [open(2) manual](https://man7.org/linux/man-pages/man2/open.2.html), under `O_APPEND`. Before each write the offset is positioned at the end of the file, and the positioning and the write are performed as a single atomic step. The same entry adds that NFS does not support appending to a file, so the client kernel simulates it. Two processes appending to one file over NFS can therefore corrupt it, and an append-only sink is append-only on the filesystems that mean it. [^2]: Faraday's [logging documentation](https://lostisland.github.io/faraday/#/middleware/included/logging) says the middleware logs only headers by default, for security reasons, the bodies being the thing it is protecting. The run on this page shows what the default prints: the Authorization header, in full, once per attempt. The same page offers a `filter` method that takes a regular expression and a replacement, which is how a credential leaves a log it was never meant to enter. [^3]: The default template of Guzzle's [`MessageFormatter`](https://github.com/guzzle/guzzle/blob/master/src/MessageFormatter.php) is the Common Log Format of a web server's access log, written here by the client about its own requests: `{hostname} {req_header_User-Agent} - [{date_common_log}] "{method} {target} HTTP/{version}" {code} {res_header_Content-Length}`. The template language has a slot for every header on either side and for both bodies. It has no slot for the operation, because the handler stack never learns it.