diff --git a/reference/analytics/overview.md b/reference/analytics/overview.md index 78f4ec2c3..dff99256e 100644 --- a/reference/analytics/overview.md +++ b/reference/analytics/overview.md @@ -133,31 +133,45 @@ Example aggregate entry: } ``` + + +Gauges that each thread reports and aggregation sums across threads (`memory`, `read-transaction-queue-depth`, `write-transaction-queue-depth`, `mqtt-connections`, and `ws-connections`) carry the aggregation `period` on their aggregate rows; before v5.4.0 it read `0`. Aggregate `memory` and queue-depth rows also no longer carry `threadId`, which held the sum of the reporting threads' ids. Raw entries keep their `threadId`. + ## Standard Metrics Harper automatically tracks the following metrics for all services. Applications can also define custom metrics via [`server.recordAnalytics()`](../http/api.md#serverrecordanalyticsvalue-metric-path-method-type). ### HTTP Metrics -| `metric` | `path` | `method` | `type` | Unit | Description | -| ------------------ | ------------- | -------------- | --------------------------- | ----- | ---------------------------------------- | -| `duration` | resource path | request method | `cache-hit` or `cache-miss` | ms | Duration of request handler | -| `duration` | route path | request method | `fastify-route` | ms | Duration of Fastify route handler | -| `duration` | operation | | `operation` | ms | Duration of Operations API operation | -| `success` | resource path | request method | | % | Percentage of successful requests | -| `success` | route path | request method | `fastify-route` | % | | -| `success` | operation | | `operation` | % | | -| `bytes-sent` | resource path | request method | | bytes | Response bytes sent | -| `bytes-sent` | route path | request method | `fastify-route` | bytes | | -| `bytes-sent` | operation | | `operation` | bytes | | -| `transfer` | resource path | request method | `operation` | ms | Duration of response transfer | -| `transfer` | route path | request method | `fastify-route` | ms | | -| `transfer` | operation | | `operation` | ms | | -| `socket-routed` | | | | % | Percentage of sockets immediately routed | -| `tls-handshake` | | | | ms | TLS handshake duration | -| `tls-reused` | | | | % | Percentage of TLS sessions reused | -| `cache-hit` | table name | | | % | Percentage of cache hits | -| `cache-resolution` | table name | | | ms | Duration of resolving uncached entries | +| `metric` | `path` | `method` | `type` | Unit | Description | +| -------------------- | ------------- | -------------- | --------------------------- | ----- | ----------------------------------------------------------------------------------------------------------------------------- | +| `duration` | resource path | request method | `cache-hit` or `cache-miss` | ms | Duration of request handler | +| `duration` | route path | request method | `fastify-route` | ms | Duration of Fastify route handler | +| `duration` | operation | | `operation` | ms | Duration of Operations API operation | +| `request-time` | resource path | request method | `cache-hit` or `cache-miss` | ms | Time from dispatch to response ready, request queue wait included (see [`request-time`](#request-time)) | +| `request-time` | route path | request method | `fastify-route` | ms | | +| `request-time` | operation | | `operation` | ms | | +| `duration-by-thread` | | | | ms | `duration` per worker thread across all its requests, in `hdb_analytics` only (see [per-thread metrics](#per-thread-metrics)) | +| `success` | resource path | request method | | % | Percentage of successful requests | +| `success` | route path | request method | `fastify-route` | % | | +| `success` | operation | | `operation` | % | | +| `bytes-sent` | resource path | request method | | bytes | Response bytes sent | +| `bytes-sent` | route path | request method | `fastify-route` | bytes | | +| `bytes-sent` | operation | | `operation` | bytes | | +| `transfer` | resource path | request method | `operation` | ms | Duration of response transfer | +| `transfer` | route path | request method | `fastify-route` | ms | | +| `transfer` | operation | | `operation` | ms | | +| `socket-routed` | | | | % | Percentage of sockets immediately routed | +| `tls-handshake` | | | | ms | TLS handshake duration | +| `tls-reused` | | | | % | Percentage of TLS sessions reused | +| `cache-hit` | table name | | | % | Percentage of cache hits | +| `cache-resolution` | table name | | | ms | Duration of resolving uncached entries | + +#### `request-time` + + + +`request-time` measures from when Harper dispatches a request to when its response is ready, before the body is sent: the handler time that `duration` records, plus any wait in the HTTP request queue that [`http.requestQueueLimit`](../http/configuration.md#httprequestqueuelimit) bounds. It is recorded only for requests that pass through that queue, which are those with a method other than `GET`, `HEAD`, and `OPTIONS`, and only when analytics is enabled as the request arrives. It does not include the TLS handshake, request parsing, or any wait for the event loop before dispatch; [`event-loop-delay`](#per-thread-metrics) covers that wait. For a request that Node's HTTP server hands to a Fastify route, it also includes the Harper request chain that ran first, such as authentication; a request the uWS backend hands to Fastify records no `request-time`. Raw entries carry `mean` and `distribution` in milliseconds and a `count` of requests, and aggregate rows add percentiles. It is not recorded on Bun. ### MQTT / WebSocket Metrics @@ -224,6 +238,21 @@ write load. However, a wedged commit contributes no sample until it settles — distribution with the server log: the "Rejecting writes on this thread" error is the authoritative signal when the guard trips. Tune the threshold against a baseline for your workload. +### Per-Thread Metrics + + + +| `metric` | Key attributes | Other | Unit | Description | +| -------------------- | --------------------------- | -------- | ---- | ------------------------------------------------------------------------------------------ | +| `event-loop-delay` | `mean`, `maxDelay`, `count` | `thread` | ms | How late the thread's event loop ran a 20 ms timer, on average and at worst | +| `duration-by-thread` | `mean`, `count` | `thread` | ms | Handler `duration` across every request one worker thread handled, in `hdb_analytics` only | + +Each row names its thread in `thread`, the thread's `worker_threads` `threadId`, which changes when a worker is replaced. In `hdb_raw_analytics` the same id is the entry's `threadId`. + +`event-loop-delay` comes from Node's [`monitorEventLoopDelay`](https://nodejs.org/api/perf_hooks.html#perf_hooksmonitoreventloopdelayoptions), which fires a timer every 20 ms. `mean` and `maxDelay` are the milliseconds by which it fired late, so an idle thread reads about 0, and `count` is the number of timer firings, not requests. A thread writes an entry only in a second in which it recorded other analytics. The measurement restarts with each report, and again when activity resumes after a quiet gap of more than a second, so a stall during that gap is not reported. A stall that begins in the same loop turn as that restart, or as a report's flush, is not measured either. It is not recorded on Bun. + +`duration-by-thread` exists only in `hdb_analytics`: aggregation combines every `duration` entry a thread recorded in the period into one row for that thread, with the total `count` and the count-weighted `mean`, and keeps no percentiles. The per-path detail for each thread stays in `hdb_raw_analytics`, whose raw entries carry their `threadId`. The `duration` rows are unchanged, so do not add the two together. + ### Resource Usage Metrics | `metric` | Key attributes | Other | Unit | Description | diff --git a/release-notes/v5-lincoln/5.4.md b/release-notes/v5-lincoln/5.4.md index ad0d66d61..6be8b2a05 100644 --- a/release-notes/v5-lincoln/5.4.md +++ b/release-notes/v5-lincoln/5.4.md @@ -63,3 +63,9 @@ The new `threads.v8Flags` setting takes a V8 flag, or a list of them, and applie ### Restore Checks a Backup Before Deleting the Database `restore_backup` no longer deletes a database before checking that the backup can be read. It first verifies the checksum of every database file in the backup, checks its transaction logs, opens each table file to confirm this version can read its format and compression, and, for a backup that captured blobs, checks that the blob snapshot is present. A backup that fails is refused and the database is left as it was (one an earlier restore left incomplete stays blocked); previously the restore deleted the database first and then failed, so a backup taken by a newer version, or one with a corrupt file, destroyed the database it was meant to restore. The check reads the whole backup once, so a restore takes longer, and an online restore keeps the database unavailable while it runs; it needs no extra disk space. A restore interrupted while it is still checking the backup leaves the destination's files and any preexisting incomplete-restore marker unchanged; a previously healthy database loads normally on the next start. Blob file contents are not checked. See [`restore_backup`](/reference/v5/backups/operations#restore_backup). + +## Analytics + +### Per-Thread Event-Loop Delay and Request Time + +Three built-in metrics are new. `event-loop-delay` reports how late each thread's event loop runs. `duration-by-thread` reports each worker thread's handler `duration` in `hdb_analytics`, one row per thread. `request-time` adds the HTTP request queue's wait to handler time for requests with a method other than `GET`, `HEAD`, and `OPTIONS`. Aggregate rows for gauges summed across threads, such as `memory`, now carry the aggregation `period` instead of `0`, and `memory` and queue-depth rows no longer carry a summed `threadId`. See [Per-Thread Metrics](/reference/v5/analytics/overview#per-thread-metrics) and [`request-time`](/reference/v5/analytics/overview#request-time).