Readiness: Implemented
Build an app
Logging
A line a person reads and a line a log aggregator reads are different lines, and the way to have both is to build a record and format it twice. uf builds the record: a level, a time, a constant message, and fields. Every request gets an id when it arrives, and that id is readable from a loader, a route handler and a server component's render without anybody being handed a request.
What you will be able to do: log structured records, read the request id from inside a render, choose a format and a level, and send lines somewhere else.
What you need first: a project that serves requests — Routing.
Startup and error hooks
Place $instrumentation.js at the router root. register() runs once per
application instance, before its first request; concurrent first requests await
the same promise. A failed startup stays failed. Development reloads create a new
instance, and each Worker isolate or serverless instance starts independently.
// app/$instrumentation.js
// @flow
import { logger } from "@uniflowed/server";
import { startTelemetry } from "./_server/telemetry.js";
export async function register() {
await startTelemetry();
}
export async function onRequestError(error, context) {
logger().error("request failed", {
error,
phase: context.phase,
route: context.route,
requestId: context.requestId,
});
}
The context includes method, the matched route pattern (or null), the request
id and phase: middleware, route, loader, render, action, or request.
The hook also receives exceptions recovered by a route boundary and late streamed
render failures. One exception is reported once per request. An error in the hook
is logged without replacing the application's response. Workers keep asynchronous
error hooks alive through waitUntil.
This entry works under uf dev, uf start, uf preview and every runtime adapter.
It does not run while prerendering a static build. Hook modules belong directly at
the router root; they are never routes or browser imports.
OpenTelemetry
uf emits through @opentelemetry/api; the application installs its own SDK,
context manager and exporter in register(). Any compatible exporter can receive
the spans. Without an SDK the API is a no-op: uf starts no exporter, background
timer or network connection. Use the SDK appropriate to the deployment; the
framework does not select a vendor or a Node-only SDK.
The trace contains uf.request, uf.middleware, uf.route, uf.loader,
uf.render, uf.action and uf.fetch. An @uniflowed/fetch call inside an async
Server Component is a child of its render. Loaders remain optional; component
fetching is traced directly. uf.render measures the renderer through its shell;
uf.request remains open while a returned response body is consumed or cancelled.
Once the response body is finished, the request span ends before deferred
after() callbacks. On a buffered serverless host such as Lambda, an application
can therefore flush its SDK in after(() => provider.forceFlush()). Streaming
hosts may run deferred callbacks before the body ends; use an exporter that keeps
its asynchronous delivery alive with that platform's lifecycle API. Span processors
run with the original request context, including when a stream finishes later.
Attributes include http.request.method, http.route, and the response status
when available. Outgoing fetch spans include the upstream hostname and scheme.
uf does not add query strings, credentials, cookies or request bodies to these
attributes. Exceptions can contain application data: choose filtering and
retention in the application's exporter. Configure a context manager for async
parentage and a propagator to join inbound trace headers to an upstream trace.
@uniflowed/fetch injects that propagator's headers into its outgoing requests.
For example, a Node application can install @opentelemetry/sdk-trace-base,
@opentelemetry/context-async-hooks and its chosen exporter, construct a
BasicTracerProvider with a span processor, then register it with
trace.setGlobalTracerProvider(provider) and install an
AsyncLocalStorageContextManager with context.setGlobalContextManager(...).
See OpenTelemetry's JavaScript instrumentation guide
for SDK and exporter configuration.
Browser instrumentation
app/$instrumentation.client.js runs before hydration and can export an async
register(), onError(error, { source }), and onNavigation(timing). Error sources
are error, unhandledrejection, navigation, and startup. Observers
are removed during HMR; an observer failure does not interrupt navigation.
A rejected client registration is reported as startup; its listeners are
disposed and the application still mounts or hydrates. Server registration stays
fail-closed, as described above.
Navigation timing contains kind, pathname, duration in milliseconds and
status. kind: "document" comes from the browser's Navigation Timing API;
kind: "router" measures the router's asynchronous push and replace work.
These timings do not claim to measure when every Suspense boundary paints.
The pathname excludes the query string. The browser module is separate from the
server module, so server credentials and SDKs stay out of client bundles.
Saying something
// @flow
import { logger } from "@uniflowed/server";
export async function loader({ params }: LoaderArgs) {
const order = await findOrder(params.id);
if (order == null) {
logger().warn("order not found", { orderId: params.id });
}
return order;
}
logger() is the process logger with this request's id and matched route
already on it, so a line written six levels down inside a render can be joined
to the request that caused it. The message is a constant and everything that
varies is a field — order not found with orderId=8813 is a thing you can
count, and "order 8813 not found" is a thing you can only grep.
Unlike cookies(), headers() and requestId(), it does not throw outside a
request. Those three answer about a request and have no honest answer without
one; a logger has the same answer either way, minus the id. A package whose
logging call is the one call you cannot make from a failure path has it
backwards.
The request id
// @flow
import { requestId } from "@uniflowed/server";
export default function ErrorPage() {
return <p>Something went wrong. Quote {requestId()} if you get in touch.</p>;
}
It is created when the request arrives and lives on the request context, so two requests in flight cannot see each other's — the failure a module-level variable has, and only under load.
Reading it counts as reading request state, exactly as cookies() does, so a
render that puts it in the document is a render uf will not put in the route
cache. A document holding a request id is true of exactly one request, and a
cache that stored it would tell every later visitor they were the first one.
logger() does not count: an id that reaches a log line has not made the
document personal, and a page that logs must not thereby become a page uf
refuses to cache.
uf generates the id and never takes it from the request. An X-Request-Id a
client sent can be identical on a million requests, which defeats the only thing
an id is for, and it lands in a log line.
The line a request leaves behind
Every request writes one line after its response, and the field that makes it worth keeping is the route:
11:41:15.638 info request requestId=37f84251-… method=GET path=/orders/8813 route=/orders/:id status=200 durationMs=12
A log of paths says /orders/8813 was slow. A log of routes says /orders/:id
is slow, which is the question you actually have. The route is what
@uniflowed/router matched, and it is null for a request that matched
nothing — a static asset, a 404, a request a guard refused above any route.
The query string is never in it. That is where a return path, a search term, a
signed download URL and an OAuth code and state all live, and a host writing
this line does not know which route it is logging.
The level comes from the status: error at 500 and above, warn at 400,
info otherwise — so UF_LOG_LEVEL=warn leaves exactly the requests that went
wrong.
Format and level
| Variable | Values | Default |
|---|---|---|
UF_LOG_LEVEL | debug, info, warn, error, silent | info |
UF_LOG_FORMAT | json, text | json when NODE_ENV=production, else text |
A name that is not a level falls back to info rather than to silence: a typo
in a deployment's environment must not be the reason an incident left no trace.
Output goes to console.error at every level, not only for errors. In the
process that runs uf start and uf preview, stdout is @uniflowed/vite's JSON
control channel, and console.info writes there on Node — so choosing the
stream by level would put a log line in the middle of a protocol.
Sending it somewhere else
// @flow
import { createLogger, installLogger } from "@uniflowed/server/log";
installLogger(
createLogger({
level: "info",
sink: (record) => myCollector.send(record),
}),
);
Every line uf writes goes there afterwards, including the ones written from inside a render. A deployment already has somewhere it puts logs, and a framework that could only write its own shape to its own stream is a framework the operator has to work around.
For a test, recordingLogger() hands back a logger and the array of records it
collects — the records rather than the arguments, which is where redaction and
truncation have already happened and so the half worth asserting on.
A record's time is a Temporal.Instant, read through
@uniflowed/core/temporal rather than from Date.now(). That is what makes the
timestamp something a test can pin: install a clock with setClock and the
records stamped under it say exactly what you set. durationMs on a request
line is measured with the same clock at both ends, so a manualClock you
advance by 1500 ms reports durationMs=1500. Both formats spell the instant
with three fractional digits always — Instant.toString() omits the fraction on
a whole second, and . sorts below Z, so a collector sorting the timestamp
string would put …:05Z after …:05.500Z.
What a log line may not carry
A credential. Field names that name one — accessToken, client_secret,
Set-Cookie, password and the rest — are replaced with [redacted], at every
depth, matched after normalising case, -, _ and .. It is a table of names
rather than a test of values on purpose: recognising "this looks like a JWT" is
a regular expression over untrusted input, and a heuristic that misses once has
published the token. A field called code is deliberately not redacted — it
is ECONNRESET far more often than it is an authorization code.
A second record. Every string loses its control characters and is cut to a fixed length before it is formatted. A path or a user agent is text a client chose, and a newline in one would close its own record and open a fabricated one — which is how a log becomes evidence of something that did not happen.
Where to go next
Web vitals is next: five numbers the browser already has, sent only where you say.
Edit this pagedocs/app/guide/logging/$page.mdx