navree
Documentation

Logbook

A local debugging timeline of every request, query, job, mail, event, cache call and log line, with filters by tag and user, and request replay.

On this page

Introduction

Featurelogbook Logbook shows you what your app did. While you develop, it records every request with everything that happened during it: the queries it ran, the events it emitted, the mail it sent, the cache calls it made, the data it changed and the log lines it wrote. It shows them as one timeline at /_logbook, served by your app. Filter it by tag or user, open a request to see its queries in order, and replay it after you change the code.

Logbook is for development. It records full request and response bodies, which is what you want on your machine and never on a server. In a release build it is off: it records nothing and serves nothing, unless you turn it on deliberately.

Installation

The logbook feature of the navree facade brings the crate navree-logbook. It is part of full, the default, and an app made with navree new already includes the module. To add it to an existing app:

src/app.rs

LogbookModule is global and needs nothing but HttpModule. It records what the modules in your app do, so a module you leave out (say, MailModule) has nothing to show. It keeps its entries in its own SQLite file, storage/logbook.db, not in your app's database.

Start the app and open the timeline:

Shell
Text

Because entries are stored on disk, they survive the restarts navree dev makes when you change the code: the request that failed before your fix is still there after it.

The timeline

The page has three parts.

  • The list. Entries, newest first, arriving live. Requests, jobs and scheduled tasks are batches: one line each, with the method and path or the job type, the status, the duration, the user, and small counters for the queries, events, mail, log lines, exceptions and outgoing calls inside. Failed batches are marked in amber, and so are batches with slow or duplicate queries.
  • The filters. A row of entry types (requests, queries, jobs, mail, events, cache, logs, exceptions, outgoing HTTP, notifications, data changes, scheduled tasks, dumps) under a search box that takes filter terms.
  • The detail. A selected request shows its summary first: the method, path, route template, status, duration, request id, client address, user, workspace and trace. Tabs below hold the request (headers, query string, body), the response (headers, body), the queries, the events, the jobs, the mail, the cache calls, the log lines, the exceptions, the outgoing calls, the data changes, the dumps, the timeline (a waterfall of everything the request did, in order, drawn against the request's duration) and Replay.

A queued job continues the trace of the request that dispatched it. A job's detail links back to that request (Dispatched by), and a request's Jobs tab lists the job attempts in its trace, so you can follow work from the click to the worker and back.

What Logbook records

Each kind of entry comes from a watcher. Every watcher is on by default; turn one off with logbook.watchers.<name> = false. Logbook builds on the app's telemetry events and on the data changes Repo records.

WatcherRecordsDetail
requestsEvery HTTP requestMethod, path, route, status, duration, user, workspace, headers, query string, request and response bodies
queriesEvery SQL statementThe SQL with its placeholders (the database module reports no bound values), the duration, the connection, and where it ran (the request, job or scheduled task)
jobsEvery job attemptType, queue, job id, attempt, outcome (processed, released for another attempt, or failed), error, duration
mailEvery message the Mailer hands to its transportSender, recipients, subject, the rendered HTML and text bodies, the transport
eventsEvery event emitted or publishedName, payload, the listeners that ran, the ones queued and the ones that failed
cacheEvery cache callOperation (hit, miss, write, forget), key, store
logsLog lines at logbook.log_level (debug) or aboveLevel, target, message, fields
exceptions5xx responses, panics and errors you report with Telemetry::report_exceptionThe error and its source chain, the location of a panic
http_clientCalls through HttpClientMethod, URL, status, duration, attempts, error
notificationsEvery notification, one entry per channelType, notifiable, channel, notification id
modelsEvery insert, update and delete through RepoTable, id, the changed columns with old and new values
scheduleEvery scheduled task that runsTask, the minute it was due, error, duration

A job's error is part of its entry; the exceptions watcher records errors of requests and your own reports.

Log lines reach Logbook after the log filter: Logbook keeps the lines that pass log.level and are at logbook.log_level or above. To see debug lines in Logbook, set log.level (or the target in log.levels) to debug as well.

Logbook leaves its own routes out, and the paths in logbook.ignore.routes (/health/* and /metrics by default): nothing those requests do is recorded.

Filtering

The search box takes free text, which matches paths, routes, SQL, job types, event names, mail subjects and recipients, log messages and targets, and these terms:

TermShows
user:0192f0c1-…Entries of one user (a prefix of the id is enough)
tag:deal:0199c1d2Entries whose batch has a tag starting with this
status:500, status:4xxRequests by status or status class
route:/api/v1/deals/{id}Requests to one route
type:queryOne kind of entry, like the buttons (several type: terms show any of them)
slowSlow queries, and the batches that ran one
failedFailed requests (5xx), jobs, queries, outgoing calls and scheduled tasks
duration>200, duration<5Entries that took longer (or shorter) than this many milliseconds
batch:01a17749…Everything inside one batch, by request id or job id (a prefix is enough)
trace:4bf92f35…Everything in one trace: a request and the jobs it queued
"two words"Free text with spaces

Terms combine: user:0192f0c1 status:4xx route:/api/v1/deals/{id} shows one user's failed calls to one route. Without a type:, batch: or trace: term the list shows batches and entries outside any batch. Clicking a user, a tag, a route or a status anywhere in the detail view filters by it.

Tags

Logbook tags entries for you:

  • every batch with user:<id> and, with workspaces, workspace:<id>;
  • requests with route:<template> and status:<code>, and replays with replay;
  • jobs with job:<type> and queue:<name>, scheduled runs with schedule:<task>;
  • data changes with the entity in the singular and its id, such as deal:0199c1d2-6f7e-7a31-b5d4-2f0c8e9a1b23, on the batch that made the change, so tag:deal:0199c1d2 finds every request and job that touched that deal.

Add your own to the current batch through the Logbook service:

src/modules/contacts/import.rs

tag labels the running request, job or scheduled task. dump(label, &value) records any Serialize value as an entry of its own, in its place on the batch's timeline: the quickest way to see what a variable held without a println! in your terminal. Both do nothing outside a batch (a dump there is an entry on its own) and nothing at all when Logbook is off, so they can stay in your code.

Duplicate queries

When the same statement runs logbook.duplicate_queries times (5) or more in one batch, Logbook marks the batch and the queries. Statements are compared as SQL with placeholders, so loading twenty companies by id is one statement run twenty times. That is usually a loop loading related records one at a time:

GET /api/v1/deals · Queries

The Queries tab lists the repeated statements first, with how many times each ran and their total time, then every statement in order. Fix the loop with one IN query or a join. Queries slower than logbook.slow_query_ms (100 ms) are marked too, and so is the batch that ran them.

Replaying requests

A request's detail has a Replay tab. It opens the recorded request in an editor: the method, the path and query string, the headers and the body, all prefilled and all editable. Send it and Logbook runs it through your app's router again, in-process, and records the result as a new batch tagged replay whose request links to the original. Fix the bug, wait for navree dev to restart, and replay the request that failed without going back to your front end.

  • As the same user. When the app includes AuthModule, Replay sends the request as the user who made it: Logbook signs a fresh access token for them, valid for five minutes. Recorded Authorization headers are never stored, so a replay never reuses one. Untick the As … box, which names the user's id, to send it as a guest.
  • Unsafe methods ask first. A POST, PUT, PATCH or DELETE replays only after you confirm: it changes data again, and creates a second deal if the first request created one.
  • Copy as curl. The request as a curl command against http.addr, without credentials.

Mail has Open HTML, which shows the rendered message in a new tab, sandboxed and without scripts: with the log mail transport you read every message your app sends without a mail catcher.

Turn replay off with logbook.replay = false.

From code, Logbook::replay(id, ReplayRequest { .. }) does the same and returns the status, headers and body (ReplayRequest::default() replays as recorded; set confirm: true for unsafe methods, as_guest: true to drop the user), and Logbook::curl(id) gives the command.

The API

The page reads a JSON API under the same path, with the same access rules:

RouteDoes
GET /_logbook/api/entries?q=&type=&before=&after=&limit=Entries matching a filter, newest first: { "data": [...], "next": <seq> }
GET /_logbook/api/entries/{id}One entry
GET /_logbook/api/batches/{id}A batch: its entries in order and its duplicate_queries
POST /_logbook/api/requests/{id}/replayReplays a request (the body is a ReplayRequest); 409 for an unconfirmed unsafe method
GET /_logbook/api/requests/{id}/curlThe request as a curl command
DELETE /_logbook/api/entriesDeletes every entry

Storage and pruning

StoreWhereUse it for
file (default)A SQLite file, logbook.file (storage/logbook.db)Everyday development: entries survive restarts.
memoryThe process's memoryTests, and machines where you'd rather not write the file.

Logbook keeps the newest logbook.max_entries entries (10,000) and nothing older than logbook.keep_hours (24), pruning at boot and every five minutes while the app runs. Batches are pruned whole, never half. To start over:

Shell

Bodies longer than logbook.capture.max_body_kb (64 KiB) are cut, with the original size shown. Binary bodies are stored as their size and content type only, and streamed bodies (server-sent events, bodies of unknown or very large size) are passed through untouched.

Security

Logbook shows everything, so it is built to stay on your machine.

  • Off in release builds. In a binary built with --release, logbook.enabled defaults to false: no routes, no watchers, nothing written. See release builds for the one exception.
  • Local requests only. The UI and its API answer requests from loopback addresses (127.0.0.1, ::1) and nothing else, whatever http.addr is. Another machine on your network gets a 404. To open it to others, for a shared staging server for example, set logbook.allow_remote = true: then every request needs a signed-in user with the permission logbook.view, checked by the app's route authorizer (AccessModule). Without one, the app fails to boot.
  • Secrets are masked. Authorization, Proxy-Authorization, Cookie and Set-Cookie headers are never stored, and values whose names contain a fragment of log.redact (password, token, secret and the rest) are stored as [redacted], in headers, query strings, JSON bodies and form bodies. Point Logbook at development data, not at a copy of production.

Release builds

To use Logbook on a staging server built with --release, set logbook.enabled = true, and logbook.allow_remote = true with a route authorizer to reach it from another machine. The app then logs a warning at every boot, Logbook is recording in a release build, so it can't stay on by accident. In production, use Lighthouse: it samples, masks bodies by default and is built to run there.

You can also leave the module out of release builds entirely:

src/app.rs

Using Logbook in tests

Logbook can tell a test what a request did, which makes "this page runs three queries" something you can assert. TestApp turns Logbook off; turn it back on with the memory store and read the last batch:

tests/deals_board.rs

A Batch has queries(), duplicate_queries(), events(), jobs(), mail(), cache_calls(), logs(), exceptions(), http_calls(), notifications(), models(), dumps(), tags(), its own entry as head() (with request() for a request) and entries() for everything, in order. last_request(), last_job(), last_schedule() and batch(id) find one; entries(&ListQuery) takes a filter; clear() empties the store between steps of a test. Logbook::in_memory(options) gives a recording Logbook outside an app.

Configuration

Every key of the logbook section is optional. From the environment: APP_LOGBOOK__STORE=memory, APP_LOGBOOK__WATCHERS__CACHE=false, and lists as comma-separated strings (APP_LOGBOOK__IGNORE__ROUTES=/health/*,/metrics,/up).

KeyDefaultWhat it does
logbook.enabledtrue in debug builds, false in release buildsRecord and serve anything at all.
logbook.path/_logbookWhere the UI is served.
logbook.storefilefile or memory.
logbook.filestorage/logbook.dbThe SQLite file of the file store.
logbook.max_entries10000Entries kept.
logbook.keep_hours24Age after which entries are pruned.
logbook.allow_remotefalseServe the UI to non-loopback clients, behind the permission logbook.view.
logbook.log_leveldebugThe lowest level of log lines recorded.
logbook.slow_query_ms100When a query is marked slow.
logbook.duplicate_queries5Repeats of one statement in a batch that mark it as duplicated.
logbook.capture.request_bodytrueStore request bodies.
logbook.capture.response_bodytrueStore response bodies.
logbook.capture.max_body_kb64Bodies are cut after this size.
logbook.replaytrueAllow replaying requests.
logbook.ignore.routes["/health/*", "/metrics"]Paths never recorded (* matches anything).
logbook.watchers.<name>trueEach watcher: requests, queries, jobs, mail, events, cache, logs, exceptions, http_client, notifications, models, schedule.

A bad value fails the boot with an error naming the key.

CommandWhat it does
logbook:clearDeletes every entry (also from logbook.file when Logbook is off in this build).