LogTape 2.4.0: Source locations, configuration inspection, sink draining, and request completion levels #254
dahlia
announced in
Announcements
Replies: 0 comments
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Uh oh!
There was an error while loading. Please reload this page.
LogTape is a logging library for JavaScript and TypeScript that works across Deno, Node.js, Bun, and browsers. It's built around structured logging, has zero dependencies, and is designed to work as well in library code as in application code.
Version 2.4.0 adds opt-in source locations for development logging, an
inspectLogger()function that explains why a record does or doesn't reach a sink, a"forward"mode for sink inheritance,drain()for waiting on pending sink output, more control overfingersCrossed()buffers, and level selection by response outcome in the Express, Hono, Koa, and Elysia integrations.Source locations
In a browser's DevTools, every line LogTape prints is attributed to the sink's
console.log()call, not to the code that logged. That link can't change, because theconsolecall really does happen inside the sink. This release adds the call site to the text of the message instead. It was requested in #134 and implemented in #241 and #253.Setting
captureSourceLocation: trueon a logger configuration records where each logging method was called, in the newLogRecord.sourceLocationfield (aSourceLocationwithfile,line, andcolumn). Child categories inherit the setting,withConfig()andwithConfigSync()accept it, and @logtape/config does too. Formatters decide whether to show the location through the newsourceLocationoption ofgetTextFormatter()andgetAnsiColorFormatter(), and the newgetConsoleFormatter()does the same for console sinks:The location comes from the runtime's stack trace, so capturing it costs several microseconds per call (tens on Deno). That is why it is off by default and meant for development. When no configuration enables it, LogTape only checks two module variables. LogTape doesn't resolve source maps, so bundled or minified code may report positions in the generated code unless the runtime applies source maps itself. When the stack can't be read unambiguously, the location is left out instead of guessed. The feature was tested on Node.js, Deno, Bun, Chromium, and Firefox, but not on Safari. The source location documentation has the details on which call site is reported for tagged templates, child loggers, and wrapper functions.
Thanks to @benjamind for filing the original request, and to @belgattitude for weighing in on the trade-offs.
Inspecting the effective configuration
getConfig()tells you what you configured, but not how a particular logger's level, its ancestors' sinks, and their filters combine. The newinspectLogger()function shows how they combine for one logger in the current execution context, without logging anything or invoking filters and sinks. It is meant for the case where records don't show up where you expect:A
"debug"record is accepted by["my-app", "db"], but the only sink belongs to["my-app"], whoselowestLevelis"info". The report shows each sink path with thelowestLevelgates along it and the categories that supplied them, the filters that apply, where sink inheritance stops, and whether a scoped configuration is in effect. A path behind a custom filter is reported as"conditional", since the outcome is only known when a record is logged. The report doesn't look inside sinks, so a sink wrapped bywithFilter()orfingersCrossed()can still drop a record on a path the report marks"enabled".It also makes category mistakes visible:
inspectLogger("my-app:http")shows a single category segment"my-app:http"whose only ancestor is the root, not a child of["my-app"]. The documentation lists every field of the report. It was proposed in #243 and implemented in #251.getLoggers()enumerates every logger in the category tree under a given logger (the root by default) in depth-first order. It only sees loggers thatgetLogger()has already created, so a logger made lazily inside a function that hasn't run yet won't appear. The use cases in #62 were a workspace with many packages and an app with a debug panel for toggling logging by category. Thanks to @kwonoj and @callumgare for raising it, and to Jepoy (@Polqt) for implementing it in #207.Forwarding sinks regardless of ancestor levels
Sometimes one descendant category needs more verbose output while keeping the same destinations as its ancestors. With the default
parentSinks: "inherit", lowering the child'slowestLevelis not enough: each ancestor'slowestLevelstill gates its own sinks, so a record below the ancestor's threshold never reaches them. The workaround was to repeat the parent's sink names on the child and setparentSinks: "override", after which the two lists could fall out of sync.The new
parentSinks: "forward"mode inherits every ancestor's sinks without applying the ancestors'lowestLevelthresholds. Only the logger's ownlowestLeveldecides what is accepted:An ancestor configured with
parentSinks: "override"still stops the chain. The default"inherit"mode is unchanged, and the mode is also accepted in @logtape/config. See Forwarding sinks regardless of ancestor levels for the exact rules. This was proposed in #198.Draining sinks and async sink limits
Disposing a stream sink closes its stream and stops it from accepting records. The new
drain()function instead waits for pending output and keeps the sinks open, which suits long-running processes and serverless functions that must finish sending logs after returning a response.Drainableis the interface sinks implement to support it:drain()waits for the records that sinks accepted before the call and nothing logged afterward. A record counts as settled when its sink operation finishes, including when it fails, or when the sink drops it after accepting it. It doesn't guarantee a disk sync or delivery to a remote collector. The sinks fromgetStreamSink()andfromAsyncSink()are drainable,withFilter()andfingersCrossed()forwarddrain()to the sink they wrap, and draining afingersCrossed()sink does not release records still waiting for a trigger. It was tested on Deno, Node.js, and Bun, and not on browsers or edge runtimes. The design is in #239 and #247.fromAsyncSink()also takes options now, because its promise chain used to be unbounded, as reported in #238 and fixed in #246.maxQueueSizecaps how many records wait for the async sink, not counting the one being processed, andoverflowchooses whether a full queue drops its oldest waiting record (the default) or the incoming one. The limit bounds queued records, not total memory: with"drop-oldest", the bookkeeping of each dropped record stays until the record being processed settles.onDropreceives aSinkDropEventwith the count and the reason, without any record payloads. On serverless platforms,waitUntilis called synchronously during each logging call, with a promise that settles once that record and every earlier one has been processed or dropped. AwaitUntil()that looks up the current request therefore attaches the promise to the request that logged the record:This was tested on Deno, Node.js, Bun, and a local workerd, but not on hosted platforms. The serverless section of the sinks manual has the details. Non-blocking console and stream sinks silently dropped the oldest record when the buffer reached twice its size, and swallowed background write errors. Changes in #245 and #249 add
onDropandonErrorcallbacks tononBlocking, which report aggregated drop counts and failures without exposing the records. The same change fixes concurrent or repeated disposal of a non-blocking stream sink, which now finishes pending output before closing or releasing its writer.The
closeStreamoption ofgetStreamSink(), tracked in #203, disposes the sink without closing a stream you own.writer.close()can hang on streams likeWritable.toWeb(process.stdout)inside a SIGINT handler. WithcloseStream: false, disposal still waits for queued writes, flushes, and releases the writer lock.Fingers-crossed buffer control
fingersCrossed()buffers records until one at the trigger level arrives. This release adds options for buffering again after a trigger, ending request buffers explicitly, and copying buffered records.Once a trigger fires, every later record passes straight through, so in a long-running process one error turns the sink into a plain sink for the rest of its life. Setting
afterTrigger: "buffer"makes it go back to buffering after each trigger, so each error is output together with the records that led up to it, and not the ones already flushed. This was reported in #234 and fixed in #235. The default is"passthrough", as before.A request's buffer also had no explicit end. With
isolateByContext, a successful request's buffer just waited for LRU or TTL eviction. #205 asked for a way to clear it when a Hono request finishes, and @RWOverdijk's request led tobufferAction. The callback callback inspects each record and returns"flush"to emit the matching buffer plus that record,"discard"to drop both, orundefinedto apply the usual rules. For lifecycles that end outside the logging stream, the returned sink hasflush()anddiscard()methods that take an optional{ context, category }selector:Both actions end the current buffer, and a later record with the same isolation key starts a fresh one. A
triggerLevelmatch behaves differently by default: the key stays in passthrough mode. BecausebufferActionruns before the already-triggered check, a final request record can also end a buffer that entered passthrough mode earlier.Buffered records hold references to their property objects, so mutating an object after logging it changes what the buffered record shows later. The optional
snapshot(record)callback copies a record when it is buffered. It was proposed in #242 and implemented in #250. It runs synchronously, only for records that are buffered, and routing and triggering still use the original record. You are responsible for copying interpolated message values as well asproperties, since LogTape has no built-in cloning policy, and if the callback throws, the failure follows the sink error path instead of falling back to the mutable record. See the fingers crossed sink documentation for the full rules.Request completion levels
The Express, Hono, Koa, and Elysia integrations logged every completed request at one fixed
level, so a 200 and a 500 had the same severity. Each package now accepts acompletionLevelcallback that picks the level from the response outcome, modeled on pino-http'scustomLogLevel. It was requested in #240 and implemented in #248:The callback receives the framework's context plus a
RequestCompletionobject withstatusandresponseTime. In Hono, it also includes theerrorfrom the error handler and whether the body wasaborted. In Elysia, the callback also picks the level of the record written by the error hook, without adding a second record. Theleveloption still applies to request-start logs and is the fallback: if the callback throws or returns an invalid level, the failure is reported to the meta logger and the record is written atlevel. The response is never affected. Signatures differ per framework, so check the integration docs, such as Express completion log levels, for what each one passes.@logtape/elysia also supports Elysia 2 beta alongside 1.4, in #212.
Bare string values
getTextFormatter()andgetAnsiColorFormatter()always render interpolated strings the wayinspect()does, quoted and escaped. Quoting and escaping make a command or path harder to copy from the output. The newvalue: "bare"preset renders top-level string values as they are. Strings nested in objects and arrays keep their quotes, and the same option now exists on the pretty formatter. This came out of #236 and was implemented in #237.A bare string skips
inspect()'s quoting and escaping but is still sanitized: SGR escape sequences are always escaped, even withsgr: "preserve", because one\x1b[8mcould conceal the rest of the output, and newlines are escaped unlesssanitize.newlinesis explicitly"preserve". The JSON Lines and logfmt formatters keep their format-defined quoting."bare"is not shell quoting.TextFormatterOptions.valuenow has the type"bare" | ((value, inspect) => string). Code that invokesoptions.valuedirectly must first check that it is a function.Smaller improvements
getRotatingFileSink()takes arotatedFilePathoption to customize rotated file paths, for example to keep the .log extension (app.1.loginstead ofapp.log.1), so log shippers with a*.logglob don't skip backups. Thanks to @benrichardv for the request in Allow customizing rotated file names ingetRotatingFileSink()#215; it was implemented in Allow custom rotated file paths #216. In the same change, positivemaxFilesvalues must now be integers from 1 to 1,000, or sink creation throwsRangeError. Zero and negative values still disable backups.LogRecorder.waitFor()waits for the first matching record, with a timeout (1000 ms by default) and optionalAbortSignal, so tests of background work no longer have to poll or sleep. It waits for the recorder to observe a record, not for delivery through async sinks (Add an awaitable matcher toLogRecorder#244, Add awaitable log matching toLogRecorder#252).no-dynamic-messageflags dynamic expressions passed as log messages, which LogTape treats as templates (Add a lint rule for dynamic log messages #199); Deno Lint users enable it through@logtape/lint/deno/strict.no-unrendered-propertiesflags properties that no message placeholder references and that sinks forwarding only the message would lose (Add opt-inno-unrendered-propertieslint rule #214).Upgrading
npm update @logtape/logtape # if you use any of the affected integrations npm update @logtape/config @logtape/elysia @logtape/express @logtape/file npm update @logtape/hono @logtape/koa @logtape/lint @logtape/pretty npm update @logtape/testingTwo changes can affect existing code. Positive
maxFilesvalues passed togetRotatingFileSink()must now be integers from 1 to 1,000.TextFormatterOptions.valuenow accepts"bare"as well as a function, so code that invokes it must first check its type. All other changes are additive. See the full changelog for complete details.All reactions