Skip to content

Config Logging and Cache

Dejan Strbac edited this page Nov 12, 2026 · 1 revision

This page covers two sections of the configuration file. [logging] sets where ALPS writes its log, in which format, and from which level. [cache] sets the in-memory cache each session keeps. The page also covers what [server] debug adds, how to rotate a log file with SIGHUP, the few lines written outside [logging], and the log lines operators usually search for. The key reference is docs/CONFIGURATION.md, and the runbook is docs/OPERATIONS.md.

The defaults

Each key has its own default, whichever of the others are set:

Key Default
output stdout
format json, or console with [server] debug = true
level info, or debug with [server] debug = true
access true

Setting only level = "warn", for example, keeps the log on stdout as JSON. config.example.toml sets output = "stderr", format = "console" and level = "info".

[logging] keys

Key Default Meaning
output stdout "stdout", "stderr", "syslog", or a file path.
format see above Only "json", in lower case, gives JSON lines. Any other value, "JSON" included, gives console text (key=value).
level see above "debug", "info", "warn" (or "warning") or "error", in any case. An unknown value means info, with no warning.
access true One request line per HTTP request, at info level. false turns these lines off. The sign-in and session lines stay.

A key ALPS does not know is ignored, so a misspelt key keeps its default. ALPS logs a warning for it at startup, once the log is open, such as Unknown configuration key: logging.levl (ignored). The warning is at warn level, so level = "error" leaves it out. A known key with a value of the wrong type stops startup, for example access = "off":

Error loading config file: failed to parse TOML config: toml: line 8 (last key "logging.access"): incompatible types: TOML value has type string; destination has type boolean

Choosing an output

stdout and stderr. These suit a service manager. Under the shipped systemd unit, both go to the journal (journalctl -u alps -f). Under the shipped FreeBSD rc.d script, daemon(8) appends both to /var/log/alps/alps.log. See Service Files.

A file path.

  • ALPS opens the file for appending. If the file does not exist, ALPS creates it with mode 0644 (before the umask).
  • The directory must already exist. If ALPS cannot open the file, it writes Failed to open log file <path>: <error>, falling back to stderr to stderr and logs to stderr. It keeps running.
  • Give an absolute path. Both shipped service files run ALPS in /, so a relative path resolves from there.
  • Under the shipped systemd unit (ProtectSystem=strict), list the log directory in ReadWritePaths (see Rotating a log file).
  • The log holds user names and client addresses, and at level debug with [server] debug or [provider.imap] debug on, the protocol traces with message, contact and calendar content. Keep the directory readable only by the ALPS user and administrators, for example mode 750 and owner alps. A file that already exists keeps its own mode.
  • ALPS never rotates or truncates the file.

"syslog".

  • ALPS connects to the local syslog daemon with facility daemon and tag alps. Each message is the formatted line (JSON or console text), so the line carries its own timestamp as well as the one syslog adds.
  • The syslog priority follows the line's level: daemon.err for errors, daemon.warning for warnings, daemon.info for info lines and daemon.debug for debug lines. Make sure the syslog daemon keeps the priorities your level lets through, daemon.info and above at the default level.
  • If the syslog daemon cannot be reached at startup, ALPS writes Failed to connect to syslog: <error>, falling back to stderr and logs to stderr. On Windows, which has no syslog, the error is syslog is not supported on this platform.

A few lines go to stderr whatever output says (see Lines outside [logging]). With a file or syslog, collect stderr as well.

Formats

The same sign-in, as JSON:

{"time":"2026-11-12T10:58:59.026582+01:00","level":"INFO","msg":"sign-in","user":"user@example.com","ip":"192.0.2.10","session":"0adb1560f7bc","2fa":false,"remember":false,"restored":false,"agent":"Mozilla/5.0 (X11; Linux x86_64) ..."}

and as console text:

time=2026-11-12T10:58:17.964+01:00 level=INFO msg=sign-in user=user@example.com ip=192.0.2.10 session=667d2ad61324 2fa=false remember=false restored=false agent="Mozilla/5.0 (X11; Linux x86_64) ..."

Use json when a log collector reads the lines. Use console for a terminal. Timestamps are in the host's local time zone, with its offset.

Levels

Each level logs its own lines and those of the levels above it in the table. The lines named are the ones operators meet most often, not a full list.

Level What it adds
error Fatal startup errors, and a Request error: <error> line for every error a request handler returns. This includes refusals answered with a 4xx status, such as Request error: code=403, message=Invalid origin. Also errors in ALPS's own work, such as PANIC in handler for <path>: ..., SIGHUP: <error>, an upload that could not be read or stored (upload multipart: ...) or a password change that failed.
warn sign-in failed, session not restored, and the startup warnings: Unknown configuration key: ... (ignored), an unset [webauthn] rpid or an origin outside it, and Enabled plugin "<name>" did not load. A few others.
info The startup lines, the request lines, sign-in, session ended, session restored, account switches, rate-limiter lines, CSRF: lines, most of the cluster's and the certificate manager's lines, and the IMAP provider's warnings (alps/provider: ...).
debug Several lines per request: the auth middleware's steps, rate-limit checks, and Cache HIT and Cache MISS lines. Also the gossip library's own lines in a cluster, and, when [server] debug or [provider.imap] debug is on, the IMAP provider's notes and the protocol trace lines.

Use info in production. At warn, the request lines and successful sign-ins are no longer logged. At error, failed sign-ins and the startup warnings are not logged either.

level = "debug" alone does not turn on the protocol traces. Those come only with [server] debug, or for IMAP alone with [provider.imap] debug, and then only while the level is debug (see below). Debug lines still name users, client addresses and folders, so keep level = "debug" to test setups.

Rotating a log file

When output is a file path, SIGHUP has ALPS open the same path again and close the old descriptor. A rotation tool can therefore move the file aside, signal ALPS, and ALPS goes on writing to a new file under the old name.

  • After the reopen, ALPS writes SIGHUP: log file reopened to the new file. The line is at info level, so it is not written with level = "warn" or "error".
  • If the path cannot be opened, ALPS keeps writing to the old descriptor. It logs SIGHUP: reopen log file <path>: <error> at error level there.
  • With stdout, stderr or syslog, or after a fallback to stderr, there is nothing to reopen, and ALPS logs SIGHUP: no log file to reopen at info level.
  • SIGHUP does not reload the configuration or the TLS certificates. Restart ALPS for those.
  • ALPS handles SIGHUP from the moment it has opened the log, before the slower startup steps such as joining a cluster or checking the DAV servers, so a rotation during startup does not stop it. Only a SIGHUP that arrives while the configuration is still being read ends the process. SIGINT and SIGTERM are handled once ALPS listens on [server] addr (Signals and Graceful Shutdown).

systemd and logrotate

The unit's ExecReload sends SIGHUP, so systemctl reload alps reopens the file, and a logrotate postrotate script can call it. Under the shipped unit, the log directory must exist, belong to alps, and be listed in ReadWritePaths in a drop-in, because the unit makes the file system read-only. Running-in-Production has the complete setup: the [logging] section, the drop-in, the commands that create the directory, and a logrotate file, all tested on Debian 13.

Use delaycompress in the logrotate file. It leaves the newest rotated file uncompressed until the next run, so lines that ALPS writes between the move and the SIGHUP still land in a plain file.

FreeBSD and newsyslog

The rc.d script's /var/log/alps/alps.log is daemon(8)'s output. daemon(8), not ALPS, holds it open, and the script starts daemon(8) with -H, so daemon(8) reopens it on SIGHUP. The script writes two pid files: daemon(8)'s own in /var/run/alps/daemon.pid, and ALPS's in /var/run/alps/alps.pid (Caveats (FreeBSD)).

With the default [logging] output, every line goes to alps.log. To rotate it, have newsyslog signal daemon(8). The script's comments give this entry:

# /etc/newsyslog.conf.d/alps.conf
# logfilename            [owner:group]  mode  count  size  when  flags  [/pid_file]                [sig_num]
/var/log/alps/alps.log   alps:alps      640   7      *     @T00  JC     /var/run/alps/daemon.pid   1

To have ALPS write a log file of its own instead, set [logging] output to another file in that directory, and have newsyslog signal ALPS itself. alps.log then keeps only the lines written outside [logging].

[logging]
output = "/var/log/alps/server.log"
format = "json"
/var/log/alps/server.log   alps:alps      640   7      *     @T00  BJ     /var/run/alps/alps.pid     1

The B flag stops newsyslog from writing its plain-text "logfile turned over" line into the new file, so a JSON log stays all JSON. Without a pid file in the entry, newsyslog signals syslogd instead.

The log lines operators look for

At startup

Line Level Meaning
Configured SMTP server: <url> info The [smtp] server in use.
Rate limiting enabled: IP=<n>/min, <n>/hour | User=<n>/15min, <n>/hour | Global=<n>/sec info Only while [server.rate_limit] is on (docs/RATELIMIT.md).
Unknown configuration key: <key> (ignored) warn A key or section ALPS does not know, usually a misspelling. The key keeps its default (Configuration-Overview).
Loaded plugin "<name>" info One line for each plugin that loads. A plugin that enabled keeps out gets no line (Config-Plugins).
Enabled plugin "<name>" did not load; check its name and backend configuration warn A name with enabled = true that did not load: a misspelt section name, or a plugin without what it needs.
WebAuthn: [webauthn] rpid is unset, defaulting to "localhost" ..., WebAuthn: origin "..." is outside rpid "..." ... warn Set rpid and origins to your public hostname (Config-Rate-Limiting-and-WebAuthn).
Starting ACME HTTP-01 challenge handler on <addr> info With Let's Encrypt only. ACME HTTP-01 handler error: <error> (error) means that listener could not start, and ALPS keeps running (Config-TLS).
Starting server on <addr> info The last startup step: ALPS is about to listen.

Errors found before the log is opened go to stderr as plain text, and ALPS exits with status 1. Examples are Error: -config flag is required, Error loading config file: ... and Error generating options: .... Later fatal errors, such as Failed to initialize TLS manager: ..., go to the [logging] output at error level. ALPS logs no line of its own for the start or the end of a shutdown. It logs Session shutdown timed out waiting for cleanup only when the sessions' cleanup takes longer than 5 seconds (Startup and Exit Status).

One line per request

With access = true:

time=2026-11-12T10:58:18.012+01:00 level=INFO msg=request method=GET path=/mailboxes/INBOX status=200 bytes=4281 duration_ms=32.41 ip=192.0.2.10 user=user@example.com session=667d2ad61324
  • path leaves out the query string, which can hold search terms and remote image addresses.
  • bytes is the size of the response body.
  • user and session appear once the request belongs to a session, including the request that signs in.
  • session is a short hash of the session token, never the token itself. It ties together the lines of one session.
  • ip is the peer's address, or the client address that a proxy listed in trusted_proxies forwarded. Behind a proxy that is not listed, every line shows the proxy's address (Setup-Behind-a-Reverse-Proxy).

Set access = false when the reverse proxy already keeps an access log.

Sign-in and sessions

ALPS logs these lines whatever access says:

Message Level Fields
sign-in info user, ip, session, 2fa, remember, restored, agent. After a second factor: also factor (security key, or recovery code with recovery_codes_left), and without restored.
sign-in awaits second factor info user, ip, session
sign-in failed warn user, ip, reason, and depending on the reason error, agent, detail or session
session restored info user, ip, session
session not restored warn user, ip, error
account switch, account switch awaits second factor info user, to, ip, session (the new one), and for account switch also 2fa_trusted
session ended info user, session, reason, duration

The reason of sign-in failed is bad credentials, rate limited (with the limiter's message in detail), connection limit, second factor refused, recovery code refused or error (the mail server could not be reached, with the cause in error). With bad credentials, error says why the login was refused: the mail server's answer, or under multi a domain that no rule covers (no mail provider configured for domain "example.org"). The password is never logged. For example:

level=WARN msg="sign-in failed" user=user@example.com ip=192.0.2.10 reason="bad credentials" error="authentication failed: ..." agent=Mozilla/5.0
level=WARN msg="sign-in failed" user=user@example.com ip=192.0.2.10 reason="rate limited" detail="Too many login attempts, please wait a minute"
level=WARN msg="sign-in failed" user=user@example.com ip=192.0.2.10 reason=error error="failed to connect to IMAP server: dial tcp 127.0.0.1:143: connect: connection refused"

The meaning of each session ended reason, and when sessions are restored, are on Sessions-and-Sign-in. The rate limiter's own lines are listed in docs/RATELIMIT.md.

Origin checks behind a proxy

A state-changing request whose Origin (or Referer) is not the origin ALPS expects is refused with 403. ALPS logs two lines for it:

level=INFO msg="CSRF: Origin mismatch: got \"https://webmail.example.com\", expected \"http://webmail.example.com\" (scheme differs and the peer 10.0.0.2 is not in trusted_proxies; ...)"
level=ERROR msg="Request error: code=403, message=Invalid origin"

When the mismatch looks like a proxy setting, the line ends with a hint in parentheses, such as a peer missing from trusted_proxies, a missing X-Forwarded-Proto, or a host forwarded without its port. Fix the proxy or trusted_proxies, or list the origin in trusted_origins (Config-Server, Setup-Behind-a-Reverse-Proxy).

Lines outside [logging]

Almost every line goes through [logging], including those of the cluster (Config-Cluster), of the TLS certificate manager (Config-TLS), of the IMAP provider, and the protocol traces of [server] debug and [provider.imap] debug (below). The IMAP provider's warnings are info lines that start with alps/provider:. The one to look for when settings do not persist is alps/provider: IMAP server doesn't support the METADATA extension, using transient store instead (Mail-Server-Requirements). Others report a command the server refused or failed, such as THREAD, NAMESPACE, LSUB or LIST with RETURN options, and the simpler way ALPS takes instead.

Only the errors found before the log is opened do not go through [logging], so output, format and level do not apply to them: the startup errors, and the Failed to open log file and Failed to connect to syslog messages above. They go to stderr as plain text without a timestamp.

Under systemd, stderr goes to the journal. Under the FreeBSD script, it goes to daemon(8)'s alps.log.

[server] debug and the protocol traces

[server] debug = true is for development only. It changes these things:

What With debug = true
Log defaults format becomes console and level becomes debug, where [logging] does not set them.
TLS handshake errors Logged at debug level, as http: TLS handshake error from <addr>: <error>. Without debug they are dropped, even at level = "debug".
IMAP The whole exchange of every IMAP connection is logged. The password is redacted.
CalDAV and CardDAV Every request and response is logged, bodies included. The Authorization, Proxy-Authorization, Cookie and Set-Cookie headers are redacted.
ManageSieve The exchange is logged. Credentials are redacted.
IMAP provider notes A few notes are logged at debug level, for example when SORT or THREAD fails and ALPS falls back.

The traces go through [logging] as protocol trace lines at debug level, with the protocol (imap, caldav, carddav or managesieve) in protocol and the exchange in data. They follow output and format like every other line, and they appear only while level is debug, so a level of info or above leaves them out even with debug = true. For example, with format = "console":

level=DEBUG msg="protocol trace" protocol=imap data="..."

The traces hold message bodies, contacts, calendar events and account data, so treat a log that holds them as secret. Keep debug off in production.

[provider.imap] debug = true turns on the IMAP trace and the IMAP provider notes, for that provider only. It does not change the [logging] defaults, so both show only with level = "debug", and it does not turn on the CalDAV, CardDAV or ManageSieve traces (Config-Providers-and-SMTP). Keep it off in production too.

[cache]

Each session keeps its own cache in memory, on the node that holds the session. It holds:

  • the folder list and each folder's counts;
  • pages of message listings (search results are never cached);
  • message structures and conversations;
  • message parts, and the inline images read with an HTML body, up to max_part_kib each.

The cache ends with its session, and a restart loses every cache. There is no limit on its total size: each session holds what it read within ttl_minutes, and max_part_kib bounds a single part.

Key Default Meaning
enabled true Leaving the key out keeps the cache on. With false, each entry lives one second instead of ttl_minutes.
ttl_minutes 10 How long an entry is served after it was stored. 0 or a negative value means 10.
max_part_kib 1024 The largest message part kept, its header and body together, in KiB. 0 or a negative value means 1024.
[cache]
enabled = true
ttl_minutes = 10
max_part_kib = 1024

How fresh the cache is

ALPS drops the affected entries itself when the user changes something in ALPS. A cached page of a folder is served only while the folder's counts (messages, unread, UIDVALIDITY and UIDNEXT) are the ones it was read at. A change made in another mail client that leaves those counts as they were, such as a star, is not seen until the page expires after ttl_minutes. With [server] condstore = true, on a server that offers CONDSTORE, ALPS reads only the changed flags at the next check instead (Config-Server, docs/CONFIGURATION.md).

A shorter ttl_minutes shows such changes sooner and holds less memory, at the cost of more IMAP reads. A longer one holds more memory per session. A background sweep every 30 seconds frees expired entries.

Large parts

A part above max_part_kib is read from the mail server each time it is asked for. The browser keeps its own copy of the parts it downloads (/raw): those responses carry an ETag and Cache-Control: private, no-cache, and a revalidation is answered with 304 without the part being read again. Lower max_part_kib when many sessions open large attachments and memory is short.

Turning it off

enabled = false keeps entries for one second, so a request repeated within that second is still answered from the cache. Every other listing and every message open goes to the mail server, which adds load there. Use it only to rule the cache out while you look into a problem.

Caches [cache] does not set

  • The IMAP provider keeps, for each session, the THREAD and SORT answers of up to 8 folders while a folder's contents stay the same, and up to 5000 message previews for each folder.
  • The CalDAV and CardDAV plugins keep the home set of each connection (the account, the server and the credentials) for 10 minutes, or until listing the calendars or address books from it fails. The whole cache is emptied when it grows past 1000 connections, and at a restart (Home Set Caching).
  • The multi provider keeps autodiscovery answers for 15 minutes (Config-Providers-and-SMTP).
  • BIMI logos are cached on disk for up to 7 days (The BIMI Logo Cache).

Seeing the cache at work

With level = "debug", ALPS logs a line for each lookup:

level=DEBUG msg="Cache MISS for message INBOX/1 part [1], fetched and cached"
level=DEBUG msg="Cache HIT for message INBOX/1 part [1]"
level=DEBUG msg="Cache MISS for message INBOX/1 part [2], fetched, 307349 bytes, too large to cache"
level=DEBUG msg="Cache HIT for messages in INBOX page 0 (query: \"\")"

For production

  • [server] debug = false and [provider.imap] debug = false.
  • format = "json" when a collector reads the log, and level = "info".
  • A log file with an absolute path, in a directory that exists, is owned by alps and is closed to other users. List it in ReadWritePaths under systemd, and rotate it with SIGHUP.
  • Collect stderr as well, for the startup errors written outside [logging].
  • No Unknown configuration key warnings at startup.
  • List only your own proxies in trusted_proxies, so that ip is the client's address.
  • Keep the [cache] defaults unless memory or freshness calls for a change.

See also Configuration-Overview, Running-in-Production and docs/OPERATIONS.md.

Clone this wiki locally