github-mirror/oxynote
1
0
Fork 0
mirror of https://github.com/oxynote/oxynote.git synced 2026-10-17 02:49:18 +02:00
Code Issues Actions Packages Projects Releases Wiki Activity Graph

improve log levels

Browse Source
This commit is contained in:
swithek 2026-08-30 19:30:59 +02:00
parent 65f9c70e7e
commit cfcbdb3037
38 changed files with 975 additions and 180 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

5
CLAUDE.md
View File

@ -87,7 +87,7 @@ Strong success criteria let you loop independently. Weak criteria ("make it work
- `e2e/` — Playwright end-to-end suite (`@oxynote/e2e`, **pnpm**) plus the two docker-compose stacks it drives: the dev stack built from this repo, and the all-in-one image `docker/prod/` produces. Not shipped; it exercises the composed product through a real backend. Every file, script and make target belonging to one stack is named `dev` or `prod` — neither is the unnamed default. Details: [e2e/CLAUDE.md](e2e/CLAUDE.md).
- `scripts/` — helpers the root Makefile calls. `run-quietly.sh` runs a build step with its output held back, replaying the log only if the step fails.
- `docker/` — dev docker-compose stack, Caddyfile, `env/` (committed `*.example.env` templates; `make setup` copies them to the gitignored `*.local.env` files the compose stack reads, and `web.example.env` also to `web/.env` for the host dev server and electron builds), `demo/` (demo-data configs for mariadb/postgres).
- `docker/prod/` — the production all-in-one image: alpine-based Dockerfile (built via `make prod-build`; core comes from goreleaser), the image's Caddyfile (sibling of `docker/Caddyfile`), the TS launcher (`@oxynote/launcher`, **pnpm**) that validates the flat public `OXYNOTE_*` env, generates internal secrets, and supervises caddy + web + core + auth-realtime, plus the example compose deployment. Details: [docker/prod/CLAUDE.md](docker/prod/CLAUDE.md).
- `docker/prod/` — the production all-in-one image: alpine-based Dockerfile (built via `make prod-build`; core comes from goreleaser), the image's Caddyfile (sibling of `docker/Caddyfile`), the TS launcher (`@oxynote/launcher`, **pnpm**) that validates the flat public `OXYNOTE_*` env, generates internal secrets, and supervises caddy + web + core + auth-realtime, plus the example compose deployment and the local override `make prod-run` layers on it. Details: [docker/prod/CLAUDE.md](docker/prod/CLAUDE.md).
**One `.gitignore`, and it lives at the repository root.** Components do not carry their own — a rule for a nested directory is written with its path (`e2e/test-results/`, `web/coverage/`), so every exclusion in the repository is readable in one file. The exception is `web/packages/lezer-promql/`, which is a vendored upstream fork and keeps the ignore file it ships with.
@ -107,7 +107,8 @@ make lint # fix lint/format/type issues in web, auth-realtime, core, datage
make check-lint # the same gates, verification only
make prod-build # goreleaser core binary + the all-in-one prod image
make prod-run # run the example prod compose against the local image
make prod-run # build the image + run the example compose on :8080, with
# a mailpit on :8025 so signup mail is readable
make prod-stop # stop it
# release-only, run by .github/workflows/release.yml on a tag:
# make prod-publish RELEASE_VERSION=1.2.3 -> pushes :latest and :1.2.3

14
Makefile
View File

@ -10,6 +10,8 @@ PROD_BUILD_EXTRA ?=
COMPOSE := docker-compose -p oxynote -f docker/docker-compose.dev.yaml
E2E_DEV_COMPOSE := docker compose -f e2e/docker-compose.dev.yaml $(E2E_DEV_COMPOSE_EXTRA)
E2E_PROD_COMPOSE := docker compose -f e2e/docker-compose.prod.yaml
PROD_COMPOSE := docker compose -f docker/prod/docker-compose.example.yaml \
-f docker/prod/docker-compose.local.yaml
# a tag names the stack an image belongs to. The e2e targets override these
# to :e2e-dev and :e2e-prod so a run cannot replace the image `make start`
@ -165,14 +167,18 @@ prod-publish:
-t ghcr.io/oxynote/oxynote:$(RELEASE_VERSION) \
--push .
# the example compose against the locally built image
# build the image, then run the example deployment against it on
# http://localhost:8080 (ctrl-c stops it). The local override adds the mail
# sink the example only describes in a comment: signup requires a verified
# address, so without it the verification link is only logged. Read the
# delivered mail at http://localhost:8025.
.PHONY: prod-run
prod-run:
OXYNOTE_IMAGE_TAG=prod docker compose -f docker/prod/docker-compose.example.yaml up
prod-run: prod-build
OXYNOTE_IMAGE_TAG=$(PROD_IMAGE_TAG) $(PROD_COMPOSE) up
.PHONY: prod-stop
prod-stop:
docker compose -f docker/prod/docker-compose.example.yaml down
$(PROD_COMPOSE) down
# changedetection.io generates its API key on first boot; start it alone and
# copy the key into core.local.env before the rest of the stack (core reads

6
docker/Caddyfile
View File

@ -3,6 +3,12 @@
# upstreams differ. Change the two files together.
{
admin off # disable the admin API
# every served request is an INFO access log line, and nothing here
# reads them; warnings and errors still come through.
log {
level WARN
}
}
(common) {

7
docker/docker-compose.dev.yaml
View File

@ -112,6 +112,7 @@ services:
max-file: "3"
postgres:
image: postgres:18.6-alpine
command: ["postgres", "-c", "log_checkpoints=off"]
volumes:
- postgres_data:/var/lib/postgresql
- ./demo/postgres/init-demo-db.sh:/docker-entrypoint-initdb.d/init-demo-db.sh
@ -133,6 +134,7 @@ services:
max-file: "3"
mariadb:
image: mariadb:12.3.2-noble
command: ["--log-warnings=1"]
volumes:
- mariadb_data:/var/lib/mysql
- ./demo/mariadb/init-demo-db.sql:/docker-entrypoint-initdb.d/init-demo-db.sql
@ -161,6 +163,7 @@ services:
environment:
- MEILI_MASTER_KEY=devmasterkey
- MEILI_ENV=development
- MEILI_LOG_LEVEL=WARN
restart: unless-stopped
logging:
driver: local
@ -171,6 +174,8 @@ services:
mailpit:
container_name: mailpit
image: axllent/mailpit:v1.31.0
environment:
- MP_QUIET=true
restart: unless-stopped
logging:
driver: local
@ -181,6 +186,7 @@ services:
valkey:
container_name: valkey
image: valkey/valkey:9.1.1-alpine
command: ["valkey-server", "--loglevel", "warning"]
volumes:
- valkey_data:/data
restart: unless-stopped
@ -240,6 +246,7 @@ services:
environment:
- GF_SECURITY_ADMIN_USER=admin
- GF_SECURITY_ADMIN_PASSWORD=admin
- GF_LOG_LEVEL=error
volumes:
core_storage:

5
docker/env/auth-realtime.example.env vendored
View File

@ -15,6 +15,11 @@ OXYNOTE_AUTH_REALTIME_VALKEY_DSN=redis://valkey:6379
# the listen address as host:port; empty binds all interfaces on 8081.
OXYNOTE_AUTH_REALTIME_ADDRESS=
# observability
# the floor for everything the service writes, better-auth's and
# hocuspocus's lines included (DEBUG, INFO, WARN, ERROR); empty means INFO.
OXYNOTE_AUTH_REALTIME_LOG_LEVEL=
# public URLs (the caddy front door)
OXYNOTE_AUTH_REALTIME_BETTER_AUTH_BASE_URL=http://localhost:8080/auth-realtime
OXYNOTE_AUTH_REALTIME_BETTER_AUTH_COOKIE_DOMAIN=localhost

29
docker/prod/CLAUDE.md
View File

@ -13,7 +13,11 @@ tini. Postgres is the only required external service; valkey, an
S3-compatible store, meilisearch, SMTP and changedetection.io are optional
and external too — without a store, objects are kept on the data volume;
`docker-compose.example.yaml` is the canonical deployment and `README.md`
the operator-facing reference.
the operator-facing reference. `docker-compose.local.yaml` is not part of
either: it is the override **`make prod-run`** layers on the example to
build the image and drive it from a browser here, adding the mailpit the
example only describes in a comment — signup requires a verified address, so
without a relay the verification link is never more than a log line.
Build with **`make prod-build`** from the repository root: core's
binary must come from goreleaser (never a plain `go build`), so the target
@ -79,6 +83,29 @@ also publish `ghcr.io/oxynote/core` from the `dockers_v2` block.
`loadConfig` throws on it.
- **Crash policy: die, don't restart.** Any child exit tears the rest down
and exits the container nonzero; restarts belong to the container runtime.
- **Every line the container emits is a JSON record with a `service`
field** naming the process that wrote it — `launcher`, `core`,
`auth-realtime`, `web`, `caddy` — which is what the old `[core]`-style
tags said, in a form nothing has to parse back out of the text.
- **`service` is the only thing the launcher adds to a child's line.**
`childRecord` ([logging.ts](launcher/src/logging.ts)) merges the field
into the object a child already logged and changes nothing else: core's
and auth-realtime's `time`/`level`/`msg`, caddy's `ts` and `logger`, all
survive as their own keys. Stamping the launcher's level and timestamp on
top would report when the relay ran rather than when the event happened,
and rank a line the launcher never read. A line that is not a JSON object
— plain text, an array, a number — becomes `{msg, service}`, which is all
the launcher knows about it. `service` is written last, so the launcher's
answer wins over a child that claims a different one.
- **The launcher's own events go through pino** at a fixed info level, in
the shape core and auth-realtime emit (ISO `time`, uppercase `level`,
`msg`). They are the container's lifecycle, a dozen lines per boot, and
`OXYNOTE_LOG_LEVEL` lowers what the *services* write rather than whether
the container narrates its start. Both paths share one open stdout, so
records reach the stream in write order.
- **Each stream gets its own splitter**, since a line is only whole within
the stream it arrived on; `mute` drops what a child prints with no way to
switch it off (nitro's loopback listen banner).
- **Supply chain**: every `FROM` is pinned by digest; caddy and tini are
downloaded at pinned versions and checksum-verified. Caddy is Apache-2.0
(its LICENSE ships in the image at `/oxynote/licenses/caddy/`); the name

6
docker/prod/Caddyfile
View File

@ -4,6 +4,12 @@
# files together.
{
admin off # disable the admin API
# every served request is an INFO access log line, and nothing here
# reads them; warnings and errors still come through.
log {
level WARN
}
}
(common) {

14
docker/prod/README.md
View File

@ -14,10 +14,12 @@ cp docker/prod/docker-compose.example.yaml my-deployment.yaml
docker compose -f my-deployment.yaml up -d
```
From a repository checkout, `make prod-build && make prod-run`
builds the image locally (goreleaser builds the core binary first — a bare
`docker build` is not supported) and runs the example as-is on
`http://localhost:8080`.
From a repository checkout, `make prod-run` builds the image locally
(goreleaser builds the core binary first — a bare `docker build` is not
supported) and runs this example on `http://localhost:8080`, with
`docker-compose.local.yaml` layered on top so signup mail lands in a mailpit
at `http://localhost:8025` instead of being logged. `make prod-stop` stops
it.
The image serves plain HTTP on port **8080**. For a real domain, put a
TLS-terminating proxy in front and set `OXYNOTE_PUBLIC_URL` to the public
@ -60,7 +62,9 @@ cleanly. An incomplete group fails the boot with the missing name.
by client IP — disable it behind a proxy that hides the original IP and rate
limit there instead), `OXYNOTE_MAX_DOCUMENT_HISTORY_ENTRIES`,
`OXYNOTE_DOCUMENT_HISTORY_RETENTION` (Go duration, e.g. `2160h`),
`OXYNOTE_LOG_LEVEL` (`DEBUG`/`INFO`/`WARN`/`ERROR`),
`OXYNOTE_LOG_LEVEL` (`DEBUG`/`INFO`/`WARN`/`ERROR`; the floor for both core
and auth-realtime, `WARN` by default, so the container logs carry the
exceptions rather than the traffic),
`OXYNOTE_TERMS_OF_SERVICE_URL`, `OXYNOTE_PRIVACY_POLICY_URL`.
## Secrets and the data volume

9
docker/prod/docker-compose.example.yaml
View File

@ -4,9 +4,10 @@
# put a TLS-terminating proxy in front for a real domain (the image itself
# speaks plain HTTP on 8080).
#
# `make prod-run` from the repository root uses this file as-is
# against a locally built image (tag :dev). The full variable reference
# lives in README.md next to this file.
# `make prod-run` from the repository root builds the image and runs this
# file against it, with docker-compose.local.yaml layered on top to add the
# mail sink a browser trial needs. The full variable reference lives in
# README.md next to this file.
name: oxynote-prod
@ -45,6 +46,7 @@ services:
postgres:
image: postgres:18.6-alpine
command: ["postgres", "-c", "log_checkpoints=off"]
environment:
- POSTGRES_USER=oxynote
- POSTGRES_PASSWORD=change-me-db
@ -63,6 +65,7 @@ services:
environment:
- MEILI_ENV=production
- MEILI_MASTER_KEY=change-me-meili-key
- MEILI_LOG_LEVEL=WARN
volumes:
- meilisearch_data:/meili_data
healthcheck:

29
docker/prod/docker-compose.local.yaml Normal file
View File

@ -0,0 +1,29 @@
# what `make prod-run` layers on top of the example deployment so the image
# can be driven from a browser on this machine. It is not part of the
# deployment operators copy — docker-compose.example.yaml is that file, and
# it stays as documented.
#
# the one thing a local run cannot do without is mail: signup requires a
# verified address, so without a relay the verification link is only ever
# logged. This starts the mail sink the example already describes in a
# comment and points the image at it; the delivered mail is read at
# http://localhost:8025.
name: oxynote-prod
services:
oxynote:
environment:
- OXYNOTE_SMTP_DSN=smtp://mailpit:1025?tls=none
- OXYNOTE_EMAIL_FROM_ADDRESS=Oxynote <team@example.com>
depends_on:
mailpit:
condition: service_started
mailpit:
image: axllent/mailpit:v1.31.0
environment:
- MP_QUIET=true
ports:
- "8025:8025"
restart: unless-stopped

1
docker/prod/launcher/package.json
View File

@ -24,6 +24,7 @@
},
"dependencies": {
"@sentry/node": "^10.71.0",
"pino": "^10.3.1",
"zod": "^4.4.3"
},
"devDependencies": {

98
docker/prod/launcher/pnpm-lock.yaml
View File

@ -11,6 +11,9 @@ importers:
'@sentry/node':
specifier: ^10.71.0
version: 10.71.0(@opentelemetry/core@2.10.0(@opentelemetry/api@1.9.1))
pino:
specifier: ^10.3.1
version: 10.3.1
zod:
specifier: ^4.4.3
version: 4.4.3
@ -600,6 +603,9 @@ packages:
cpu: [x64]
os: [win32]
'@pinojs/redact@0.4.0':
resolution: {integrity: sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg==}
'@rolldown/binding-android-arm-eabi@1.2.5':
resolution: {integrity: sha512-DLe/i+l8ynIBY7XEQ191TeZvCoowIGa18R+dIV30GW7DiOtp74i/xX8hs8GUjW5ARV7VZuie3d6AumSmCwbeRA==}
engines: {node: ^20.19.0 || >=22.12.0}
@ -905,6 +911,10 @@ packages:
resolution: {integrity: sha512-LElXdjswlqjWrPpJFg1Fx4wpkOCxj1TDHlSV4PlaRxHGWko024xICaa97ZkMfs6DRKlCguiAI+rbXv5GWwXIkg==}
hasBin: true
atomic-sleep@1.0.0:
resolution: {integrity: sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==}
engines: {node: '>=8.0.0'}
balanced-match@4.0.4:
resolution: {integrity: sha512-BLrgEcRTwX2o6gGxGOCNyMvGSp35YofuYzw9h1IMTRmKqttAZZVU67bdb9Pr2vUHA8+j3i2tJfjO6C6+4myGTA==}
engines: {node: 18 || 20 || >=22}
@ -1251,6 +1261,10 @@ packages:
resolution: {integrity: sha512-4a+OsYv9UktOJKE+l1A4OufDgdRF9PifWj+tJnHURo/P+WOxpG4GzUFL9qCalmWauao6ogiG+QvnCovwPoyAWA==}
engines: {node: '>=12.20.0'}
on-exit-leak-free@2.1.2:
resolution: {integrity: sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==}
engines: {node: '>=14.0.0'}
optionator@0.9.4:
resolution: {integrity: sha512-6IpQ7mKUxRcZNLIObR0hz7lxsapSSIYNZJwXPGeF0mTVqGKFIXj1DQcMoT22S3ROcLyY/rz0PWaWZ9ayWmad9g==}
engines: {node: '>= 0.8.0'}
@ -1288,6 +1302,16 @@ packages:
resolution: {integrity: sha512-qcJu88Q2IWqJsDD529JKMdwGm/dvInW4HvQnRwiH9JtihJvzGOscDtHE3x1pBKeUOTysQ8kVmLnJ2kJu7yhcGA==}
engines: {node: '>=12'}
pino-abstract-transport@3.0.0:
resolution: {integrity: sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==}
pino-std-serializers@7.1.0:
resolution: {integrity: sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw==}
pino@10.3.1:
resolution: {integrity: sha512-r34yH/GlQpKZbU1BvFFqOjhISRo1MNx1tWYsYvmj6KIRHSPMT2+yHOEb1SG6NMvRoHRF0a07kCOox/9yakl1vg==}
hasBin: true
postcss@8.5.26:
resolution: {integrity: sha512-u82N74LFzG8ca+dD8puPnplTXoGH4fTPpVGuIbt36G3qvNlkvfD0lEAZSxaly3KX8TS/L1A1gsCEmvKmBcVbkQ==}
engines: {node: ^10 || ^12 || >=14}
@ -1301,10 +1325,23 @@ packages:
engines: {node: '>=14'}
hasBin: true
process-warning@5.1.0:
resolution: {integrity: sha512-jQSaVHsPgtyw60e1rQ/A+/ArPEj/S8pS/vFnyGa/gYFXrKk/6RuDkoqVDQ5NI5MmS01698ltlAk0NoDBNLujRw==}
punycode@2.3.1:
resolution: {integrity: sha512-vYt7UD1U9Wg6138shLtLOvdAu+8DsC/ilFtEVHcH+wydcSpNE20AfSOduf6MkRFahL5FY7X1oU7nKVZFtfq8Fg==}
engines: {node: '>=6'}
quick-format-unescaped@4.0.4:
resolution: {integrity: sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==}
real-require@0.2.0:
resolution: {integrity: sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==}
engines: {node: '>= 12.13.0'}
real-require@1.0.0:
resolution: {integrity: sha512-P4nbQYQfePJxRSmY+v/KINxVucm4NF3p3s7pJveMTtom52FR4YGltUQLB8idDXwDDWW+eYrWDFbuzUnjoWHF7g==}
require-in-the-middle@8.0.1:
resolution: {integrity: sha512-QT7FVMXfWOYFbeRBF6nu+I6tr2Tf3u0q8RIEjNob/heKY/nh7drD/k7eeMFmSQgnTtCzLDcCu/XEnpW2wk4xCQ==}
engines: {node: '>=9.3.0 || >=8.10.0 <9.0.0'}
@ -1317,6 +1354,10 @@ packages:
engines: {node: ^20.19.0 || >=22.12.0}
hasBin: true
safe-stable-stringify@2.5.0:
resolution: {integrity: sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==}
engines: {node: '>=10'}
semifies@1.0.0:
resolution: {integrity: sha512-xXR3KGeoxTNWPD4aBvL5NUpMTT7WMANr3EWnaS190QVkY52lqqcVRD7Q05UVbBhiWDGWMlJEUam9m7uFFGVScw==}
@ -1340,6 +1381,9 @@ packages:
resolution: {integrity: sha512-kCZr2V3ch9i00x8zXRhjUNVcjG9ijES5dDudkXvUVCT5QlJNQWElSJdZqyPemffHoLNUYwOcou0Fy+ojN0uHSQ==}
engines: {node: '>= 18'}
sonic-boom@4.2.1:
resolution: {integrity: sha512-w6AxtubXa2wTXAUsZMMWERrsIRAdrK0Sc+FUytWvYAhBJLyuI4llrMIC1DtlNSdI99EI86KZum2MMq3EAZlF9Q==}
source-map-js@1.2.1:
resolution: {integrity: sha512-UXWMKhLOwVKb728IUtQPXxfYU+usdybtUrK/8uGE8CQMvrhOpwvzDBwj0QhSL7MQc7vIsISBG8VQ8+IDQxpfQA==}
engines: {node: '>=0.10.0'}
@ -1348,6 +1392,10 @@ packages:
resolution: {integrity: sha512-UjgapumWlbMhkBgzT7Ykc5YXUT46F0iKu8SGXq0bcwP5dz/h0Plj6enJqjz1Zbq2l5WaqYnrVbwWOWMyF3F47g==}
engines: {node: '>=0.10.0'}
split2@4.2.0:
resolution: {integrity: sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg==}
engines: {node: '>= 10.x'}
stackback@0.0.2:
resolution: {integrity: sha512-1XMJE5fQo1jGH6Y/7ebnwPOBEkIEnT4QF32d5R1+VXdXveM0IBMJt8zfaxX1P3QhVwrYe+576+jkANtSS2mBbw==}
@ -1362,6 +1410,10 @@ packages:
resolution: {integrity: sha512-qpCAvRl9stuOHveKsn7HncJRvv501qIacKzQlO/+Lwxc9+0q2wLyv4Dfvt80/DPn2pqOBsJdDiogXGR9+OvwRw==}
engines: {node: '>=8'}
thread-stream@4.2.0:
resolution: {integrity: sha512-e2zZ96wSChazBsbENf/Pcm/4swHt2cEKQ92rhUjkL9GCKiTDJIaTBenjE/m9DXi0QBmTMDkFDdOomUy20A1tDQ==}
engines: {node: '>=20'}
tinybench@2.9.0:
resolution: {integrity: sha512-0+DUvqWMValLmha6lr4kD8iAMK1HzV0/aKnCtWb9v9641TnP/MFb7Pc2bxoxQjTXAErryXVgUOfv2YqNllqGeg==}
@ -1892,6 +1944,8 @@ snapshots:
'@oxc-resolver/binding-win32-x64-msvc@11.24.2':
optional: true
'@pinojs/redact@0.4.0': {}
'@rolldown/binding-android-arm-eabi@1.2.5':
optional: true
@ -2196,6 +2250,8 @@ snapshots:
astring@1.9.0: {}
atomic-sleep@1.0.0: {}
balanced-match@4.0.4: {}
brace-expansion@5.0.9:
@ -2531,6 +2587,8 @@ snapshots:
obug@2.1.4: {}
on-exit-leak-free@2.1.2: {}
optionator@0.9.4:
dependencies:
deep-is: 0.1.4
@ -2604,6 +2662,26 @@ snapshots:
picomatch@4.0.7: {}
pino-abstract-transport@3.0.0:
dependencies:
split2: 4.2.0
pino-std-serializers@7.1.0: {}
pino@10.3.1:
dependencies:
'@pinojs/redact': 0.4.0
atomic-sleep: 1.0.0
on-exit-leak-free: 2.1.2
pino-abstract-transport: 3.0.0
pino-std-serializers: 7.1.0
process-warning: 5.1.0
quick-format-unescaped: 4.0.4
real-require: 0.2.0
safe-stable-stringify: 2.5.0
sonic-boom: 4.2.1
thread-stream: 4.2.0
postcss@8.5.26:
dependencies:
nanoid: 3.3.18
@ -2614,8 +2692,16 @@ snapshots:
prettier@3.9.6: {}
process-warning@5.1.0: {}
punycode@2.3.1: {}
quick-format-unescaped@4.0.4: {}
real-require@0.2.0: {}
real-require@1.0.0: {}
require-in-the-middle@8.0.1:
dependencies:
debug: 4.4.3
@ -2646,6 +2732,8 @@ snapshots:
'@rolldown/binding-win32-arm64-msvc': 1.2.5
'@rolldown/binding-win32-x64-msvc': 1.2.5
safe-stable-stringify@2.5.0: {}
semifies@1.0.0: {}
semver@7.8.5: {}
@ -2660,10 +2748,16 @@ snapshots:
smol-toml@1.8.0: {}
sonic-boom@4.2.1:
dependencies:
atomic-sleep: 1.0.0
source-map-js@1.2.1: {}
source-map@0.6.1: {}
split2@4.2.0: {}
stackback@0.0.2: {}
std-env@4.2.0: {}
@ -2674,6 +2768,10 @@ snapshots:
dependencies:
has-flag: 4.0.0
thread-stream@4.2.0:
dependencies:
real-require: 1.0.0
tinybench@2.9.0: {}
tinyexec@1.3.0: {}

6
docker/prod/launcher/src/env.test.ts
View File

@ -478,6 +478,12 @@ describe("loadConfig", () => {
expect(config.logLevel).toBe("DEBUG")
})
it("defaults the log level to WARN", ({ expect }) => {
const config = loadConfig(completeEnv({}))
expect(config.logLevel).toBe("WARN")
})
it.for([
{
name: "a word as a counter",

5
docker/prod/launcher/src/env.ts
View File

@ -618,7 +618,10 @@ export function loadConfig(source: Record<string, string | undefined>): Config {
values.OXYNOTE_MAX_DOCUMENT_HISTORY_ENTRIES ?? "",
documentHistoryRetention:
values.OXYNOTE_DOCUMENT_HISTORY_RETENTION ?? "",
logLevel: values.OXYNOTE_LOG_LEVEL ?? "",
// core defaults to INFO on its own, which in this image means
// every request the front door serves ends up in `docker logs`.
// An operator wants the exceptions, not the traffic.
logLevel: values.OXYNOTE_LOG_LEVEL ?? "WARN",
termsOfServiceUrl: values.OXYNOTE_TERMS_OF_SERVICE_URL ?? "",
privacyPolicyUrl: values.OXYNOTE_PRIVACY_POLICY_URL ?? "",
crashReportingDisabled: values.OXYNOTE_CRASH_REPORTING_DISABLED,

48
docker/prod/launcher/src/index.ts
View File

@ -3,9 +3,11 @@ import net from "node:net"
import os from "node:os"
import { join } from "node:path"
import * as Sentry from "@sentry/node"
import { destination } from "pino"
import { bakedLauncherSentryDsn, bakedSentryDsns } from "./baked.js"
import { loadConfig, type Config } from "./env.js"
import { checkLoopbackExposure } from "./loopback.js"
import { childRecord, createLogger } from "./logging.js"
import {
authRealtimePort,
authRealtimeUrl,
@ -43,8 +45,14 @@ const crashReporter = createCrashReporter(
// has to SIGKILL the whole container.
const shutdownDeadlineMs = 55_000
function log(line: string): void {
console.log(line)
// one open stdout for the launcher's own logger and for the children's
// relayed lines, so every record reaches the stream in write order rather
// than through two buffers.
const out = destination(1)
const log = createLogger("launcher", out)
function logChildLine(name: string, line: string): void {
out.write(`${childRecord(name, line)}\n`)
}
function sleep(ms: number): Promise<void> {
@ -110,7 +118,7 @@ async function shutdown(supervisor: Supervisor, code: number): Promise<void> {
shuttingDown = true
const deadline = setTimeout(() => {
console.error("[launcher] shutdown deadline exceeded")
log.error("shutdown deadline exceeded")
process.exit(1)
}, shutdownDeadlineMs)
@ -123,8 +131,8 @@ async function shutdown(supervisor: Supervisor, code: number): Promise<void> {
function logEnabledFeatures(config: Config): void {
const state = (enabled: boolean) => (enabled ? "on" : "off")
log(
`[launcher] search ${state(config.meilisearch !== undefined)}, ` +
log.info(
`search ${state(config.meilisearch !== undefined)}, ` +
`email ${state(config.smtp !== undefined)}, ` +
`github app ${state(config.githubApp !== undefined)}, ` +
`slack app ${state(config.slackApp !== undefined)}, ` +
@ -142,18 +150,18 @@ async function main(): Promise<void> {
})
for (const name of report.generated) {
log(`[launcher] generated secret ${name}`)
log.info(`generated secret ${name}`)
}
if (report.fromVolume.length > 0) {
log(
`[launcher] using existing secrets: ${report.fromVolume.join(", ")}`,
log.info(
`using existing secrets: ${report.fromVolume.join(", ")}`,
)
}
if (report.fromEnv.length > 0) {
log(
`[launcher] secrets provided via environment: ${report.fromEnv.join(", ")}`,
log.info(
`secrets provided via environment: ${report.fromEnv.join(", ")}`,
)
}
@ -171,10 +179,11 @@ async function main(): Promise<void> {
probe,
sleep,
log,
logChildLine,
onUnexpectedExit(name, code) {
const message = `${name} exited unexpectedly with code ${code}`
log(`[launcher] ${message}`)
log.error(message)
// the child is gone, so whatever it would have reported
// for itself is lost — an OOM kill leaves no other
// trace at all. Reporting is awaited before the
@ -226,6 +235,13 @@ async function main(): Promise<void> {
readyUrl: `${webUrl}/login`,
readyTimeoutMs: 60_000,
stopGraceMs: 10_000,
// nitro's node-server entry announces the address it
// bound with a bare console.log and offers no way to
// silence it. That address is this container's
// loopback, not the one anyone reaches the app on, so
// it is dropped here and the launcher's own "up at"
// line — the public URL — is the one left standing.
mute: /^Listening on /,
},
{
name: "caddy",
@ -264,22 +280,18 @@ async function main(): Promise<void> {
)
}
} catch (err) {
console.error(
`[launcher] ${err instanceof Error ? err.message : String(err)}`,
)
log.error(err instanceof Error ? err.message : String(err))
await crashReporter.report(err)
await supervisor.stopAll()
process.exit(1)
}
log(`[launcher] oxynote is up at ${config.publicOrigin}`)
log.info(`oxynote is up at ${config.publicOrigin}`)
logEnabledFeatures(config)
}
main().catch((err: unknown) => {
console.error(
`[launcher] ${err instanceof Error ? err.message : String(err)}`,
)
log.error(err instanceof Error ? err.message : String(err))
void crashReporter.report(err).then(() => {
process.exit(1)
})

186
docker/prod/launcher/src/logging.test.ts
View File

@ -1,61 +1,185 @@
import { describe, it, vi } from "vitest"
import { createLinePrefixer } from "./logging.js"
import { childRecord, createLineSplitter, createLogger } from "./logging.js"
describe("createLinePrefixer", () => {
it("prefixes each complete line in a chunk", ({ expect }) => {
const write = vi.fn()
const prefixer = createLinePrefixer("[core]", write)
// a destination that keeps what pino wrote, parsed back into records.
function capture() {
const lines: string[] = []
prefixer.data("first\nsecond\n")
return {
destination: {
write(chunk: string) {
lines.push(chunk)
},
},
records: () =>
lines.map(
(line) =>
JSON.parse(line) as Record<
string,
unknown
>,
),
}
}
expect(write.mock.calls).toEqual([
["[core] first"],
["[core] second"],
describe("createLogger", () => {
it("stamps every line with the service it was given", ({ expect }) => {
const written = capture()
createLogger("launcher", written.destination).info(
"starting core",
)
expect(written.records()).toEqual([
{
time: expect.stringMatching(
/^\d{4}-\d{2}-\d{2}T[\d:.]+Z$/,
) as unknown,
level: "INFO",
service: "launcher",
msg: "starting core",
},
])
})
it("carries the level of each message it is given", ({ expect }) => {
const written = capture()
const log = createLogger("launcher", written.destination)
log.info("up")
log.warn("exceeded its stop grace")
log.error("exited unexpectedly")
expect(written.records().map((record) => record.level)).toEqual(
["INFO", "WARN", "ERROR"],
)
})
})
describe("childRecord", () => {
it("passes a child's own JSON through, adding only the service", ({
expect,
}) => {
const line = JSON.stringify({
time: "2026-08-30T18:40:16.987Z",
level: "WARN",
msg: "github app integration is disabled",
version: "0.0.0",
})
expect(JSON.parse(childRecord("core", line))).toEqual({
time: "2026-08-30T18:40:16.987Z",
level: "WARN",
msg: "github app integration is disabled",
version: "0.0.0",
service: "core",
})
})
it("keeps the child's own level and time rather than restamping them", ({
expect,
}) => {
const line = JSON.stringify({
level: "warn",
ts: 1788112770.5264275,
logger: "admin",
msg: "admin endpoint disabled",
})
expect(JSON.parse(childRecord("caddy", line))).toEqual({
level: "warn",
ts: 1788112770.5264275,
logger: "admin",
msg: "admin endpoint disabled",
service: "caddy",
})
})
it("names the child itself when its line claims another service", ({
expect,
}) => {
const line = JSON.stringify({ service: "elsewhere", msg: "hi" })
expect(JSON.parse(childRecord("web", line))).toEqual({
service: "web",
msg: "hi",
})
})
it.for([
{ name: "plain text", input: "listening on the socket" },
{ name: "a broken object", input: '{"msg":"unterminated' },
{ name: "an array", input: '["one","two"]' },
{ name: "a bare number", input: "42" },
])("carries $name as the message", ({ input }, { expect }) => {
expect(JSON.parse(childRecord("web", input))).toEqual({
msg: input,
service: "web",
})
})
})
describe("createLineSplitter", () => {
it("emits each complete line in a chunk", ({ expect }) => {
const emit = vi.fn()
const splitter = createLineSplitter(emit)
splitter.data("first\nsecond\n")
expect(emit.mock.calls).toEqual([["first"], ["second"]])
})
it("holds a trailing fragment until its newline arrives", ({
expect,
}) => {
const write = vi.fn()
const prefixer = createLinePrefixer("[web]", write)
const emit = vi.fn()
const splitter = createLineSplitter(emit)
prefixer.data("par")
expect(write).toHaveBeenCalledTimes(0)
splitter.data("par")
expect(emit).toHaveBeenCalledTimes(0)
prefixer.data("tial\nrest")
splitter.data("tial\nrest")
expect(write.mock.calls).toEqual([["[web] partial"]])
expect(emit.mock.calls).toEqual([["partial"]])
})
it("drops the lines mute matches and keeps the rest", ({ expect }) => {
const emit = vi.fn()
const splitter = createLineSplitter(emit, /^Listening on /)
splitter.data("Listening on http://127.0.0.1:3000\nserving\n")
splitter.data("Listening on http://127.0.0.1:3000")
splitter.end()
expect(emit.mock.calls).toEqual([["serving"]])
})
it("flushes the held fragment at stream end", ({ expect }) => {
const write = vi.fn()
const prefixer = createLinePrefixer("[auth-realtime]", write)
const emit = vi.fn()
const splitter = createLineSplitter(emit)
prefixer.data("no newline")
prefixer.end()
splitter.data("no newline")
splitter.end()
expect(write.mock.calls).toEqual([
["[auth-realtime] no newline"],
])
expect(emit.mock.calls).toEqual([["no newline"]])
})
it("ends quietly when nothing is buffered", ({ expect }) => {
const write = vi.fn()
const prefixer = createLinePrefixer("[caddy]", write)
const emit = vi.fn()
const splitter = createLineSplitter(emit)
prefixer.data("done\n")
prefixer.end()
splitter.data("done\n")
splitter.end()
expect(write).toHaveBeenCalledTimes(1)
expect(emit).toHaveBeenCalledTimes(1)
})
it("reads buffer chunks the way streams deliver them", ({ expect }) => {
const write = vi.fn()
const prefixer = createLinePrefixer("[core]", write)
const emit = vi.fn()
const splitter = createLineSplitter(emit)
prefixer.data(Buffer.from("from a buffer\n"))
splitter.data(Buffer.from("from a buffer\n"))
expect(write.mock.calls).toEqual([["[core] from a buffer"]])
expect(emit.mock.calls).toEqual([["from a buffer"]])
})
})

110
docker/prod/launcher/src/logging.ts
View File

@ -1,20 +1,104 @@
export interface LinePrefixer {
import { pino, type DestinationStream } from "pino"
// what the launcher logs its own events through: a message at one of three
// levels.
export interface Logger {
info(message: string): void
warn(message: string): void
error(message: string): void
}
// createLogger builds the pino instance the launcher's own events go
// through, in the shape core and auth-realtime emit: an ISO timestamp, an
// uppercase level, the message under "msg", and the service field every
// record in the container stream carries. A child's output does not go
// through it — see childRecord, which adds that one field and touches
// nothing else.
//
// the level is fixed at info: the launcher's lines are the container's own
// lifecycle, a dozen per boot, and the "up at" line among them is the one an
// operator waits for — OXYNOTE_LOG_LEVEL lowers what the services
// themselves write, not whether the container narrates its start.
export function createLogger(
service: string,
destination: DestinationStream,
): Logger {
return pino(
{
level: "info",
base: { service },
timestamp: pino.stdTimeFunctions.isoTime,
formatters: {
level: (label) => ({
level: label.toUpperCase(),
}),
},
},
destination,
)
}
// childRecord renders one line of a child's output as one JSON record.
//
// a child that already logs JSON gets its object through as it wrote it,
// with one field added: service, naming the process the line came from. Its
// own level, time and fields are the ones that mean anything — stamping the
// launcher's on top would report when the relay ran rather than when the
// event happened, and rank a line the launcher never read. Anything else —
// a plain-text line, a JSON array, a bare number — becomes the msg of a
// record carrying only what the launcher does know: which child, and what
// it said.
//
// service is written last so it wins outright: the launcher is the one
// thing that knows for certain which process produced the line.
export function childRecord(service: string, line: string): string {
return JSON.stringify({ ...(asObject(line) ?? { msg: line }), service })
}
// asObject answers with the line's own fields when it is a JSON object, and
// undefined for everything else. Only an object can open with a brace, so
// the guard settles both questions at once: what it lets through parses to
// an object or not at all, and the try stays off every plain-text line a
// child writes — an array or a bare number never reaches it.
function asObject(line: string): Record<string, unknown> | undefined {
if (!line.startsWith("{")) {
return undefined
}
try {
return JSON.parse(line) as Record<string, unknown>
} catch {
return undefined
}
}
export interface LineSplitter {
data(chunk: Buffer | string): void
end(): void
}
// createLinePrefixer buffers a child's raw output chunks and emits complete
// lines tagged with the child's name, so the four processes' logs stay
// tellable apart in the single container stream. A trailing fragment is
// held until its newline arrives and flushed at stream end, which keeps the
// last line of a crashing child — usually the one that matters — from
// being lost.
export function createLinePrefixer(
prefix: string,
write: (line: string) => void,
): LinePrefixer {
// createLineSplitter buffers a child's raw output chunks and hands over
// complete lines, so each becomes one log record rather than whatever
// happened to arrive in one read. A trailing fragment is held until its
// newline arrives and flushed at stream end, which keeps the last line of a
// crashing child — usually the one that matters — from being lost.
//
// mute drops the lines it matches. It is for output a child gives no way to
// switch off — see the web spec in index.ts.
export function createLineSplitter(
emit: (line: string) => void,
mute?: RegExp,
): LineSplitter {
let buffer = ""
function take(line: string): void {
if (mute?.test(line)) {
return
}
emit(line)
}
return {
data(chunk) {
buffer += chunk.toString()
@ -26,7 +110,7 @@ export function createLinePrefixer(
break
}
write(`${prefix} ${buffer.slice(0, newline)}`)
take(buffer.slice(0, newline))
buffer = buffer.slice(newline + 1)
}
},
@ -36,7 +120,7 @@ export function createLinePrefixer(
return
}
write(`${prefix} ${buffer}`)
take(buffer)
buffer = ""
},
}

9
docker/prod/launcher/src/mapping.test.ts
View File

@ -145,6 +145,15 @@ describe("buildChildEnvs", () => {
})
})
it("gives core and auth-realtime the same log level", ({ expect }) => {
const envs = build(testConfig({ logLevel: "DEBUG" }))
expect(envs.core.OXYNOTE_CORE_LOG_LEVEL).toBe("DEBUG")
expect(envs.authRealtime.OXYNOTE_AUTH_REALTIME_LOG_LEVEL).toBe(
"DEBUG",
)
})
it("hands each secret only to the component that needs it", ({
expect,
}) => {

1
docker/prod/launcher/src/mapping.ts
View File

@ -177,6 +177,7 @@ export function buildChildEnvs(
config.maxOrganizationMembers,
OXYNOTE_AUTH_REALTIME_RATE_LIMIT_DISABLED:
config.rateLimitDisabled ? "true" : "false",
OXYNOTE_AUTH_REALTIME_LOG_LEVEL: config.logLevel,
OXYNOTE_AUTH_REALTIME_BETTER_AUTH_GITHUB_CLIENT_ID:
config.socialLogin.github?.clientId ?? "",
OXYNOTE_AUTH_REALTIME_BETTER_AUTH_GITHUB_CLIENT_SECRET:

42
docker/prod/launcher/src/supervisor.test.ts
View File

@ -74,7 +74,12 @@ function harness(childOptions: { exitOnTerm?: boolean } = {}) {
const probe = vi
.fn<(url: string) => Promise<boolean>>()
.mockResolvedValue(true)
const log = vi.fn<(line: string) => void>()
const log = {
info: vi.fn<(message: string) => void>(),
warn: vi.fn<(message: string) => void>(),
error: vi.fn<(message: string) => void>(),
}
const logChildLine = vi.fn<(name: string, line: string) => void>()
const onUnexpectedExit = vi.fn<(name: string, code: number) => void>()
const supervisor = createSupervisor({
@ -82,10 +87,19 @@ function harness(childOptions: { exitOnTerm?: boolean } = {}) {
probe,
sleep: () => Promise.resolve(),
log,
logChildLine,
onUnexpectedExit,
})
return { children, spawn, probe, log, onUnexpectedExit, supervisor }
return {
children,
spawn,
probe,
log,
logChildLine,
onUnexpectedExit,
supervisor,
}
}
describe("createSupervisor", () => {
@ -121,9 +135,7 @@ describe("createSupervisor", () => {
expect(h.probe).toHaveBeenCalledWith(
"http://127.0.0.1:1/core",
)
expect(h.log).toHaveBeenCalledWith(
"[launcher] core is ready",
)
expect(h.log.info).toHaveBeenCalledWith("core is ready")
})
it("gives up when the child never becomes ready", async ({
@ -161,7 +173,7 @@ describe("createSupervisor", () => {
)
})
it("tags the child's output with its name", async ({
it("logs the child's output under the child's own name", async ({
expect,
}) => {
const h = harness()
@ -171,8 +183,10 @@ describe("createSupervisor", () => {
h.children[0]?.stdout.emit("data", "hello\n")
h.children[0]?.stderr.emit("data", "oops\n")
expect(h.log).toHaveBeenCalledWith("[core] hello")
expect(h.log).toHaveBeenCalledWith("[core] oops")
expect(h.logChildLine.mock.calls).toEqual([
["core", "hello"],
["core", "oops"],
])
})
it("reports an exit after readiness as unexpected", async ({
@ -219,13 +233,15 @@ describe("createSupervisor", () => {
await h.supervisor.stopAll()
const stops = h.log.mock.calls
.map(([line]) => line)
.filter((line) => line.includes("stopping"))
const stops = h.log.info.mock.calls
.map(([message]) => message)
.filter((message) =>
message.includes("stopping"),
)
expect(stops).toEqual([
"[launcher] stopping caddy",
"[launcher] stopping core",
"stopping caddy",
"stopping core",
])
expect(h.children[0]?.kill).toHaveBeenCalledWith(
"SIGTERM",

39
docker/prod/launcher/src/supervisor.ts
View File

@ -1,5 +1,5 @@
import type { ChildProcess } from "node:child_process"
import { createLinePrefixer } from "./logging.js"
import { createLineSplitter, type Logger } from "./logging.js"
export interface ChildSpec {
name: string
@ -14,6 +14,9 @@ export interface ChildSpec {
readyTimeoutMs: number
// how long a SIGTERM'd child may drain before SIGKILL.
stopGraceMs: number
// output lines to drop, for what a child prints with no way to turn
// it off.
mute?: RegExp
}
export interface SupervisorDeps {
@ -25,7 +28,10 @@ export interface SupervisorDeps {
// answers whether a GET to the URL returned 200.
probe(url: string): Promise<boolean>
sleep(ms: number): Promise<void>
log(line: string): void
// the supervisor's own events.
log: Logger
// relays one line a child wrote, under that child's name.
logChildLine(name: string, line: string): void
// called when a child exits outside an initiated shutdown.
onUnexpectedExit(name: string, code: number): void
}
@ -52,24 +58,23 @@ export function createSupervisor(deps: SupervisorDeps): Supervisor {
const children: Child[] = []
let stopping = false
function attachOutput(name: string, child: ChildProcess): void {
function attachOutput(spec: ChildSpec, child: ChildProcess): void {
// a splitter per stream, never one shared: a line is only ever
// whole within the stream it arrived on.
for (const stream of [child.stdout, child.stderr]) {
if (!stream) {
continue
}
const prefixer = createLinePrefixer(
`[${name}]`,
(line) => {
deps.log(line)
},
)
const splitter = createLineSplitter((line) => {
deps.logChildLine(spec.name, line)
}, spec.mute)
stream.on("data", (chunk: Buffer) => {
prefixer.data(chunk)
splitter.data(chunk)
})
stream.on("close", () => {
prefixer.end()
splitter.end()
})
}
}
@ -102,11 +107,11 @@ export function createSupervisor(deps: SupervisorDeps): Supervisor {
}
async function start(spec: ChildSpec): Promise<void> {
deps.log(`[launcher] starting ${spec.name}`)
deps.log.info(`starting ${spec.name}`)
const process = deps.spawn(spec.command, spec.args, spec.env)
attachOutput(spec.name, process)
attachOutput(spec, process)
const exited = new Promise<number>((resolve) => {
process.once("exit", (code, signal) => {
@ -128,7 +133,7 @@ export function createSupervisor(deps: SupervisorDeps): Supervisor {
await waitReady(child)
deps.log(`[launcher] ${spec.name} is ready`)
deps.log.info(`${spec.name} is ready`)
}
async function stopAll(): Promise<void> {
@ -139,7 +144,7 @@ export function createSupervisor(deps: SupervisorDeps): Supervisor {
continue
}
deps.log(`[launcher] stopping ${child.spec.name}`)
deps.log.info(`stopping ${child.spec.name}`)
child.process.kill("SIGTERM")
const graceful = await Promise.race([
@ -153,8 +158,8 @@ export function createSupervisor(deps: SupervisorDeps): Supervisor {
continue
}
deps.log(
`[launcher] ${child.spec.name} exceeded its stop grace, killing`,
deps.log.warn(
`${child.spec.name} exceeded its stop grace, killing`,
)
child.process.kill("SIGKILL")

2
docker/prod/launcher/src/test-helpers.ts
View File

@ -62,7 +62,7 @@ export function testConfig(overrides: Partial<Config> = {}): Config {
rateLimitDisabled: false,
maxDocumentHistoryEntries: "",
documentHistoryRetention: "",
logLevel: "",
logLevel: "WARN",
termsOfServiceUrl: "",
privacyPolicyUrl: "",
crashReportingDisabled: false,

4
e2e/docker-compose.dev.yaml
View File

@ -133,6 +133,7 @@ services:
postgres:
image: postgres:18.6-alpine
command: ["postgres", "-c", "log_checkpoints=off"]
environment:
POSTGRES_USER: devuser
POSTGRES_PASSWORD: devpass
@ -148,6 +149,7 @@ services:
environment:
- MEILI_MASTER_KEY=devmasterkey
- MEILI_ENV=development
- MEILI_LOG_LEVEL=WARN
healthcheck:
test: ["CMD", "curl", "--fail", "http://localhost:7700/health"]
interval: 5s
@ -158,5 +160,7 @@ services:
# http port is published rather than proxied through caddy.
mailpit:
image: axllent/mailpit:v1.31.0
environment:
- MP_QUIET=true
ports:
- "18025:8025"

4
e2e/docker-compose.prod.yaml
View File

@ -79,6 +79,7 @@ services:
postgres:
image: postgres:18.6-alpine
command: ["postgres", "-c", "log_checkpoints=off"]
environment:
POSTGRES_USER: devuser
POSTGRES_PASSWORD: devpass
@ -94,6 +95,7 @@ services:
environment:
- MEILI_MASTER_KEY=devmasterkey
- MEILI_ENV=development
- MEILI_LOG_LEVEL=WARN
healthcheck:
test: ["CMD", "curl", "--fail", "http://localhost:7700/health"]
interval: 5s
@ -105,5 +107,7 @@ services:
# which routes nothing but the product.
mailpit:
image: axllent/mailpit:v1.31.0
environment:
- MP_QUIET=true
ports:
- "19025:8025"

32
server/auth-realtime/CLAUDE.md
View File

@ -57,6 +57,8 @@ src/
interface
reporting.ts reported() / bestEffort(), the two ways a failure reaches
sentry
logging.ts createLogger(level, destination): the pino logger
everything the service writes goes through
headers.ts normalizing whatever shape a transport hands over
auth.ts createAuth(deps) + the callbacks better-auth invokes
hocuspocus.ts createHocuspocus(deps) / createDocumentHooks(deps)
@ -98,6 +100,32 @@ Rules that follow, and that a change must not erode:
seeded, closing a direct connection). A `catch` that also builds a response
stays written out, because neither helper can express that.
**Every line the service writes goes through
[logging.ts](src/logging.ts)**, which is **pino**, at the level
`OXYNOTE_AUTH_REALTIME_LOG_LEVEL` sets (`DEBUG`/`INFO`/`WARN`/`ERROR`, INFO
by default — the production image lowers it to WARN). It is configured to
emit what core's slog handler emits — an ISO `time`, an uppercase `level`,
the message under `msg`, and pino's default `pid`/`hostname` base dropped —
so a deployment's two services produce one log format rather than two.
That includes the two libraries that would otherwise print on their own
terms: better-auth is given the matching level and a `log` callback, and
hocuspocus's Logger extension is routed to DEBUG, since a line per
connection, load, change and persist is a trace of the traffic rather than
something an operator needs.
`createLogger` takes its destination as an argument because writing to
stdout is a side effect, so the sink belongs to `index.ts` like every other
one — it passes pino's `destination(1)`, and a test passes a stream it reads
back. `Logger` stays a four-method interface rather than pino's own type:
the service logs messages at levels and nothing more, and a narrow port is
what lets a suite hand over four `vi.fn()`s.
**Nothing logs an address or a port.** The listen line says `listening` and
no more: inside a container the bound port is not the one anything reaches
the service on, so printing it only invites a wrong guess. Core's listen log
says the same thing for the same reason.
`src/sentry.ts` is the exception: node loads it through `--import` before the
app graph exists, so it reads `process.env` directly and must not import
anything of ours. Sentry's own docs call this file `instrument.js` — the name
@ -127,7 +155,9 @@ the same policy core applies to its own env — so nothing surfaces later as an
what makes a required variable report as missing rather than empty.
Adding a variable means adding it to the schema, to the `Env` interface, and
to `docker/env/auth-realtime.example.env`.
to `docker/env/auth-realtime.example.env`. One reaching the production image
also needs a line in the launcher's `mapping.ts`, which is where the public
`OXYNOTE_*` namespace is translated into each component's own.
## Formatting & TS

1
server/auth-realtime/package.json
View File

@ -57,6 +57,7 @@
"lowlight": "^3.3.0",
"nanoid": "^6.0.1",
"pg": "^8.23.0",
"pino": "^10.3.1",
"redis": "^6.2.1",
"yjs": "^13.6.32",
"zod": "^4.4.3"

92
server/auth-realtime/pnpm-lock.yaml
View File

@ -109,6 +109,9 @@ importers:
pg:
specifier: ^8.23.0
version: 8.23.0
pino:
specifier: ^10.3.1
version: 10.3.1
redis:
specifier: ^6.2.1
version: 6.2.1(@opentelemetry/api@1.9.1)
@ -1026,6 +1029,9 @@ packages:
cpu: [x64]
os: [win32]
'@pinojs/redact@0.4.0':
resolution: {integrity: sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg==}
'@redis/bloom@6.2.1':
resolution: {integrity: sha512-huQgNLaCIZfQ9SeLn4q9124uOUd8HbZDYHwwUzNcRgHqCHiHKl2dDxMqJCeWh8cMqZAoWuHR8XnWbDMIf+o7ag==}
engines: {node: '>= 20.0.0'}
@ -1571,6 +1577,10 @@ packages:
asynckit@0.4.0:
resolution: {integrity: sha512-Oei9OH4tRh0YqU3GxhX79dM/mwVgvbZJaSNaRk+bshkj0S5cfHcgYakreBjrHwatXKbz+IoIdYLxrKim2MjW0Q==}
atomic-sleep@1.0.0:
resolution: {integrity: sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==}
engines: {node: '>=8.0.0'}
axios@1.19.0:
resolution: {integrity: sha512-ht/iuYZXEjFxLH/Hkezgd7m6JKlHHXEUSneaDz8uZe1Gj5QZtCnpyDsckvAiEnT89OEbCLmnte4R4sn7P0EKFw==}
@ -2151,6 +2161,10 @@ packages:
resolution: {integrity: sha512-4a+OsYv9UktOJKE+l1A4OufDgdRF9PifWj+tJnHURo/P+WOxpG4GzUFL9qCalmWauao6ogiG+QvnCovwPoyAWA==}
engines: {node: '>=12.20.0'}
on-exit-leak-free@2.1.2:
resolution: {integrity: sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==}
engines: {node: '>=14.0.0'}
optionator@0.9.4:
resolution: {integrity: sha512-6IpQ7mKUxRcZNLIObR0hz7lxsapSSIYNZJwXPGeF0mTVqGKFIXj1DQcMoT22S3ROcLyY/rz0PWaWZ9ayWmad9g==}
engines: {node: '>= 0.8.0'}
@ -2228,6 +2242,16 @@ packages:
resolution: {integrity: sha512-RvwwcruNjI1ncT5xRakeyS9Lf8lcItv34KD+aif+VH9kduAyfYBipGh12274xtenIPZ119/R9BdTBa8gAwSh0A==}
engines: {node: '>=12'}
pino-abstract-transport@3.0.0:
resolution: {integrity: sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==}
pino-std-serializers@7.1.0:
resolution: {integrity: sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw==}
pino@10.3.1:
resolution: {integrity: sha512-r34yH/GlQpKZbU1BvFFqOjhISRo1MNx1tWYsYvmj6KIRHSPMT2+yHOEb1SG6NMvRoHRF0a07kCOox/9yakl1vg==}
hasBin: true
postcss@8.5.26:
resolution: {integrity: sha512-u82N74LFzG8ca+dD8puPnplTXoGH4fTPpVGuIbt36G3qvNlkvfD0lEAZSxaly3KX8TS/L1A1gsCEmvKmBcVbkQ==}
engines: {node: ^10 || ^12 || >=14}
@ -2257,6 +2281,9 @@ packages:
engines: {node: '>=14'}
hasBin: true
process-warning@5.1.0:
resolution: {integrity: sha512-jQSaVHsPgtyw60e1rQ/A+/ArPEj/S8pS/vFnyGa/gYFXrKk/6RuDkoqVDQ5NI5MmS01698ltlAk0NoDBNLujRw==}
prosemirror-changeset@2.4.2:
resolution: {integrity: sha512-ViYrjMSg3YFiXwIhKaluu+/mi3Yrxt6AR8ri14ulTaGcZtXO1CThl7A2gv79qx5fQnOw8woKwyBU2u+9PVCm3w==}
@ -2304,6 +2331,16 @@ packages:
resolution: {integrity: sha512-vYt7UD1U9Wg6138shLtLOvdAu+8DsC/ilFtEVHcH+wydcSpNE20AfSOduf6MkRFahL5FY7X1oU7nKVZFtfq8Fg==}
engines: {node: '>=6'}
quick-format-unescaped@4.0.4:
resolution: {integrity: sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==}
real-require@0.2.0:
resolution: {integrity: sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==}
engines: {node: '>= 12.13.0'}
real-require@1.0.0:
resolution: {integrity: sha512-P4nbQYQfePJxRSmY+v/KINxVucm4NF3p3s7pJveMTtom52FR4YGltUQLB8idDXwDDWW+eYrWDFbuzUnjoWHF7g==}
redis@6.2.1:
resolution: {integrity: sha512-Z9VHtgYs48PiQC77X9O2Er8Hj4T+5BtFjT91/vi5Is1D04N72cA946ZslM1ImJw8ZctFBZWAVjM7S5wJNeHMpg==}
engines: {node: '>= 20.0.0'}
@ -2326,6 +2363,10 @@ packages:
rou3@0.9.2:
resolution: {integrity: sha512-3SOzvaAg8rkHrXtRjpCvCvbyO5to9oOO27Z/XqHEYXfMRVSw/qMIVdmaOk9W2lcRLtR6dlqTjo9hDeJk70QBYQ==}
safe-stable-stringify@2.5.0:
resolution: {integrity: sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==}
engines: {node: '>=10'}
semifies@1.0.0:
resolution: {integrity: sha512-xXR3KGeoxTNWPD4aBvL5NUpMTT7WMANr3EWnaS190QVkY52lqqcVRD7Q05UVbBhiWDGWMlJEUam9m7uFFGVScw==}
@ -2357,6 +2398,9 @@ packages:
resolution: {integrity: sha512-kCZr2V3ch9i00x8zXRhjUNVcjG9ijES5dDudkXvUVCT5QlJNQWElSJdZqyPemffHoLNUYwOcou0Fy+ojN0uHSQ==}
engines: {node: '>= 18'}
sonic-boom@4.2.1:
resolution: {integrity: sha512-w6AxtubXa2wTXAUsZMMWERrsIRAdrK0Sc+FUytWvYAhBJLyuI4llrMIC1DtlNSdI99EI86KZum2MMq3EAZlF9Q==}
source-map-js@1.2.1:
resolution: {integrity: sha512-UXWMKhLOwVKb728IUtQPXxfYU+usdybtUrK/8uGE8CQMvrhOpwvzDBwj0QhSL7MQc7vIsISBG8VQ8+IDQxpfQA==}
engines: {node: '>=0.10.0'}
@ -2383,6 +2427,10 @@ packages:
resolution: {integrity: sha512-qpCAvRl9stuOHveKsn7HncJRvv501qIacKzQlO/+Lwxc9+0q2wLyv4Dfvt80/DPn2pqOBsJdDiogXGR9+OvwRw==}
engines: {node: '>=8'}
thread-stream@4.2.0:
resolution: {integrity: sha512-e2zZ96wSChazBsbENf/Pcm/4swHt2cEKQ92rhUjkL9GCKiTDJIaTBenjE/m9DXi0QBmTMDkFDdOomUy20A1tDQ==}
engines: {node: '>=20'}
tinybench@2.9.0:
resolution: {integrity: sha512-0+DUvqWMValLmha6lr4kD8iAMK1HzV0/aKnCtWb9v9641TnP/MFb7Pc2bxoxQjTXAErryXVgUOfv2YqNllqGeg==}
@ -3175,6 +3223,8 @@ snapshots:
'@oxc-resolver/binding-win32-x64-msvc@11.24.2':
optional: true
'@pinojs/redact@0.4.0': {}
'@redis/bloom@6.2.1(@redis/client@6.2.1(@opentelemetry/api@1.9.1))':
dependencies:
'@redis/client': 6.2.1(@opentelemetry/api@1.9.1)
@ -3740,6 +3790,8 @@ snapshots:
asynckit@0.4.0: {}
atomic-sleep@1.0.0: {}
axios@1.19.0:
dependencies:
follow-redirects: 1.16.0
@ -4282,6 +4334,8 @@ snapshots:
obug@2.1.4: {}
on-exit-leak-free@2.1.2: {}
optionator@0.9.4:
dependencies:
deep-is: 0.1.4
@ -4394,6 +4448,26 @@ snapshots:
picomatch@4.0.5: {}
pino-abstract-transport@3.0.0:
dependencies:
split2: 4.2.0
pino-std-serializers@7.1.0: {}
pino@10.3.1:
dependencies:
'@pinojs/redact': 0.4.0
atomic-sleep: 1.0.0
on-exit-leak-free: 2.1.2
pino-abstract-transport: 3.0.0
pino-std-serializers: 7.1.0
process-warning: 5.1.0
quick-format-unescaped: 4.0.4
real-require: 0.2.0
safe-stable-stringify: 2.5.0
sonic-boom: 4.2.1
thread-stream: 4.2.0
postcss@8.5.26:
dependencies:
nanoid: 3.3.18
@ -4414,6 +4488,8 @@ snapshots:
prettier@3.9.6: {}
process-warning@5.1.0: {}
prosemirror-changeset@2.4.2:
dependencies:
prosemirror-transform: 1.12.0
@ -4492,6 +4568,12 @@ snapshots:
punycode@2.3.1: {}
quick-format-unescaped@4.0.4: {}
real-require@0.2.0: {}
real-require@1.0.0: {}
redis@6.2.1(@opentelemetry/api@1.9.1):
dependencies:
'@redis/bloom': 6.2.1(@redis/client@6.2.1(@opentelemetry/api@1.9.1))
@ -4537,6 +4619,8 @@ snapshots:
rou3@0.9.2: {}
safe-stable-stringify@2.5.0: {}
semifies@1.0.0: {}
semver@7.7.2: {}
@ -4555,6 +4639,10 @@ snapshots:
smol-toml@1.8.0: {}
sonic-boom@4.2.1:
dependencies:
atomic-sleep: 1.0.0
source-map-js@1.2.1: {}
source-map@0.6.1: {}
@ -4571,6 +4659,10 @@ snapshots:
dependencies:
has-flag: 4.0.0
thread-stream@4.2.0:
dependencies:
real-require: 1.0.0
tinybench@2.9.0: {}
tinyexec@1.3.0: {}

35
server/auth-realtime/src/auth.test.ts
View File

@ -11,7 +11,13 @@ import {
type SecondaryStorageClient,
} from "./auth.js"
import { createDatabase, type Store } from "./db.js"
import { stubCore, stubStore, testEnv, type StubCore } from "./test-helpers.js"
import {
stubCore,
stubLog,
stubStore,
testEnv,
type StubCore,
} from "./test-helpers.js"
function stubRedis() {
return {
@ -42,15 +48,17 @@ function buildAuth(
) {
const real = createDatabase("postgresql://u:p@localhost/d")
const core = overrides.core ?? stubCore()
const log = stubLog()
const auth = createAuth({
env: overrides.env ?? testEnv(),
store: overrides.store ?? stubStore(),
dialect: real.dialect,
redis: overrides.redis ?? stubRedis(),
core,
log,
})
return { auth, core }
return { auth, core, log }
}
describe("authMethods", () => {
@ -431,6 +439,28 @@ describe("createAuth", () => {
expect(auth.options.basePath).toBe("/api/auth")
})
it("takes better-auth's level from the configured one", ({
expect,
}) => {
const { auth } = buildAuth({
env: testEnv({ logLevel: "ERROR" }),
})
expect(auth.options.logger.level).toBe("error")
})
it("writes better-auth's own output through the service logger", ({
expect,
}) => {
const { auth, log } = buildAuth()
auth.options.logger.log("warn", "trusted origin missing")
expect(log.warn.mock.calls).toEqual([
["better-auth: trusted origin missing"],
])
})
it("keeps secondary storage when a redis client is given", ({
expect,
}) => {
@ -454,6 +484,7 @@ describe("createAuth", () => {
store: stubStore(),
dialect: real.dialect,
core: stubCore(),
log: stubLog(),
})
expect(auth.options.secondaryStorage).toBeUndefined()

31
server/auth-realtime/src/auth.ts
View File

@ -7,6 +7,7 @@ import type { PostgresDialect } from "kysely"
import type { Store } from "./db.js"
import type { CoreClient } from "./core.js"
import type { Env, SocialProviderName } from "./env.js"
import type { Logger, LogLevel } from "./logging.js"
import { reported } from "./reporting.js"
export type AuthMethod = "email-password" | "google" | "github" | "slack"
@ -35,8 +36,20 @@ export interface AuthDeps {
// better-auth with no secondary storage.
redis?: SecondaryStorageClient
core: CoreClient
log: Logger
}
// better-auth's own level names, which are these lowercased. Passing it
// the matching one lets it drop a message before formatting it, and it
// resolves its extra "success" level to info before calling out.
const betterAuthLevels: Record<LogLevel, "debug" | "info" | "warn" | "error"> =
{
DEBUG: "debug",
INFO: "info",
WARN: "warn",
ERROR: "error",
}
// the capability list served by /api/auth-config. Derived from the same
// credentials that register the social providers, so the endpoint can
// never disagree with what better-auth actually accepts. Email-password
@ -223,7 +236,14 @@ export function createSecondaryStorage(redis: SecondaryStorageClient) {
}
}
export function createAuth({ env, store, dialect, redis, core }: AuthDeps) {
export function createAuth({
env,
store,
dialect,
redis,
core,
log,
}: AuthDeps) {
const organizationHooks = createOrganizationHooks({ env, store, core })
function socialProvider(name: SocialProviderName) {
@ -248,6 +268,15 @@ export function createAuth({ env, store, dialect, redis, core }: AuthDeps) {
// redirect URIs below).
baseURL: env.authOrigin,
basePath: "/api/auth",
// better-auth prints its own lines otherwise, on a level of
// its own; routed here they obey OXYNOTE_AUTH_REALTIME_LOG_LEVEL
// like everything else the service writes.
logger: {
level: betterAuthLevels[env.logLevel],
log: (level, message) => {
log[level](`better-auth: ${message}`)
},
},
secret: env.betterAuthSecret,
// the dialect instance alone leaves the CLI's schema generator
// unable to tell which database it is talking to (instanceof

11
server/auth-realtime/src/env.ts
View File

@ -1,5 +1,7 @@
import { z } from "zod"
import type { LogLevel } from "./logging.js"
export type SocialProviderName = "google" | "github" | "slack"
export interface SocialProviderCredentials {
@ -39,6 +41,7 @@ export interface Env {
maxOrganizations: number
maxOrganizationMembers: number
rateLimitEnabled: boolean
logLevel: LogLevel
}
// every URL here is one something dials or redirects a browser to, so the
@ -152,6 +155,13 @@ const schema = z
// does not pass the original IP through — so it can be
// switched off and left to whatever sits in front.
OXYNOTE_AUTH_REALTIME_RATE_LIMIT_DISABLED: flag(false),
// the floor for everything this service writes, better-auth's
// and hocuspocus's output included. INFO matches core's own
// default; the production image lowers both to WARN.
OXYNOTE_AUTH_REALTIME_LOG_LEVEL: z
.enum(["DEBUG", "INFO", "WARN", "ERROR"])
.optional()
.transform((value) => value ?? "INFO"),
OXYNOTE_AUTH_REALTIME_BETTER_AUTH_GOOGLE_CLIENT_ID: z
.string()
.optional(),
@ -272,5 +282,6 @@ export function loadEnv(source: Record<string, string | undefined>): Env {
values.OXYNOTE_AUTH_REALTIME_MAX_ORGANIZATION_MEMBERS,
rateLimitEnabled:
!values.OXYNOTE_AUTH_REALTIME_RATE_LIMIT_DISABLED,
logLevel: values.OXYNOTE_AUTH_REALTIME_LOG_LEVEL,
}
}

31
server/auth-realtime/src/hocuspocus.test.ts
View File

@ -8,7 +8,12 @@ import {
type AuthSession,
} from "./hocuspocus.js"
import { replaceYdocContent, transformer } from "./ydocument.js"
import { fragmentXml, stubCore, type StubCore } from "./test-helpers.js"
import {
fragmentXml,
stubCore,
stubLog,
type StubCore,
} from "./test-helpers.js"
type ConnectedDocument = Y.Doc & { broadcastStateless: Mock }
@ -677,10 +682,34 @@ describe("createDocumentHooks", () => {
})
describe("createHocuspocus", () => {
it("sends the hocuspocus logger's per-connection lines out at DEBUG", ({
expect,
}) => {
const log = stubLog()
const server = createHocuspocus({
auth: stubAuth(),
core: stubCore(),
log,
})
// the extension keeps its sink in its own configuration; the
// server exposes no other way to reach it.
const logger = server.configuration.extensions[0] as {
configuration: { log: (...args: unknown[]) => void }
}
logger.configuration.log("onStoreDocument", "doc-1")
expect(log.debug.mock.calls).toEqual([
["onStoreDocument doc-1"],
])
expect(log.info.mock.calls).toEqual([])
})
it("wires the document hooks onto the server", ({ expect }) => {
const server = createHocuspocus({
auth: stubAuth(),
core: stubCore(),
log: stubLog(),
})
expect(typeof server.configuration.onAuthenticate).toBe(

27
server/auth-realtime/src/hocuspocus.ts
View File

@ -3,6 +3,8 @@ import * as Y from "yjs"
import { nanoid } from "nanoid"
import { Hocuspocus } from "@hocuspocus/server"
import { Logger } from "@hocuspocus/extension-logger"
// aliased because the extension above already claims the name Logger.
import type { Logger as ServiceLogger } from "./logging.js"
import type { CoreClient } from "./core.js"
import { toAxiosHeaders, toHeaders } from "./headers.js"
import { bestEffort, reported } from "./reporting.js"
@ -329,9 +331,28 @@ export function createDocumentHooks({ auth, core }: DocumentHookDeps) {
}
}
export function createHocuspocus(deps: DocumentHookDeps): Hocuspocus {
export function createHocuspocus({
log,
...hooks
}: DocumentHookDeps & { log: ServiceLogger }): Hocuspocus {
return new Hocuspocus({
extensions: [new Logger()],
...createDocumentHooks(deps),
// the extension writes a line per connection, load, change and
// persist. That is a trace of the traffic rather than
// something an operator needs to see, so it goes out at DEBUG
// instead of straight to stdout.
extensions: [
new Logger({
log: (...args: unknown[]) => {
log.debug(
args
.map((arg) =>
String(arg),
)
.join(" "),
)
},
}),
],
...createDocumentHooks(hooks),
})
}

15
server/auth-realtime/src/index.ts
View File

@ -2,11 +2,13 @@ import { serve } from "@hono/node-server"
import { Hono } from "hono"
import { createNodeWebSocket } from "@hono/node-ws"
import { createClient } from "redis"
import { destination } from "pino"
import { loadEnv } from "./env.js"
import { createDatabase } from "./db.js"
import { createCoreClient } from "./core.js"
import { createAuth } from "./auth.js"
import { createHocuspocus } from "./hocuspocus.js"
import { createLogger } from "./logging.js"
import { createRoutes } from "./routes.js"
import { bestEffort } from "./reporting.js"
@ -15,6 +17,7 @@ import { bestEffort } from "./reporting.js"
// needs, which is what makes the rest of the service testable without a
// database, a redis, or a port.
const env = loadEnv(process.env)
const log = createLogger(env.logLevel, destination(1))
const database = createDatabase(env.databaseDSN)
const { store, dialect } = database
@ -34,11 +37,12 @@ if (env.valkeyDsn) {
await redis.connect()
}
const auth = createAuth({ env, store, dialect, redis, core })
const auth = createAuth({ env, store, dialect, redis, core, log })
const hocuspocus = createHocuspocus({
auth: { getSession: (input) => auth.api.getSession(input) },
core,
log,
})
const app = new Hono()
@ -111,9 +115,10 @@ const server = serve(
port: info.port,
})
console.log(
`Server is running on http://localhost:${info.port}`,
)
// deliberately without the address: this is the port inside
// the container, which is not the one anything reaches the
// service on, and printing it only invites a wrong guess.
log.info("listening")
},
)
nodeWs.injectWebSocket(server)
@ -126,7 +131,7 @@ const shutdownDeadlineMs = 15_000
// seconds, so exiting on the signal alone would drop that window of edits.
async function shutdown() {
const deadline = setTimeout(() => {
console.error("shutdown deadline exceeded")
log.error("shutdown deadline exceeded")
process.exit(1)
}, shutdownDeadlineMs)
deadline.unref()

78
server/auth-realtime/src/logging.test.ts Normal file
View File

@ -0,0 +1,78 @@
import { describe, it } from "vitest"
import { createLogger, type LogLevel } from "./logging.js"
// a destination that keeps what pino wrote, parsed back into records.
function capture() {
const lines: string[] = []
return {
destination: {
write(chunk: string) {
lines.push(chunk)
},
},
records: () =>
lines.map(
(line) =>
JSON.parse(line) as Record<
string,
unknown
>,
),
}
}
const thresholdCases: {
name: string
level: LogLevel
expected: LogLevel[]
}[] = [
{
name: "DEBUG",
level: "DEBUG",
expected: ["DEBUG", "INFO", "WARN", "ERROR"],
},
{ name: "INFO", level: "INFO", expected: ["INFO", "WARN", "ERROR"] },
{ name: "WARN", level: "WARN", expected: ["WARN", "ERROR"] },
{ name: "ERROR", level: "ERROR", expected: ["ERROR"] },
]
describe("createLogger", () => {
it.for(thresholdCases)(
"at $name emits that level and every level above it",
({ level, expected }, { expect }) => {
const written = capture()
const log = createLogger(level, written.destination)
log.debug("d")
log.info("i")
log.warn("w")
log.error("e")
expect(
written.records().map((record) => record.level),
).toEqual(expected)
},
)
it("writes core's log shape: an ISO time, an upper-case level, a msg", ({
expect,
}) => {
const written = capture()
createLogger("INFO", written.destination).warn(
"cannot reach core",
)
expect(written.records()).toEqual([
{
time: expect.stringMatching(
/^\d{4}-\d{2}-\d{2}T[\d:.]+Z$/,
) as unknown,
level: "WARN",
msg: "cannot reach core",
},
])
})
})

44
server/auth-realtime/src/logging.ts Normal file
View File

@ -0,0 +1,44 @@
import { pino, type DestinationStream } from "pino"
// the levels are core's slog levels, spelled the same way, so one
// OXYNOTE_LOG_LEVEL means the same thing on both sides of the deployment.
export type LogLevel = "DEBUG" | "INFO" | "WARN" | "ERROR"
// what the service logs through, and all it needs: a message at one of four
// levels. It is the narrow port pino satisfies, so a test takes four
// vi.fn()s rather than standing up a logger to assert against.
export interface Logger {
debug(message: string): void
info(message: string): void
warn(message: string): void
error(message: string): void
}
// createLogger builds the pino instance every line goes through, shaped to
// match what core's slog handler emits — an ISO timestamp, the level as an
// uppercase word, the message under "msg" — so one deployment's two
// services produce one log format rather than two.
//
// base is null because pino would otherwise stamp every line with a pid and
// a hostname, and neither says anything about a container running one
// process under an id docker assigned. destination is a parameter because
// writing to stdout is a side effect, and those belong to the composition
// root; a test passes a stream it can read back.
export function createLogger(
level: LogLevel,
destination: DestinationStream,
): Logger {
return pino(
{
level: level.toLowerCase(),
base: null,
timestamp: pino.stdTimeFunctions.isoTime,
formatters: {
level: (label) => ({
level: label.toUpperCase(),
}),
},
},
destination,
)
}

17
server/auth-realtime/src/test-helpers.ts
View File

@ -3,6 +3,7 @@ import type * as Y from "yjs"
import type { CoreClient } from "./core.js"
import type { Store } from "./db.js"
import type { Env } from "./env.js"
import type { Logger } from "./logging.js"
export type StubStore = {
[K in keyof Store]: Mock<Store[K]>
@ -58,6 +59,21 @@ export function stubCore(): StubCore {
}
}
export type StubLogger = {
[K in keyof Logger]: Mock<Logger[K]>
}
// a logger that records instead of writing, so a suite neither prints nor
// has to spy on the console to assert what a code path logged.
export function stubLog(): StubLogger {
return {
debug: vi.fn(),
info: vi.fn(),
warn: vi.fn(),
error: vi.fn(),
}
}
// a complete, valid configuration. Tests override only the field under
// test so an unrelated env change cannot quietly alter what they assert.
export function testEnv(overrides: Partial<Env> = {}): Env {
@ -81,6 +97,7 @@ export function testEnv(overrides: Partial<Env> = {}): Env {
maxOrganizations: 100,
maxOrganizationMembers: 5,
rateLimitEnabled: true,
logLevel: "INFO",
...overrides,
}
}

28
server/core/internal/server/server.go
View File

@ -7,8 +7,6 @@ import (
"fmt"
"log/slog"
"net/http"
"net/url"
"strings"
"sync"
"time"
@ -237,7 +235,10 @@ func NewServer(
// Listen starts listening for incoming connections.
func (s *Server) Listen() {
s.log.Info("listening", slog.String("address", s.Address()))
// deliberately without the address: it is the one inside the
// container, which is not the one anything reaches the server on, so
// logging it only invites a wrong guess.
s.log.Info("listening")
err := s.http.ListenAndServe()
if !errors.Is(err, http.ErrServerClosed) {
@ -245,27 +246,6 @@ func (s *Server) Listen() {
}
}
// Address returns the address of the server.
func (s *Server) Address() string {
host := s.http.Addr
// a host-less address binds all interfaces; localhost stands in for
// log readability.
if strings.HasPrefix(s.http.Addr, ":") {
host = "localhost"
if s.http.Addr != ":80" {
host += s.http.Addr // port can be random
}
}
addr := &url.URL{
Scheme: "http",
Host: host,
}
return addr.String()
}
// Close performs clean up operations.
func (s *Server) Close() error {
if err := s.http.Shutdown(context.Background()); err != nil {

34
server/core/internal/server/server_test.go
View File

@ -299,40 +299,6 @@ func Test_Server_Listen(t *testing.T) {
assert.NotContains(t, content2(), "cannot terminate gracefully")
}
func Test_Server_Address(t *testing.T) {
t.Parallel()
cc := map[string]struct {
Addr string
Result string
}{
"Default HTTP port is omitted": {
Addr: ":80",
Result: "http://localhost",
},
"Custom port is included": {
Addr: ":1234",
Result: "http://localhost:1234",
},
"Host-qualified address is used verbatim": {
Addr: "127.0.0.1:8180",
Result: "http://127.0.0.1:8180",
},
}
for cn, c := range cc {
t.Run(cn, func(t *testing.T) {
t.Parallel()
s := Server{
http: &http.Server{Addr: c.Addr},
}
assert.Equal(t, c.Result, s.Address())
})
}
}
func Test_Server_Close(t *testing.T) {
t.Parallel()