| 1 | # Observability |
| 2 | |
| 3 | > For maintainers. Using T3 Code? See [docs/user](../user/). |
| 4 | |
| 5 | T3 Code has one server-side observability model: |
| 6 | |
| 7 | - pretty logs go to stdout for humans |
| 8 | - completed spans go to a local NDJSON trace file |
| 9 | - traces, metrics, and logs can also be exported over OTLP to a real backend like Grafana LGTM |
| 10 | |
| 11 | The local trace file is the persisted source of truth for normal local launches. Those launches do not |
| 12 | write a separate server log file, but SSH-managed launches also persist the remote process's |
| 13 | stdout/stderr at `~/.t3/ssh-launch/<state>/server.log`. |
| 14 | |
| 15 | ## Where To Find Things |
| 16 | |
| 17 | ### Logs |
| 18 | |
| 19 | Logs are human-facing: |
| 20 | |
| 21 | - destination: stdout |
| 22 | - format: `Logger.consolePretty()` |
| 23 | - normal local persistence: none |
| 24 | - SSH-managed launch persistence: `~/.t3/ssh-launch/<state>/server.log` |
| 25 | - remote export: OTLP only, when configured |
| 26 | |
| 27 | If you want a log message to show up in the trace file, emit it inside an active span with `Effect.log...`. `Logger.tracerLogger` will attach it as a span event. |
| 28 | |
| 29 | Configuring a logs endpoint takes over that job. The server then exports log records, which cover |
| 30 | every message instead of only the ones inside an active span and carry the trace and span ids so |
| 31 | they still line up with the trace. `Logger.tracerLogger` is dropped in that mode, so the same |
| 32 | message is not exported twice and the trace file stops carrying log messages. stdout output and |
| 33 | SSH-managed launch persistence stay unchanged either way. |
| 34 | |
| 35 | ### Traces |
| 36 | |
| 37 | Completed spans are written as NDJSON records to `serverTracePath`. The default depends on how the |
| 38 | server starts: production and explicitly configured homes use |
| 39 | `<home>/userdata/logs/server.trace.ndjson` (so `~/.t3/userdata/...` by default, or |
| 40 | `/custom/path/userdata/...` with `--home-dir /custom/path`), a linked worktree dev run uses |
| 41 | `<worktree>/.t3/userdata/logs/server.trace.ndjson`, and an implicit dev run outside a linked |
| 42 | worktree uses `~/.t3/dev/logs/server.trace.ndjson`. |
| 43 | |
| 44 | Important fields common to both record types: |
| 45 | |
| 46 | - `type`: `effect-span` or `otlp-span` |
| 47 | - `name`: span name |
| 48 | - `traceId`, `spanId`, `parentSpanId`: correlation |
| 49 | - `durationMs`: elapsed time |
| 50 | - `attributes`: structured context |
| 51 | - `events`: embedded logs and custom events |
| 52 | |
| 53 | `effect-span` records also contain `exit` with `Success`, `Failure`, or `Interrupted`. `otlp-span` |
| 54 | records instead carry OTLP resource, scope, and optional status fields. |
| 55 | |
| 56 | The `TraceRecord`, `EffectTraceRecord`, and `OtlpTraceRecord` schemas live in |
| 57 | `packages/shared/src/observability.ts`. |
| 58 | |
| 59 | SQL statement spans (named `sqlite`) and `sql.transaction` spans carry `db.connection` and |
| 60 | `db.lock_wait_ms`. `db.connection` is `writer` for the main connection, which runs on the event loop, |
| 61 | or `reader` for the read-only connection in a worker thread. `db.lock_wait_ms` is the part of the |
| 62 | span spent waiting for that connection, behind other SQL. That wait does not block the event loop, |
| 63 | so subtract it before you blame a slow span on the query. Statements inside a transaction use its |
| 64 | connection and do not carry these attributes. |
| 65 | |
| 66 | DPoP proof failures include the safe `environment.dpop.failure_code` span |
| 67 | attribute. A `time_window` failure means that a signed proof was too old or too |
| 68 | far in the future for the environment server's allowed window. It can point to |
| 69 | a date or time problem on either device, but it can also result from a delayed |
| 70 | request. |
| 71 | |
| 72 | #### Summarize the trace file |
| 73 | |
| 74 | `t3 trace summary` reads the trace file and its rotated backups directly, so it works while the |
| 75 | server is stalled or stopped. It prints counts, rates, and latency percentiles per span name. Use |
| 76 | it to measure background work or to compare two builds. |
| 77 | |
| 78 | ```bash |
| 79 | t3 trace summary --since 30m --limit 40 |
| 80 | ``` |
| 81 | |
| 82 | It reads `T3CODE_TRACE_FILE` if set, else `<home>/userdata/logs/server.trace.ndjson` for |
| 83 | `--base-dir` or `T3CODE_HOME`, plus the `T3CODE_TRACE_MAX_FILES` rotated backups. For a dev run or |
| 84 | a copied file, set `T3CODE_TRACE_FILE`. `--since 30m` keeps spans that ended in the last 30 |
| 85 | minutes. The rate is per minute between the first and last span end. |
| 86 | |
| 87 | ### Metrics |
| 88 | |
| 89 | Metrics are not written to a local file. |
| 90 | |
| 91 | - local persistence: none |
| 92 | - remote export: OTLP only, when configured |
| 93 | - current definitions: `apps/server/src/observability/Metrics.ts` |
| 94 | |
| 95 | If OTLP is not configured, metrics still exist in-process, but you will not have a local artifact to inspect. |
| 96 | |
| 97 | ### Event Loop Stalls |
| 98 | |
| 99 | `apps/server/src/observability/EventLoopMonitor.ts` samples the server's event loop every 30 s. When |
| 100 | the loop stalled for more than 2 s since the previous sample, it records a root |
| 101 | `server.eventLoop.stall` span with a warning. The span has trace level `Warn`, so it stays when |
| 102 | `T3CODE_TRACE_MIN_LEVEL` is `Warn`. The warning shows in Settings > Diagnostics unless OTLP logs are |
| 103 | on. The span time is when the sample ran, not when the stall happened. |
| 104 | |
| 105 | The trace file rotates in well under an hour on a busy server, so each stall is also appended as one |
| 106 | NDJSON line to `event-loop-stalls.ndjson`, next to the trace file. A line has `time` and the span |
| 107 | attributes. The file keeps the last 1000 or more stalls, with one rotated backup |
| 108 | (`event-loop-stalls.ndjson.1`). Use it to see how often a server stalls over days. |
| 109 | |
| 110 | Some delay is not recorded: |
| 111 | |
| 112 | - `delayMaxMs` is the longest stall, and can undercount it by up to 1 s. The 2 s threshold applies to |
| 113 | this value, so a stall over 3 s is normally recorded, and a shorter one can be missed. A stall |
| 114 | that ends just as a sample runs can be missed too. |
| 115 | - Time the computer spends asleep reads as delay on macOS and Windows. So a sample only counts when |
| 116 | the loop was busy, not waiting for events, for at least `delayMaxMs`. Busy time covers the whole |
| 117 | window, so a short sleep in an otherwise busy window can still record a false stall. The span then |
| 118 | shows CPU time far below `delayMaxMs`. |
| 119 | - The first sample after launch is skipped. Startup work such as migrations and projection bootstrap |
| 120 | can block the loop for seconds on a large database. |
| 121 | |
| 122 | CPU times and page faults cover the whole process over the whole window since the previous sample. |
| 123 | The window is nominally 30 s, but a long stall delays the sample and makes the window longer. Other |
| 124 | work in the window can hide a wait, so only CPU time far below `delayMaxMs` proves the thread was |
| 125 | waiting. Read CPU together with page faults: |
| 126 | |
| 127 | - High `cpuSystemMs` with many page faults means memory pressure. Major faults are reads from disk or swap. |
| 128 | On macOS, reads from compressed memory are minor faults plus system CPU. |
| 129 | - High `cpuUserMs` with few page faults means JavaScript work or garbage collection. |
| 130 | - Low CPU with few major page faults points at synchronous disk I/O, such as SQLite reads or trace |
| 131 | file writes. |
| 132 | - Many `involuntaryContextSwitches` mean other processes were competing for the CPU. |
| 133 | |
| 134 | ### Related Artifacts |
| 135 | |
| 136 | Provider event NDJSON files still exist for provider runtime streams. Those are separate from the main server trace file. |
| 137 | |
| 138 | ## Run The Server In Instrumented Mode |
| 139 | |
| 140 | There are two useful modes: |
| 141 | |
| 142 | - local-only: stdout + local `server.trace.ndjson` |
| 143 | - full local observability: stdout + local trace file + OTLP export to Grafana/Tempo/Prometheus |
| 144 | |
| 145 | The local trace file is always on. OTLP export is opt-in. |
| 146 | |
| 147 | ### Option 1: Local Traces Only |
| 148 | |
| 149 | You do not need any extra env vars. Just run the app normally and inspect `server.trace.ndjson`. |
| 150 | |
| 151 | Examples: |
| 152 | |
| 153 | ```bash |
| 154 | npx t3 |
| 155 | ``` |
| 156 | |
| 157 | ```bash |
| 158 | node --run dev |
| 159 | ``` |
| 160 | |
| 161 | ```bash |
| 162 | node --run dev:desktop |
| 163 | ``` |
| 164 | |
| 165 | ### Option 2: Run With A Local LGTM Stack |
| 166 | |
| 167 | #### 1. Start Grafana LGTM |
| 168 | |
| 169 | ```bash |
| 170 | docker run --name lgtm \ |
| 171 | -p 3000:3000 \ |
| 172 | -p 4317:4317 \ |
| 173 | -p 4318:4318 \ |
| 174 | --rm -ti \ |
| 175 | grafana/otel-lgtm |
| 176 | ``` |
| 177 | |
| 178 | Then open `http://localhost:3000`. |
| 179 | |
| 180 | Default Grafana login: |
| 181 | |
| 182 | - username: `admin` |
| 183 | - password: `admin` |
| 184 | |
| 185 | #### 2. Export OTLP env vars |
| 186 | |
| 187 | For endpoint settings and startup precedence, see the |
| 188 | [user telemetry guide](../user/telemetry.md#export-diagnostics-to-your-own-receiver). |
| 189 | In a worktree, use `vp run dev` instead of `npx t3` to keep state isolated. |
| 190 | |
| 191 | ```bash |
| 192 | export T3CODE_OTLP_TRACES_URL=http://localhost:4318/v1/traces |
| 193 | export T3CODE_OTLP_METRICS_URL=http://localhost:4318/v1/metrics |
| 194 | export T3CODE_OTLP_LOGS_URL=http://localhost:4318/v1/logs |
| 195 | export OTEL_RESOURCE_ATTRIBUTES=deployment.environment.name=development |
| 196 | ``` |
| 197 | |
| 198 | Optional: |
| 199 | |
| 200 | ```bash |
| 201 | export T3CODE_TRACE_MIN_LEVEL=Info |
| 202 | export T3CODE_TRACE_TIMING_ENABLED=true |
| 203 | ``` |
| 204 | |
| 205 | #### 3. Launch the app from that same shell |
| 206 | |
| 207 | CLI: |
| 208 | |
| 209 | ```bash |
| 210 | npx t3 |
| 211 | ``` |
| 212 | |
| 213 | Monorepo web/server dev: |
| 214 | |
| 215 | ```bash |
| 216 | node --run dev |
| 217 | ``` |
| 218 | |
| 219 | Monorepo desktop dev: |
| 220 | |
| 221 | ```bash |
| 222 | node --run dev:desktop |
| 223 | ``` |
| 224 | |
| 225 | Packaged desktop app: |
| 226 | |
| 227 | Launch the actual app executable from the same shell so the desktop app and embedded backend inherit `T3CODE_OTLP_*`. |
| 228 | |
| 229 | macOS app bundle example: |
| 230 | |
| 231 | ```bash |
| 232 | T3CODE_OTLP_TRACES_URL=http://localhost:4318/v1/traces \ |
| 233 | T3CODE_OTLP_METRICS_URL=http://localhost:4318/v1/metrics \ |
| 234 | T3CODE_OTLP_LOGS_URL=http://localhost:4318/v1/logs \ |
| 235 | "/Applications/T3 Code.app/Contents/MacOS/T3 Code" |
| 236 | ``` |
| 237 | |
| 238 | Direct binary example: |
| 239 | |
| 240 | ```bash |
| 241 | T3CODE_OTLP_TRACES_URL=http://localhost:4318/v1/traces \ |
| 242 | T3CODE_OTLP_METRICS_URL=http://localhost:4318/v1/metrics \ |
| 243 | T3CODE_OTLP_LOGS_URL=http://localhost:4318/v1/logs \ |
| 244 | ./path/to/your/desktop-app-binary |
| 245 | ``` |
| 246 | |
| 247 | Do not rely on launching from Finder, Spotlight, the dock, or the Start menu after setting shell env vars. Those launches usually will not pick them up. |
| 248 | |
| 249 | #### 4. Fully restart after changing env |
| 250 | |
| 251 | The backend reads observability config at process start. If you change OTLP env vars, stop the app completely and start it again. |
| 252 | |
| 253 | ## How To Use Traces And Metrics To Debug The Server |
| 254 | |
| 255 | ### Start With The Local Trace File |
| 256 | |
| 257 | The trace file is the fastest way to inspect raw span data. |
| 258 | |
| 259 | Resolve the path for the launch mode once. Production and explicitly configured homes store runtime |
| 260 | state under the base directory's `userdata` folder: |
| 261 | |
| 262 | ```bash |
| 263 | TRACE_FILE="${T3CODE_HOME:-$HOME/.t3}/userdata/logs/server.trace.ndjson" |
| 264 | ``` |
| 265 | |
| 266 | A dev server started from a linked worktree defaults to that worktree's local home: |
| 267 | |
| 268 | ```bash |
| 269 | TRACE_FILE="$WORKTREE/.t3/userdata/logs/server.trace.ndjson" |
| 270 | ``` |
| 271 | |
| 272 | Only an implicit dev run outside a linked worktree uses the shared dev directory: |
| 273 | |
| 274 | ```bash |
| 275 | TRACE_FILE="$HOME/.t3/dev/logs/server.trace.ndjson" |
| 276 | ``` |
| 277 | |
| 278 | Tail the selected file: |
| 279 | |
| 280 | ```bash |
| 281 | tail -f "$TRACE_FILE" |
| 282 | ``` |
| 283 | |
| 284 | Show failed spans: |
| 285 | |
| 286 | ```bash |
| 287 | jq -c 'select(.type == "effect-span" and .exit._tag != "Success") | { |
| 288 | name, |
| 289 | durationMs, |
| 290 | exit, |
| 291 | attributes |
| 292 | }' "$TRACE_FILE" |
| 293 | ``` |
| 294 | |
| 295 | Show slow spans: |
| 296 | |
| 297 | ```bash |
| 298 | jq -c 'select(.durationMs > 1000) | { |
| 299 | name, |
| 300 | durationMs, |
| 301 | traceId, |
| 302 | spanId |
| 303 | }' "$TRACE_FILE" |
| 304 | ``` |
| 305 | |
| 306 | Inspect embedded log events: |
| 307 | |
| 308 | ```bash |
| 309 | jq -c 'select(any(.events[]?; .attributes["effect.logLevel"] != null)) | { |
| 310 | name, |
| 311 | durationMs, |
| 312 | events: [ |
| 313 | .events[] |
| 314 | | select(.attributes["effect.logLevel"] != null) |
| 315 | | { |
| 316 | message: .name, |
| 317 | level: .attributes["effect.logLevel"] |
| 318 | } |
| 319 | ] |
| 320 | }' "$TRACE_FILE" |
| 321 | ``` |
| 322 | |
| 323 | Follow one trace: |
| 324 | |
| 325 | ```bash |
| 326 | jq -r 'select(.traceId == "TRACE_ID_HERE") | [ |
| 327 | .name, |
| 328 | .spanId, |
| 329 | (.parentSpanId // "-"), |
| 330 | .durationMs |
| 331 | ] | @tsv' "$TRACE_FILE" |
| 332 | ``` |
| 333 | |
| 334 | Filter orchestration commands: |
| 335 | |
| 336 | ```bash |
| 337 | jq -c 'select(.attributes["orchestration_v2.command_type"] != null) | { |
| 338 | name, |
| 339 | durationMs, |
| 340 | commandType: .attributes["orchestration_v2.command_type"], |
| 341 | threadId: .attributes["orchestration_v2.thread_id"] |
| 342 | }' "$TRACE_FILE" |
| 343 | ``` |
| 344 | |
| 345 | Filter git activity: |
| 346 | |
| 347 | ```bash |
| 348 | jq -c 'select(.attributes["git.operation"] != null) | { |
| 349 | name, |
| 350 | durationMs, |
| 351 | operation: .attributes["git.operation"], |
| 352 | cwd: .attributes["git.cwd"], |
| 353 | hookEvents: [ |
| 354 | .events[] |
| 355 | | select(.name == "git.hook.started" or .name == "git.hook.finished") |
| 356 | ] |
| 357 | }' "$TRACE_FILE" |
| 358 | ``` |
| 359 | |
| 360 | ### Use Tempo When You Need A Real Trace Viewer |
| 361 | |
| 362 | Tempo is better than raw NDJSON when you want to: |
| 363 | |
| 364 | - search across many traces |
| 365 | - inspect parent/child relationships visually |
| 366 | - compare many slow traces |
| 367 | - drill into one failing request without hand-joining by `traceId` |
| 368 | |
| 369 | Recommended flow in Grafana: |
| 370 | |
| 371 | 1. Open `Explore`. |
| 372 | 2. Pick the `Tempo` data source. |
| 373 | 3. Set the time range to something recent like `Last 15 minutes`. |
| 374 | 4. Start broad. Do not begin with a very narrow query. |
| 375 | 5. Look for spans from the `t3code-server` or `t3code-desktop` service, then narrow by span name or |
| 376 | attributes. |
| 377 | |
| 378 | Good first searches: |
| 379 | |
| 380 | - service name `t3code-server` or `t3code-desktop`, plus a resource attribute such as |
| 381 | `deployment.environment.name` |
| 382 | - span names like `sendTurn` or a Git operation such as `GitVcsDriver.statusDetails.status` |
| 383 | - Git spans whose `git.operation` attribute identifies the operation |
| 384 | - orchestration spans with attributes like `orchestration_v2.command_type` |
| 385 | |
| 386 | Once you know traces are arriving, narrower TraceQL queries for names such as `sendTurn` or Git |
| 387 | operation names become useful. |
| 388 | |
| 389 | ### Use Metrics To See Systemic Problems |
| 390 | |
| 391 | Traces are best for one request. Metrics are best for trends. |
| 392 | |
| 393 | Good metric families to watch: |
| 394 | |
| 395 | - `t3_rpc_request_duration` |
| 396 | - `t3_provider_turn_duration` (how long the provider adapter takes to start a turn, not the turn's run time) |
| 397 | - `t3_git_command_duration` |
| 398 | |
| 399 | Counters tell you volume and failure rate: |
| 400 | |
| 401 | - `t3_rpc_requests_total` |
| 402 | - `t3_provider_turns_total` |
| 403 | - `t3_git_commands_total` |
| 404 | |
| 405 | Webhooks have their own families: |
| 406 | |
| 407 | - `t3_webhook_deliveries_total` by `outcome` and `source` (`relay` or `direct`). Beyond what the |
| 408 | sender sees, `queue_full` means a task already had its limit of deliveries waiting, |
| 409 | `prompt_too_long` means the filled-in prompt passed the provider limit, and `duplicate` means |
| 410 | the relay delivered a request this environment had already run. |
| 411 | - `t3_webhook_runs_total` by `outcome` (`started`, `skipped`, `failed`) for the runs those |
| 412 | deliveries start, which happen after the sender has its answer. |
| 413 | - `t3_webhook_held_delay` for how long requests the relay held waited before arriving. |
| 414 | |
| 415 | - `t3_secret_requests_total` by `status` (`saved`, `declined`, `cancelled`, `timed_out`) for secrets |
| 416 | agents asked users for, and `t3_secret_refs_consumed_total` by `result` (`used`, `rejected`) for |
| 417 | tools redeeming them. Neither ever carries a value. |
| 418 | |
| 419 | `ScheduledTaskService.triggerWebhook` spans carry the same outcome per request, and each run |
| 420 | started from a delivery is its own `ScheduledTaskService.runWebhookDelivery` trace. For a request |
| 421 | the relay forwarded, the local span retains the relay's parent span for correlation; The Knife |
| 422 | does not export it to T3 Connect. Requests that reach the environment directly never join a |
| 423 | sender's trace. |
| 424 | |
| 425 | Use metrics when the question is: |
| 426 | |
| 427 | - "is this always slow?" |
| 428 | - "did this get worse after a change?" |
| 429 | - "which command type is failing most often?" |
| 430 | |
| 431 | Use traces when the question is: |
| 432 | |
| 433 | - "what happened in this specific request?" |
| 434 | - "which child span caused this one slow interaction?" |
| 435 | - "what logs were emitted inside the failing flow?" |
| 436 | |
| 437 | ## Common Workflows |
| 438 | |
| 439 | ### "Why did this request fail?" |
| 440 | |
| 441 | 1. Start with the local NDJSON file. |
| 442 | 2. Find `effect-span` records where `exit._tag != "Success"`. |
| 443 | 3. Group by `traceId`. |
| 444 | 4. Inspect sibling spans and span events. |
| 445 | 5. If needed, move to Tempo for the full trace tree. |
| 446 | |
| 447 | ### "Why is the UI feeling slow?" |
| 448 | |
| 449 | 1. Search for slow top-level spans in the trace file or Tempo. |
| 450 | 2. Check child spans for sqlite, git, provider, or terminal work. |
| 451 | 3. Look at the matching duration metrics to see whether the slowness is systemic. |
| 452 | |
| 453 | ### "Are git hooks causing latency?" |
| 454 | |
| 455 | 1. Filter `git.operation` spans. |
| 456 | 2. Inspect `git.hook.started` and `git.hook.finished` events. |
| 457 | 3. Compare hook timing to the enclosing git span duration. |
| 458 | |
| 459 | ### "Why do I have spans locally but nothing in Grafana?" |
| 460 | |
| 461 | Usually one of these is true: |
| 462 | |
| 463 | - `T3CODE_OTLP_TRACES_URL` was not set |
| 464 | - the app was launched from a different environment than the one where you exported the vars |
| 465 | - the app was not fully restarted after changing env |
| 466 | - Grafana is looking at the wrong time range or service name |
| 467 | |
| 468 | If the local NDJSON file is updating, local tracing is working. The problem is almost always OTLP export configuration or process startup. |
| 469 | |
| 470 | ## How To Think About Adding Tracing To Future Code |
| 471 | |
| 472 | ### Prefer Boundaries Over Tiny Helpers |
| 473 | |
| 474 | Good span boundaries: |
| 475 | |
| 476 | - RPC methods |
| 477 | - orchestration command handling |
| 478 | - provider adapter calls |
| 479 | - external process calls |
| 480 | - persistence writes |
| 481 | - queue handoffs |
| 482 | |
| 483 | Avoid tracing every tiny helper. Most helpers should inherit the active span rather than create a new one. |
| 484 | |
| 485 | ### Reuse `Effect.fn(...)` Where It Already Exists |
| 486 | |
| 487 | The codebase already uses `Effect.fn("name")` heavily. That should usually be your first tracing boundary. |
| 488 | |
| 489 | For ad hoc work: |
| 490 | |
| 491 | ```ts |
| 492 | import { Effect } from "effect"; |
| 493 | |
| 494 | const runThing = Effect.gen(function* () { |
| 495 | yield* Effect.annotateCurrentSpan({ |
| 496 | "thing.id": "abc123", |
| 497 | "thing.kind": "example", |
| 498 | }); |
| 499 | |
| 500 | yield* Effect.logInfo("starting thing"); |
| 501 | return yield* doWork(); |
| 502 | }).pipe(Effect.withSpan("thing.run")); |
| 503 | ``` |
| 504 | |
| 505 | ### Put High-Cardinality Detail On Spans |
| 506 | |
| 507 | Use span annotations for IDs, paths, and other detailed context: |
| 508 | |
| 509 | ```ts |
| 510 | yield * |
| 511 | Effect.annotateCurrentSpan({ |
| 512 | "provider.thread_id": input.threadId, |
| 513 | "provider.request_id": input.requestId, |
| 514 | "git.cwd": input.cwd, |
| 515 | }); |
| 516 | ``` |
| 517 | |
| 518 | ### Keep Metric Labels Low Cardinality |
| 519 | |
| 520 | Good metric labels: |
| 521 | |
| 522 | - operation kind |
| 523 | - method name |
| 524 | - provider kind |
| 525 | - aggregate kind |
| 526 | - outcome |
| 527 | |
| 528 | Bad metric labels: |
| 529 | |
| 530 | - raw thread IDs |
| 531 | - command IDs |
| 532 | - file paths |
| 533 | - cwd |
| 534 | - full prompts |
| 535 | - full model strings when a normalized family label would do |
| 536 | |
| 537 | Detailed context belongs on spans, not metrics. |
| 538 | |
| 539 | ### Use Logs As Span Events |
| 540 | |
| 541 | Logs inside a span become part of the trace story: |
| 542 | |
| 543 | ```ts |
| 544 | yield * Effect.logInfo("starting provider turn"); |
| 545 | yield * Effect.logDebug("waiting for approval response"); |
| 546 | ``` |
| 547 | |
| 548 | Those messages show up as span events because `Logger.tracerLogger` is installed. |
| 549 | |
| 550 | ### Use The Pipeable Metrics API |
| 551 | |
| 552 | `withMetrics(...)` is the default way to attach a counter and timer to an effect: |
| 553 | |
| 554 | ```ts |
| 555 | import { someCounter, someDuration, withMetrics } from "../observability/Metrics.ts"; |
| 556 | |
| 557 | const program = doWork().pipe( |
| 558 | withMetrics({ |
| 559 | counter: someCounter, |
| 560 | timer: someDuration, |
| 561 | attributes: { |
| 562 | operation: "work", |
| 563 | }, |
| 564 | }), |
| 565 | ); |
| 566 | ``` |
| 567 | |
| 568 | ## Detailed API Reference |
| 569 | |
| 570 | ### Runtime Wiring |
| 571 | |
| 572 | The server observability layer is assembled in `apps/server/src/observability/Observability.ts`. |
| 573 | |
| 574 | It provides: |
| 575 | |
| 576 | - pretty stdout logger |
| 577 | - `Logger.tracerLogger` |
| 578 | - local NDJSON tracer |
| 579 | - optional OTLP trace exporter |
| 580 | - optional OTLP metrics exporter |
| 581 | - optional OTLP log exporter |
| 582 | - Effect trace-level and timing refs |
| 583 | |
| 584 | The desktop main process is a second producer, assembled in |
| 585 | `apps/desktop/src/app/DesktopObservability.ts`. It reads the same `T3CODE_OTLP_*` names and the same |
| 586 | Settings entries as the backend it supervises, and covers work the backend cannot see: app startup, |
| 587 | window and menu handling, backend supervision, and updates. It reports as service |
| 588 | `t3code-desktop`, so a collector shows it alongside the backend rather than mixed into it. It |
| 589 | exports traces and logs only; the main process records no metrics, so the metrics endpoint applies |
| 590 | to the backend alone. |
| 591 | |
| 592 | ### Env Vars |
| 593 | |
| 594 | Local trace file: |
| 595 | |
| 596 | - `T3CODE_TRACE_FILE`: override trace file path |
| 597 | - `T3CODE_TRACE_MAX_BYTES`: per-file rotation size, default `10485760` |
| 598 | - `T3CODE_TRACE_MAX_FILES`: rotated file count, default `10` |
| 599 | - `T3CODE_TRACE_BATCH_WINDOW_MS`: flush window, default `1000` |
| 600 | - `T3CODE_TRACE_MIN_LEVEL`: minimum trace level, default `Info` |
| 601 | - `T3CODE_TRACE_TIMING_ENABLED`: enable timing metadata, default `true` |
| 602 | |
| 603 | OTLP export: |
| 604 | |
| 605 | - `T3CODE_OTLP_TRACES_URL`: OTLP trace endpoint |
| 606 | - `T3CODE_OTLP_METRICS_URL`: OTLP metric endpoint |
| 607 | - `T3CODE_OTLP_LOGS_URL`: OTLP log endpoint |
| 608 | - `T3CODE_OTLP_EXPORT_INTERVAL_MS`: export interval, default `10000` |
| 609 | - `T3CODE_OTLP_HEADERS`: extra headers for all three exporters, same format as |
| 610 | `OTEL_EXPORTER_OTLP_HEADERS`: comma-separated `key=value` pairs with percent-encoded values. |
| 611 | - `T3CODE_OTLP_PROTOCOL`: `http/json` (default) or `http/protobuf` |
| 612 | |
| 613 | The server and the desktop app also read the standard |
| 614 | `OTEL_EXPORTER_OTLP_{TRACES,METRICS,LOGS}_ENDPOINT` and generic `OTEL_EXPORTER_OTLP_ENDPOINT` (with |
| 615 | `/v1/traces`, `/v1/metrics`, or `/v1/logs` appended), for a collector expecting those instead. A |
| 616 | non-blank `T3CODE_OTLP_*_URL` wins over either, and a per-signal endpoint wins over the generic one |
| 617 | for its signal. A blank value counts as unset. A signal with an OTEL endpoint takes its headers from |
| 618 | `OTEL_EXPORTER_OTLP_HEADERS` and its protocol from `OTEL_EXPORTER_OTLP_PROTOCOL` (default |
| 619 | `http/protobuf`, read case-insensitively), and a per-signal |
| 620 | `OTEL_EXPORTER_OTLP_{TRACES,METRICS,LOGS}_HEADERS` or `_PROTOCOL` wins over the generic one for its |
| 621 | signal. `T3CODE_OTLP_HEADERS` and `T3CODE_OTLP_PROTOCOL` never apply to it. An endpoint that is not |
| 622 | an `http` or `https` URL, a protocol other than `http/protobuf` or `http/json` such as `grpc`, or |
| 623 | headers that are not `key=value` pairs with percent-encoded values turn that signal's export off |
| 624 | with a startup warning, rather than sending it to the Settings endpoint. |
| 625 | |
| 626 | Service names are fixed: `t3code-server` for the backend and `t3code-desktop` for the desktop main |
| 627 | process, both in `service.namespace` `t3code`. `OTEL_SERVICE_NAME` and a `service.name` or |
| 628 | `service.namespace` in `OTEL_RESOURCE_ATTRIBUTES` are ignored. Tell installations apart with other |
| 629 | resource attributes, such as `OTEL_RESOURCE_ATTRIBUTES=deployment.environment.name=development`. |
| 630 | |
| 631 | If the OTLP URLs are unset, local tracing still works, metrics stay in-process only, and logs stay |
| 632 | on stdout only. |
| 633 | |
| 634 | ### The Kill Switch |
| 635 | |
| 636 | `T3CODE_OTEL_SDK_DISABLED` and `OTEL_SDK_DISABLED` turn off every OTLP export in both the server and |
| 637 | the desktop main process, overriding any endpoint from the environment or Settings. Local trace |
| 638 | files and stdout logs are unaffected. |
| 639 | |
| 640 | `T3CODE_OTEL_SDK_DISABLED` wins when set, so `T3CODE_OTEL_SDK_DISABLED=false` re-enables export on a |
| 641 | machine that sets `OTEL_SDK_DISABLED` for everything else. It accepts the usual boolean spellings |
| 642 | (`true`/`false`, `yes`/`no`, `on`/`off`, `1`/`0`, `y`/`n`). `OTEL_SDK_DISABLED` follows the |
| 643 | OpenTelemetry specification and only `true` disables export, so `OTEL_SDK_DISABLED=1` does not. |
| 644 | Values are case-insensitive and trimmed. An unrecognized value is ignored with a startup warning. |
| 645 | |
| 646 | `OTEL_TRACES_EXPORTER`, `OTEL_METRICS_EXPORTER`, or `OTEL_LOGS_EXPORTER` set to `none` turns off |
| 647 | just that signal, overriding an OTEL endpoint and the Settings endpoint. A `T3CODE_OTLP_*_URL` still |
| 648 | wins for its signal. `otlp` is the default, and any other exporter name, such as `console` or |
| 649 | `prometheus`, is ignored with a startup warning. |
| 650 | |
| 651 | ### What Is Instrumented Today |
| 652 | |
| 653 | Current high-value span and metric boundaries include: |
| 654 | |
| 655 | - WebSocket RPC request spans (`ws.rpc.<method>`) and metrics in |
| 656 | `apps/server/src/observability/RpcInstrumentation.ts` |
| 657 | - startup phases |
| 658 | - orchestration command processing |
| 659 | - provider session and turn operations |
| 660 | - git command execution and git hook events |
| 661 | - terminal session lifecycle |
| 662 | - sqlite query execution, except the statements inside `orchestrationV2.EventSink.write`, which |
| 663 | its `sql.transaction` span times as one |
| 664 | - event loop stalls (`server.eventLoop.stall`) |
| 665 | |
| 666 | ### Current Constraints |
| 667 | |
| 668 | - logs outside spans are not persisted in the trace file; SSH-managed launch stdout/stderr is still |
| 669 | captured in its launcher log |
| 670 | - metrics are not snapshotted locally |
| 671 | |
| 672 | ## Heap Snapshots |
| 673 | |
| 674 | To see what a long-running server holds in memory, send it `SIGUSR2`. The server writes a V8 heap |
| 675 | snapshot to its logs dir and logs the path. This works for desktop, `npx t3`, and service installs |
| 676 | on macOS and Linux. Windows has no `SIGUSR2`. |
| 677 | |
| 678 | Send the signal to the server pid in `server-runtime.json`, which sits in the server's state dir |
| 679 | next to the `logs` dir. For a dev server or a `--home-dir` launch, use that server's state dir from |
| 680 | [Traces](#traces). Do not send it to the desktop app or the service launcher: a process without the |
| 681 | handler exits on `SIGUSR2`. After a crash the file can keep a stale pid that now belongs to a |
| 682 | different process, so check the pid first. |
| 683 | |
| 684 | ```bash |
| 685 | pid="$(jq .pid "${T3CODE_HOME:-$HOME/.t3}/userdata/server-runtime.json")" |
| 686 | ps -p "$pid" -o command= |
| 687 | ``` |
| 688 | |
| 689 | If `ps` shows the T3 Code server, send the signal: |
| 690 | |
| 691 | ```bash |
| 692 | kill -USR2 "$pid" |
| 693 | ``` |
| 694 | |
| 695 | The file is `<logsDir>/server-<pid>-<timestamp>.heapsnapshot`, next to `server.trace.ndjson`. To |
| 696 | open it, use the Memory tab in Chrome DevTools and select Load. |
| 697 | |
| 698 | Before you take one: |
| 699 | |
| 700 | - The server stops while it writes the file. For a large heap this can take a minute or more. |
| 701 | Connected clients can reconnect during the pause, and an event loop monitor, if the server has |
| 702 | one, records the pause as a stall. Send the signal once. A second signal sent during a write |
| 703 | takes another snapshot after the first one finishes. |
| 704 | - The write needs about as much free memory as the heap uses. On a machine that is already |
| 705 | swapping, it can make the problem worse or crash the server. |
| 706 | - The file contains everything in server memory, including tokens, secrets, and thread content. Do |
| 707 | not share it publicly. Delete it when you are done, because storage cleanup does not remove it. |