rendered from docs/operations.md 9b5e5a6a6ba2

Operations

Procedures for the deployment terraform-aws-didbot-pds/templates/user_data.sh.tftpl builds: one instance, one systemd unit didbot-pds, one container of the release image, one data volume at /data with the data directory at /data/pds.

Question Command
Is the unit up systemctl status didbot-pds
What did it say journalctl -u didbot-pds -f
Is a container running docker ps --filter name=didbot-pds
Which commit is running curl -s https://<zone>/health | jq .revision
What did the last deploy do journalctl -u didbot-converge
Is the process live and progressing curl -s https://<zone>/health
Are sign-in pushes being dropped curl -s https://<zone>/health | jq .oauthPushes
How full is the data volume curl -s https://<zone>/health | jq .disk
When was the log last trimmed journalctl -u didbot-pds | grep 'wrote a checkpoint while serving'
Is a relay reading the firehose curl -s https://<zone>/health | jq .firehose
What does it hold curl -s https://<zone>/xrpc/bot.did.stats

Upgrading

scripts/deploy-pds.sh --var-file <tfvars> <rev> is the upgrade: it takes the backup, applies and waits for the new build. See Deploying for what each step does. By hand, the same thing is:

  1. Snapshot. Take an on-demand backup of the data volume into the didbot-pds vault, or an EBS snapshot of it. A snapshot holds the volume as it was when it started, so it only has to have started.
  2. Apply with container_image_tag set to the new tag. That changes the release parameter and nothing else.
  3. Converge. Within thirty seconds the timer pulls the image, restarts the unit and waits for /health; systemctl start didbot-converge does it at once. journalctl -u didbot-converge says what it did, and curl -s https://<zone>/health | jq .revision which commit answers.
  4. Announce, if a relay stopped following the server while it was down: didbot announce, as in Announcing to relays.

An image that writes a newer layout than the directory’s pds.layout stamp names rewrites the directory on its first boot. The journal reads read a data directory written under layout <n>; rewriting it in this one, then restored the deployment from its write-ahead log. That boot takes a checkpoint, trims the log against it, and rewrites the stamp last.

Boot refusals

Each stops the process at startup, before it serves anything, and the unit then restarts every five seconds logging the same message.

Journal message What it means What to do
the data directory at … was written as version … The stamp names a version this image does not read. The message says which versions it does Going forward, run one of those images first. Going backward, “Rolling back”
the data directory at … carries a stamp written before this binary’s check Half the stamp has nothing to compare against Run the build that wrote it, or delete the directory
the data directory at … holds state and carries no pds.layout The directory says nothing about what wrote it “Restoring” — bring pds.layout back with the rest of the volume
the commit history for … names …, which is not a content identifier A commit entry the log holds cannot be read Run the build that wrote it. Do not edit the log by hand
blob bytes are present and pds.wal names none of them Blob files with no log to name them “Restoring”
entry <n> did not parse Intact bytes this binary does not read as an entry Run the build that wrote it. Do not delete frames by hand
Another process holds the lock A second writer against one directory Find and stop it; never mount one data directory twice
A permission error writing to the data directory Ownership, not mode chown — see “Restoring”
the data volume is full: … could not be written A write the boot makes found no room. The message names the file and says how much is free Grow the volume and resize2fs its ext4 filesystem — see “The data volume”

The files beside the log

The write-ahead log holds the accounts. Beside it sits one small file per kind of state that a restart must not drop and a restore does not need. Each can be deleted on its own, and what that costs is below. None of them is covered by the layout stamp, so a change to one does not refuse the directory.

File Holds Deleting it costs
pds.grants OAuth grants: which tokens are live, whose they are, when they expire Every application signed out. Each has to be authorized again
pds.proofs bot.did.createAccount and bot.did.createSession proofs already spent A spent proof can be presented once more inside its window
pds.estop The halt an operator threw The halt is released, and the server starts accepting writes
pds.policy The policy set in force Every policy is gone. An empty set refuses nothing
pds.sequence The highest firehose sequence number handed out The number comes back from the log instead, which is behind on a restored volume

The data volume

The volume at /data holds the log, the blobs, the checkpoint and the record heap. The rendered config gives the log a tenth of the volume, [capacity] log_budget_bytes, and every account’s blobs together half of it, [blobs] total_quota_bytes. Each account’s blobs also stop at [blobs] account_quota_bytes. A write past either of the first two is refused with 507 StorageFull, an upload past an account’s quota with 403 AccountQuotaExceeded, and the server keeps serving what it holds. The record heap, records/pds.heap, grows with every record written.

The server gives the log its room back without a restart. Once the log reaches [capacity] checkpoint_log_bytes, half its budget unless set, and once a day otherwise ([capacity] checkpoint_interval_secs), it writes the state to pds.checkpoint and deletes the log segments before it. The journal reads taking a checkpoint while serving, then wrote a checkpoint while serving and trimmed the log against it with the bytes trimmed and left. While one runs, the volume holds the new checkpoint beside the old one and the process holds a second copy of the state in memory. A 507 on the log’s budget with a checkpoint while serving failed in the journal is a checkpoint that could not be written; the line says why, and the server tries again every minute.

GET /health carries disk: the volume’s freeBytes and totalBytes, read as the request is answered, and alert, which watermark the free space is below. freeBytes leaves out the blocks ext4 keeps back for root, which the image’s uid cannot write. A boot whose own write finds no room stops with the message under “Boot refusals”. See “Disk filling” for the watermarks.

Growing the volume takes two steps. Raise data_volume_size_gb and apply: that resizes the EBS volume in place, and restarts the container on a rendered config whose two bounds above are derived from the new size. Then run resize2fs on the volume’s device on the host, because ext4 does not grow with the volume under it.

Rolling back

The converger rolls a release back on its own when the new container does not pass its health check: it records the refused release in /var/lib/didbot/release.refused, which it then does not retry, and puts the previous image and config back. Until the unit runs the previous release again, each tick retries the rollback. To roll back a release that passed, deploy the earlier commit. To retry a refused one, delete that file.

Neither works once the new image has rewritten the data directory’s layout: the earlier image refuses the directory, and the converger’s journal says the previous release did not come back either. Restore the snapshot taken before the deploy.

Restoring the snapshot follows “Restoring”, its Mark step included, since relays may hold what the new image sent. It loses everything written since the snapshot: see Backups and restore.

Rules across upgrades

Backups

terraform-aws-didbot-pds/backup.tf puts the one EBS data volume under an AWS Backup plan: vault <name_prefix>-pds (didbot-pds by default), rule daily, schedule cron(0 9 * * ? *) — 09:00 UTC — and delete_after = 30, thirty daily recovery points. The RPO is twenty-four hours. aws_backup_selection.pds names the one resource the plan covers: the EBS data volume mounted at /data.

Snapshot the volume; do not rsync the directory.

Restoring

  1. Volume. Create a volume from a recovery point in the <name_prefix>-pds vault, in the target instance’s availability zone. It carries the whole directory, pds.layout included: a volume that came back without it is refused, because the directory then says nothing about what wrote it.
  2. Attach. Attach it to a fresh instance, never to the running one, and mount it at /data, where that instance’s boot script chowns /data/pds to uid 10001. The image runs as that uid and chmods the data directory to 0700 on every open: the mode a snapshot carries is re-tightened, the owner is the chown.
  3. Mark. touch /data/pds/pds.restored, before the unit’s first start.
  4. Start. systemctl start didbot-pds.
  5. Verify. Run the checks under “Verifying a restore”.
  6. Announce. didbot announce, as in Announcing to relays. A relay that stopped dialing this host after a FutureCursor subscribes again, and one still reading is unaffected.
  7. Clean up. Detach and delete any test volume.

The boot that finds pds.restored tells relays what the restore lost, and removes the file once it has. It raises the firehose sequence floor by 10^12, logging the data directory was restored: raised the firehose sequence floor. It sends every account’s position again, and resets each live repository with #sync over a new commit, logging told `subscribeRepos` what the restore lost. A boot that stops before that line leaves the file, and the next boot sends everything again. See conformance for what each frame says.

On a blob bytes are present and pds.wal names none of them refusal: finish the restore so the log is present, or move blobs/ aside and start with an empty blob store, after which getBlob answers NotFound for the blobs the accounts reference.

Verifying a restore

The startup line is restored the deployment from its write-ahead log, and its fields are the count of each thing that came back. It may be followed by wrote the checkpoint the next boot reads the log from. A the write-ahead log ends in an incomplete write; truncating it warning reports the discarded bytes and the offset it stopped at; on a snapshot restore that is the torn tail of the append in flight when the snapshot was taken.

Check Confirms
GET /health returns 200 with ticks advancing between two calls a few seconds apart The process is live and its ten-second tick is running
GET /xrpc/bot.did.stats Accounts, records and bytes per collection match what the deployment had, and blobs.held matches its blob inventory
blobs.missingAtBoot in that response reads {"count": 0, "bytes": 0} Every blob the log names had its bytes on the disk this deployment started on. A nonzero count is that many 404s waiting, and bytes is what the restore would have to bring back; the CIDs are in the startup ERROR line
blobs.discardedAtBoot reads {"count": 0, "bytes": 0} The copy carried no blob bytes the log could not account for. A nonzero count is that many files deleted during startup
GET /xrpc/bot.did.listAccounts The accounts that should be there are there
One agent’s did.json resolves The signing keys came back
Fetch one blob that account references The bytes are on the disk; getBlob re-hashes what it reads and refuses on a mismatch

Sign-in pushes that leave no decision behind

POST /oauth/par is unauthenticated, and no answer it gives may depend on whether an account exists — so a client flooding one agent’s pending sign-ins gets the same 201 an ordinary push gets, and the agent sees only that its own sign-in never arrives. GET /health carries oauthPushes, three counts since this process started:

Count What moved it
displaced A push past an account’s own pending_per_account bound. That account’s oldest undecided sign-in made way for it
unresolvedHint A push whose login_hint named no account here
serverFull A push refused because this server holds pending_total decision records already, counting an answered one until its request expires. This is the one an ordinary caller can see, as a 403

Read them twice a minute apart: these are totals, so what says anything is how fast they move. displaced climbing steadily is a flood aimed at accounts this deployment holds; unresolvedHint climbing is one probing for accounts it does not. The journal carries a sampled info line for the first, one in a hundred, naming the account — sampled because logging every one would make the log the thing a flood amplifies.

bot.did.stats and bot.did.listAccounts are public by default; under --close-disclosure they answer 403 and the figures are in the startup line.

Scopes a sign-in is not granted, and forms outside the spec

A sign-in that asks for a transition:, identity: or account: scope has that scope dropped and the rest granted. So does one that names a scope this server cannot read, such as the unknown kind space:* or the value account:status. The agent’s decision record lists each dropped scope under cut.

An app may write a scope in a form the permission spec does not define. The server reads it as well as it can, and once it has checked the client it writes a warn line naming the client, the atom as the app wrote it, and how it was read. The operator’s own [oauth] scope_ceiling is read without one, so its partial wildcards write nothing.

Form Read as
A partial wildcard, such as repo:app.bsky.* The NSIDs under that prefix, at any depth
rpc: with no aud Every audience
rpc:*?aud=* Every method at every audience, as written
An aud that is not * or a DID with a service fragment That audience alone
repo:…?action=manage No record operation, so the scope adds no write
A comma list of actions, action=create,update Each action in it
A parameter its kind does not take Ignored
A list parameter both after the : and by name, such as blob:image/png?accept=text/html Every value
A parameter that takes one value, given twice The first
A scope this server cannot read Kept as written, and dropped

Answering an incident

journalctl -u didbot-pds and GET /health answer on the instance. The didbot commands run on the operator’s own machine after didbot login --server <zone>. The dashboard at https://<zone>/dashboard reads the same state in a browser, and its three app panels filter by client and by account. Every journal line named here is written at the default log level.

Symptom Start with
An app’s sign-in, token or XRPC call is refused The journal’s refused a request lines: “Sign-ins failing”
An app’s login stopped getting tokens The dashboard’s logins panel, /dashboard/api/apps/logins: each login’s scope in force, and whether policy would issue it a token now
A policy refused a sign-in, a token or a write, or the scope ceiling cut a sign-in’s scopes The dashboard’s refusals panel, /dashboard/api/apps/refusals
What an app or an account wrote The dashboard’s writes panel, /dashboard/api/apps/writes
An account’s writes are refused didbot account show <name> --server <zone>: “An account’s writes refused”
A relay stopped seeing commits /health’s firehose: “A relay stopped seeing commits”
The data volume is filling /health’s disk: “Disk filling”
Accounts pile up that never wrote didbot account list --never-wrote --server <zone>. didbot account delete --never-wrote --server <zone> lists the same, and deletes them with --confirm
An app’s keys or tokens leaked didbot app end-logins --client <client_id> --server <zone>
One account must stop now didbot account lock <name> --server <zone>
The whole server must stop now didbot estop --pause --server <zone>, or --revoke to end every token too. didbot estop --server <zone> reports the stop and what it refused

Sign-ins failing

Each refused OAuth or XRPC request writes one refused a request line:

Field Holds
endpoint par, authorize, token or xrpc. The request span before it names the path
client_id The app, when the request named one
account The account, when the check that refused knew it
error The error the caller was sent
reason Why. For a client metadata document that could not be used, the cause, which the caller is not sent

journalctl -u didbot-pds --since -1h | grep 'refused a request' | grep '<client_id>' lists one app’s refusals. WARN is for what the operator acts on: the app’s metadata document cannot be used, its redirect or its authentication no longer matches that document, the server holds too many pending sign-ins, or a refresh token or DPoP key was presented the way a stolen one would be. Expired codes and tokens, malformed requests and policy refusals are INFO.

Repeats collapse. The first refusal of a kind is written at once. The same refusal again within five minutes is counted, and the count is written as the same refusal repeated, with repeats, once the five minutes are up. At most 60 new kinds are written a minute for each severity, endpoint and error together. Past that, refusals went unwritten gives the count, naming all three. So a flood of invalid_client at par leaves a reused refresh token’s invalid_grant at token written.

An account’s writes refused

didbot account show <name> --server <zone> prints the account’s state, its locks and its latest ledger entries. Each lock names the party that hung it. GET /xrpc/bot.did.getAccountLedger?did=<did> answers the whole ledger, unless --close-disclosure names get-account-ledger.

A lock hung by policy is a quarantine a policy’s freeze verdict hung. didbot account show <name> --server <zone> --json prints its ledger entry in full: "event": "locked", with policyEvaluation naming the evaluation. The dashboard’s refusals panel, filtered to the account, shows that evaluation’s row: the verdict, the policies that fired and their reason. /dashboard/api/apps/refusals?account=<name> gives each row’s evaluationId, which is the ledger entry’s policyEvaluation. didbot account lift-quarantine <name> --server <zone> takes the lock off.

A lock hung by parent comes from above: an account in its lineage is locked, or the operator record naming the account or one above it is gone. Its state then ends in paused. didbot operate --check <name> walks the edges up and stops at the one that fails.

A relay stopped seeing commits

GET /health’s firehose holds consumers, the subscribeRepos connections attached now, and newestSeq, the newest sequence number assigned. consumers at 0 while newestSeq climbs is a firehose nobody is reading.

The journal writes subscribeRepos consumer connected with the cursor the consumer asked for. subscribeRepos consumer disconnected follows with the same cursor, the reason it ended, lasted_secs, and the frames sent. A consumer closed for falling behind is a WARN line with lagged. The last disconnect says when the relay left and why. didbot announce asks it back, as in Announcing to relays.

Disk filling

The ten-second health line carries disk_free and disk_total, in bytes. journalctl -u didbot-pds --since -1d | grep 'health accounts=' is the volume’s free-space history.

GET /health’s disk.alert is ok, warning or critical, measured against two watermarks of free space as a share of the volume: [capacity] disk_warning_free_percent, 20 by default, and disk_critical_free_percent, 10 by default. Startup refuses a warning outside 10 to 50, or a critical outside 2 to 20 or not below the warning, and names the key. Falling below one writes the data volume's free space fell below a watermark at WARN, with free_bytes and watermark_percent. Rising back above writes the data volume's free space rose back above a watermark at INFO. terraform-aws-didbot-pds/monitoring.tf raises its disk alarm while alert is anything but ok.

The log and the blobs stop at their own budgets; see “The data volume”. The record heap, checkpoints and the files beside the log grow until the volume is full. Grow the volume before critical, as “The data volume” describes.