Part 6 of 6 Running one for other people
Credentials, and keeping them out of logs
By the end of this chapter, Laurence can see every credential the instance has issued, end any one of them at once, and knows which of his logs would have written a secret down if nothing stopped them.
This is the chapter you read before you need it. Everything in it takes a few seconds on an ordinary afternoon, and the same work on the afternoon somebody pastes a token into a chat window is the difference between a small nuisance and a long evening.
The work so far
Laurence has the instance of An account, an install and a first run at the address TLS, a proxy and systemd gave it, with Keanu's account from Adding the people, a project, and a calendar feed somebody has subscribed to:
sudo useradd --system --no-create-home --shell /usr/sbin/nologin subroutine
sudo python3 -m venv /opt/subroutine
sudo /opt/subroutine/bin/pip install "subroutine[postgres]"
sudo install -d -o subroutine -g subroutine -m 0755 /var/lib/subroutinesudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine init --workspace metacortex --instance-name MetaCortex
sudo -u subroutine tee -a /var/lib/subroutine/config/subroutine/config.toml > /dev/null <<'SETTING'
public_url = "https://tasks.example.com"
SETTING
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine project create web "Website rebuild"
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine user create keanu --name "Keanu Reeves" --terminal | tee /tmp/for-keanu
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine calendar create "Website rebuild deadlines" --project web | tee /tmp/the-feed
The instance is serving, with everything it prints kept where the rest of this chapter can read it:
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine serve | tee /tmp/subroutine.log
What has been handed out
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine token list
subroutine token list is every credential this instance has issued, and no secret is stored, so there is nothing in that listing to leak. What it shows is the prefix, who holds it, what it is for, when it expires and when it was last used.
The second line is the one that matters on a bad day. When you think a credential has got out, the question is not how many there are, it is which of them could write and how far each one reaches. That line answers it for each, and the never used at the end of it answers the other question, which is whether anybody has.
Ending one
The credential Keanu was given works, as it should:
token=$(grep -o 'sr_[A-Za-z0-9_-]*' /tmp/for-keanu | head -1)
curl -so /dev/null -w '%{http_code}\n' -H "Authorization: Bearer $token" https://tasks.example.com/v1/tasks
Keanu opens the sign-in link he was given, and whatever holds the calendar feed polls it, which is all either of those ever does:
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine login link --username keanu | tee /tmp/a-link
link=$(grep -o 'https://[^ ]*' /tmp/a-link)
feed=$(grep -o 'https://[^ ]*\.ics' /tmp/the-feed | head -1)
curl -so /dev/null -w '%{http_code}\n' "$link"
curl -so /dev/null -w '%{http_code}\n' "$feed"
Both of those requests are now in a log, which is the second half of this chapter. First, ending them.
The prefix in that listing is part of the credential itself, which is how you match a token somebody has sent you to the row that describes it:
prefix=$(echo "$token" | cut -d_ -f2)
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine token revoke "$prefix"
It means what it says:
curl -so /dev/null -w '%{http_code}\n' -H "Authorization: Bearer $token" https://tasks.example.com/v1/tasks
There is no session to wait out. A revoked credential is checked on every request rather than cached for a while, so the gap between deciding and it being true is the time the command takes. That is the whole answer to a key having leaked, and it is why the listing is worth reading before you revoke rather than after: revoking the wrong one is recoverable, and issuing a replacement is one command, but knowing which one was the problem is not something you can work out afterwards.
Signing somebody out
A token is one door and a browser is the other, and ending one does nothing to the other. This is the browser:
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine login revoke keanu
subroutine login revoke ends every browser that account is signed in on, and cancels any sign-in link that has been minted for them and not yet used. That is what a lost phone needs, and it is also the safe thing to do when a link has gone somewhere you did not mean it to go.
What the log would have written down
A sign-in link travels in a URL, and it has to, because a link is something somebody clicks and a click is a GET. So it reaches every access log that sees the request. A calendar feed is worse: its credential is in the path rather than the query, and a subscription polls it every few minutes for as long as anybody keeps it, and the address does not expire by itself.
Both were reached a moment ago. Here is what the instance wrote down:
grep -E 'signin|calendars' /tmp/subroutine.log
subroutine serve redacts both in its own access log, and does the same for an API token somebody has wrongly put in ?token=, ?api_key= or ?access_token=, which is refused as a way of authenticating but is a real credential by the time it is refused.
The feed keeps its short prefix and loses the secret, which is the useful compromise: you can still tell which subscription is polling you, and the part that would let anybody else read it is gone.
Two things worth knowing rather than guessing about a logged link. It is usually already spent, because the log line is written when the response goes out and the link is consumed before that. The exception is the confirmation page: if the browser was already signed in as somebody else, the link is deliberately left usable so that saying no costs nothing, and it stays usable for the rest of its life.
Your proxy writes the same request line down
Nothing here can reach that log, so it is yours to set. With nginx, a format using $uri rather than $request drops the query string:
Not checked: the build does not run this.
log_format subroutine '$remote_addr - "$request_method $uri" $status';
access_log /var/log/nginx/subroutine.log subroutine;That handles the query and not the path, so it is not enough on its own for calendar feeds, whose secret is exactly the part $uri keeps. If you serve feeds through a proxy and keep its access log, either stop logging that path or rewrite it before it is recorded:
Not checked: the build does not run this.
location /v1/calendars/ {
access_log off;
proxy_pass http://127.0.0.1:8471;
}Neither fragment is checked by anything here, and both are a starting point rather than a configuration.
If you run the app under your own uvicorn or gunicorn rather than subroutine serve, call subroutine.api.logs.redact_access_logs() before starting it. The filter belongs to a logger inside your process, and nothing else installs it for you.
Ending a feed, or moving it
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine calendar list
last polled is how you tell a subscription somebody is using from one somebody set up once and forgot, which is worth knowing before you end it.
That first column is the prefix the log line kept, which is how a subscription polling too often in your access log becomes a row here with a name on it:
feedref=$(echo "$feed" | cut -d/ -f6)subroutine calendar reset gives the same feed a new address:
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine calendar reset "$feedref" | tee /tmp/the-feed-again
The prefix changes with the address, so a feed you have reset is a different line in your logs from then on. That is worth knowing if you were watching one particular subscription: the thing you were matching on is not the thing any more.
And ending it altogether:
sudo -u subroutine env \
XDG_CONFIG_HOME=/var/lib/subroutine/config \
XDG_DATA_HOME=/var/lib/subroutine/data \
XDG_STATE_HOME=/var/lib/subroutine/state \
/opt/subroutine/bin/subroutine calendar revoke "$(grep -o 'https://[^ ]*\.ics' /tmp/the-feed-again | cut -d/ -f6)"
Reset when somebody still wants the feed and the address has gone astray. Revoke when they do not. Nothing about either touches the work the feed was showing.
With that, every credential this instance has issued can be seen, matched to whatever turned up where it should not have, and ended in one command, and the two logs that would otherwise have kept a copy of the secret do not.