lacme-accountd: new setting 'logfile' to log signature requests.

Prefixed with a timestamp.

8 files changed, 116 insertions, 63 deletions

diff --git a/Changelog b/Changelog
index c69d0d0..e6becda 100644
--- a/Changelog
+++ b/Changelog
@@ -50,6 +50,8 @@ lacme (0.7.1) upstream;
    and --privkey= (and 'socket'/'privkey' configuration options).
  * lacme-accountd(1): base64url-decode incoming signature requests shown
    in messages to the standard error.
+ * lacme-accountd(1): new setting 'logfile' to log (decoded) incoming
+   signature requests to a file.
  + Improve nginx/apache2 snippets for direct serving of challenge files
    (with the new 'challenge-directory' logic symlinks can be disabled).
  + Split Nginx and Apapche2 static configuration snippets into seperate
diff --git a/lacme b/lacme
index ad7e1d8..88ab78d 100755
--- a/lacme
+++ b/lacme
@@ -558,12 +558,12 @@ sub acme_client($@) {
 
         # ensure we're the only user with write access to the parent dir
         my $dirname = dirname($sockname);
-        @stat = stat($dirname) or die "stat($dirname): $!\n";
-        die "Error: insecure permissions on $dirname\n" if ($stat[2] & 0022) != 0;
+        @stat = stat($dirname) or die "Error: stat($dirname): $!\n";
+        die "Error: Insecure permissions on $dirname\n" if ($stat[2] & 0022) != 0;
 
         # ensure we're the only user with read/write access to the socket
         @stat = stat($sockname) or die "Can't stat $sockname: $! (Is lacme-accountd running?)\n";
-        die "Error: insecure permissions on $sockname\n" if ($stat[2] & 0066) != 0;
+        die "Error: Insecure permissions on $sockname\n" if ($stat[2] & 0066) != 0;
 
         # connect(2) to the socket
         socket($client, PF_UNIX, SOCK_STREAM, 0) or die "socket: $!";
diff --git a/lacme-accountd b/lacme-accountd
index 0adfe38..c8c6d5e 100755
--- a/lacme-accountd
+++ b/lacme-accountd
@@ -63,6 +63,30 @@ sub usage(;$$) {
 usage(1) unless GetOptions(\%OPTS, qw/config=s privkey=s socket=s stdio quiet|q debug help|h/);
 usage(0) if $OPTS{help};
 
+my $LOG;
+sub logmsg($@) {
+    my $lvl = shift // "all";
+    if (defined $LOG) {
+        my $now = localtime;
+        $LOG->printflush("[", $now, "] ", @_, "\n") or warn "print: $!";
+    }
+    unless (($lvl eq "debug" and !$OPTS{debug}) or ($lvl eq "noquiet" and $OPTS{quiet})) {
+        print STDERR @_, "\n" or warn "print: $!";
+    }
+}
+sub info(@) { logmsg(all => @_); }
+sub error(@) {
+    my @msg = ("Error: ", @_);
+    info(@msg);
+    die(@msg, "\n");
+}
+sub panic(@) {
+    my @loc = caller;
+    my @msg = (@_, " at line $loc[2] in $loc[1]");
+    info(@msg);
+    die(@msg, "\n");
+}
+
 sub env_fallback($$) {
     my $v = $ENV{ shift() };
     return (defined $v and $v ne "") ? $v : shift;
@@ -80,8 +104,8 @@ sub spec_expand($) {
         : $1 eq "t" ? ($< == 0 ? "@@runstatedir@@" : $ENV{XDG_RUNTIME_DIR})
         : $1 eq "T" ? env_fallback(TMPDIR => "/tmp")
         : $1 eq "%" ? "%"
-        : die "Error: \"$str\" has unknown specifier %$1\n";
-        die "Error: undefined expansion %$1 in \"$str\"\n" unless defined $x;
+        : error("\"$str\" has unknown specifier %$1");
+        error("undefined expansion %$1 in \"$str\"") unless defined $x;
         $x;
     #ge;
     return $str;
@@ -92,11 +116,16 @@ do {
 
     if (defined $OPTS{config} or -e $conffile) {
         print STDERR "Using configuration file: $conffile\n" if $OPTS{debug};
-        my $h = Config::Tiny::->read($conffile) or die Config::Tiny::->errstr()."\n";
+        my $h = Config::Tiny::->read($conffile) or error(Config::Tiny::->errstr());
         my $h2 = delete $h->{_} // {};
-        die "Invalid section(s): ".join(', ', keys %$h)."\n" if %$h;
-        my %h = map { $_ => delete $h2->{$_} } qw/privkey gpg socket quiet/;
-        die "Unknown option(s): ".join(', ', keys %$h2)."\n" if %$h2;
+        if (defined (my $logfile = $h2->{logfile})) {
+            $logfile = spec_expand($logfile);
+            die "Invalid log file name\n" unless $logfile =~ /\A(\p{Print}+)\z/; # untaint
+            open $LOG, ">>", $1 or die "Can't open $1: $!";
+        }
+        error("Invalid section(s): ".join(', ', keys %$h)) if %$h;
+        my %h = map { $_ => delete $h2->{$_} } qw/privkey gpg socket logfile quiet/;
+        error("Unknown option(s): ".join(', ', keys %$h2)) if %$h2;
         $h{quiet} = lc $h{quiet} eq 'yes' ? 1 : 0 if defined $h{quiet};
         $OPTS{$_} //= $h{$_} foreach grep {defined $h{$_}} keys %h;
     } else {
@@ -104,7 +133,7 @@ do {
     }
 
     $OPTS{quiet} = 0 if $OPTS{debug};
-    die "Error: 'privkey' is not specified\n" unless defined $OPTS{privkey};
+    error("'privkey' is not specified") unless defined $OPTS{privkey};
 };
 
 
@@ -118,27 +147,27 @@ if ($OPTS{privkey} =~ /\A(file|gpg):(\p{Print}+)\z/) {
     my ($fh, @command);
     if ($method eq 'file') {
         # generate with `openssl genpkey -algorithm RSA`
-        open $fh, '<', $filename or die "Error: Can't open $filename: $!\n";
+        open $fh, '<', $filename or error("Can't open $filename: $!");
     }
     elsif ($method eq 'gpg') {
         @command = split /\s+/, ($OPTS{gpg} // 'gpg --quiet');
-        open $fh, '-|', @command, qw/-o - --decrypt --/, $filename or die "fork: $!";
+        open $fh, '-|', @command, qw/-o - --decrypt --/, $filename or panic("fork: $!");
     }
     else {
-        die; # impossible
+        panic(); # impossible
     }
 
     my $str = do {local $/ = undef; <$fh>};
-    close $fh or die $! ?
-        "close: $!" :
-        "Error: $command[0] exited with value ".($? >> 8)."\n";
+    close $fh or ($! or !@command) ?
+        panic("close: $!") :
+        error("$command[0] exited with value ".($? >> 8));
 
     require 'Crypt/OpenSSL/RSA.pm';
     my $rsa = Crypt::OpenSSL::RSA->new_private_key($str);
     undef $str;
 
-    die "Error: $filename: Not a private key\n" unless $rsa->is_private();
-    die "Error: $filename: Invalid key\n"       unless $rsa->check_key();
+    error("$filename: Not a private key") unless $rsa->is_private();
+    error("$filename: Invalid key")       unless $rsa->check_key();
     $rsa->use_sha256_hash();
 
     require 'Crypt/OpenSSL/Bignum.pm';
@@ -149,7 +178,7 @@ if ($OPTS{privkey} =~ /\A(file|gpg):(\p{Print}+)\z/) {
     $SIGN = sub($) { $rsa->sign($_[0]) };
 }
 else {
-    die "Error: unsupported method: $OPTS{privkey}\n";
+    error("unsupported method: $OPTS{privkey}");
 }
 my $JWK_STR = JSON::->new->encode($JWK);
 
@@ -163,24 +192,24 @@ my $JWK_STR = JSON::->new->encode($JWK);
 #
 unless (defined $OPTS{stdio}) {
     my $sockname = spec_expand($OPTS{socket} // '%t/S.lacme');
-    $sockname = $sockname =~ /\A(\p{Print}+)\z/ ? $1 : die "Invalid socket name\n"; # untaint $sockname
+    $sockname = $sockname =~ /\A(\p{Print}+)\z/ ? $1 : error("Invalid socket name"); # untaint
 
     # ensure we're the only user with write access to the parent dir
     my $dirname = dirname($sockname);
-    my @stat = stat($dirname) or die "stat($dirname): $!\n";
-    die "Error: insecure permissions on $dirname\n" if ($stat[2] & 0022) != 0;
+    my @stat = stat($dirname) or error("stat($dirname): $!");
+    error("Insecure permissions on $dirname") if ($stat[2] & 0022) != 0;
 
-    my $umask = umask(0177) // die "umask: $!";
+    my $umask = umask(0177) // panic("umask: $!");
 
-    print STDERR "Starting lacme Account Key Manager at $sockname\n" unless $OPTS{quiet};
-    socket(my $sock, PF_UNIX, SOCK_STREAM, 0) or die "socket: $!";
-    my $sockaddr = Socket::sockaddr_un($sockname) // die;
-    bind($sock, $sockaddr) or die "bind: $!";
+    logmsg(noquiet => "Starting lacme Account Key Manager at $sockname");
+    socket(my $sock, PF_UNIX, SOCK_STREAM, 0) or panic("socket: $!");
+    my $sockaddr = Socket::sockaddr_un($sockname) // panic();
+    bind($sock, $sockaddr) or panic("bind: $!");
 
     ($SOCKNAME, $S) = ($sockname, $sock);
-    listen($S, 1) or die "listen: $!";
+    listen($S, 1) or panic("listen: $!");
 
-    umask($umask) // die "umask: $!";
+    umask($umask) // panic("umask: $!");
 };
 
 
@@ -194,23 +223,22 @@ sub conn($$;$) {
 
     # sign whatever comes in
     while (defined (my $data = $in->getline())) {
-        $data =~ s/\r\n\z// or die;
+        $data =~ s/\r\n\z// or panic();
 
         my ($protected, $payload) = split(/\./, $data, 2);
         unless (defined $protected and $protected =~ /\A[A-Za-z0-9\-_]+\z/) {
-            print STDERR "[$id] >>> Error: Malformed protected data, refusing to sign!\n";
+            info("[$id] >>> Error: Malformed protected data, refusing to sign!");
             last;
         }
         unless (defined $payload and $payload =~ /\A[A-Za-z0-9\-_]*\z/) {
             # payload can be empty, for instance for POST-as-GET
-            print STDERR "[$id] >>> Error: Malformed payload data, refusing to sign!\n";
+            info("[$id] >>> Error: Malformed payload data, refusing to sign!");
             last;
         }
 
-        print STDERR "[$id] >>> Incoming signature request for ",
-            "base64url(", decode_base64url($protected), ") . ",
-            "base64url(", decode_base64url($payload), ")"
-            unless $OPTS{quiet};
+        logmsg(noquiet => "[$id] >>> Incoming signature request for ",
+               "base64url(", decode_base64url($protected), ") . ",
+               "base64url(", decode_base64url($payload), ")");
 
         my $sig = $SIGN->($data);
         $out->printflush( encode_base64url($sig), "\r\n" ) or warn "print: $!";
@@ -224,11 +252,11 @@ if (defined $OPTS{stdio}) {
     for (my $count = 0;; $count++) {
         accept(my $conn, $S) or do {
             next if $! == EINTR; # try again if accept(2) was interrupted by a signal
-            die "accept: $!";
+            panic("accept: $!");
         };
-        print STDERR "[$count] >>> Accepted new connection\n" unless $OPTS{quiet};
+        logmsg(noquiet => "[$count] >>> Accepted new connection");
         conn($conn, $conn, $count);
-        print STDERR "[$count] >>> Connection terminated\n" unless $OPTS{quiet};
+        logmsg(noquiet => "[$count] >>> Connection terminated");
         $conn->close() or warn "close: $!";
     }
 }
@@ -238,12 +266,12 @@ if (defined $OPTS{stdio}) {
 #
 END {
     if (defined $SOCKNAME and -S $SOCKNAME) {
-        print STDERR "Unlinking $SOCKNAME\n" if $OPTS{debug};
-        unlink $SOCKNAME or print STDERR "Couldn't unlink $SOCKNAME: $!\n";
+        logmsg(debug => "Unlinking $SOCKNAME");
+        unlink $SOCKNAME or info("Error: unlink($SOCKNAME): $!");
     }
     if (defined $S) {
-        print STDERR "Shutting down and closing lacme Account Key Manager\n" unless $OPTS{quiet};
-        shutdown($S, SHUT_RDWR) or warn "shutdown: $!";
-        close $S or print STDERR "close: $!\n";
+        logmsg(noquiet => "Shutting down and closing lacme Account Key Manager");
+        shutdown($S, SHUT_RDWR) or info("Error: shutdown: $!");
+        close $S or info("Error: close: $!");
     }
 }
diff --git a/lacme-accountd.1.md b/lacme-accountd.1.md
index 476a150..66ef222 100644
--- a/lacme-accountd.1.md
+++ b/lacme-accountd.1.md
@@ -119,6 +119,11 @@ leading `--`) in the configuration file.  Valid settings are:
     [`gpg`(1)] to use, as well as some default options.
     Default: `gpg --quiet`.
 
+*logfile*
+
+:   An optional file where to log to.  The value is subject to
+    [%-specifier expansion](#percent-specifiers).
+
 *socket*
 
 :   See `--socket=`.
@@ -131,8 +136,8 @@ leading `--`) in the configuration file.  Valid settings are:
 ============
 
 The value the `--config=`, `--privkey=` and `--socket=` CLI options (and
-*privkey* and *socket* configuration options) are subject to %-expansion
-for the following specifiers.
+*privkey*, *socket* and *logfile* settings in the configuration file)
+are subject to %-expansion for the following specifiers.
 
 ----  ------------------------------------------------------------------
 `%C`  `@@localstatedir@@/cache` for the root user, and `$XDG_CACHE_HOME`
diff --git a/lacme.8.md b/lacme.8.md
index ca47470..7d66e79 100644
--- a/lacme.8.md
+++ b/lacme.8.md
@@ -497,7 +497,7 @@ remote [`lacme-accountd`(1)] and use it to sign [ACME] requests.
 Further hardening can be achieved by means of [`authorized_keys`(5)]
 restrictions:
 
-    restrict,from="…",command="/usr/bin/lacme-accountd --stdio" ssh-rsa …
+    restrict,from="…",command="/usr/bin/lacme-accountd --quiet --stdio" ssh-rsa …
 
 See also
 ========
diff --git a/tests/accountd b/tests/accountd
index 4626c78..2798465 100644
--- a/tests/accountd
+++ b/tests/accountd
@@ -7,11 +7,11 @@ adduser --disabled-password \
 
 # non-existent parent directory
 ! lacme --socket="/nonexistent/S.lacme" account 2>"$STDERR" || fail
-grepstderr -Fxq "stat(/nonexistent): No such file or directory"
+grepstderr -Fxq "Error: stat(/nonexistent): No such file or directory"
 
 # word-writable parent directory
 ! lacme --socket="/tmp/S.lacme" account 2>"$STDERR" || fail
-grepstderr -Fxq "Error: insecure permissions on /tmp"
+grepstderr -Fxq "Error: Insecure permissions on /tmp"
 
 # missing socket
 SOCKET=~lacme-account/S.lacme
@@ -25,21 +25,23 @@ grepstderr -Fxq "Can't stat $SOCKET: No such file or directory (Is lacme-account
 grepstderr -Fxq "Ignoring missing configuration file at default location /home/lacme-account/.config/lacme/lacme-accountd.conf"
 grepstderr -Fxq "Error: 'privkey' is not specified"
 
-install -olacme-account -glacme-account -Ddm0700 ~lacme-account/.config/lacme
+install -olacme-account -glacme-account -Ddm0700 -- \
+    ~lacme-account/.config/lacme ~lacme-account/.local/share/lacme
 mv -t ~lacme-account/.config/lacme /etc/lacme/account.key
 chown lacme-account: ~lacme-account/.config/lacme/account.key
 
 cat >~lacme-account/.config/lacme/lacme-accountd.conf <<-EOF
 	privkey = file:%E/lacme/account.key
+	logfile = %h/.local/share/lacme/accountd.log
 EOF
 
 # non-existent parent directory
 ! runuser -u lacme-account -- lacme-accountd --socket="/nonexistent/S.lacme" 2>"$STDERR" || fail
-grepstderr -Fxq "stat(/nonexistent): No such file or directory"
+grepstderr -Fxq "Error: stat(/nonexistent): No such file or directory"
 
 # word-writable parent directory
 ! runuser -u lacme-account -- lacme-accountd --socket="%T/S.lacme" account 2>"$STDERR" || fail
-grepstderr -Fxq "Error: insecure permissions on /tmp"
+grepstderr -Fxq "Error: Insecure permissions on /tmp"
 
 # unset XDG_RUNTIME_DIR
 ! runuser -u lacme-account -- lacme-accountd 2>"$STDERR" || fail
@@ -47,7 +49,7 @@ grepstderr "Error: undefined expansion %t in \"%t/S.lacme\""
 
 # non-existent $XDG_RUNTIME_DIR
 ! runuser -u lacme-account -- env XDG_RUNTIME_DIR="/nonexistent" lacme-accountd 2>"$STDERR" || fail
-grepstderr -Fxq "stat(/nonexistent): No such file or directory"
+grepstderr -Fxq "Error: stat(/nonexistent): No such file or directory"
 
 # test running accountd
 runuser -u lacme-account -- env XDG_RUNTIME_DIR=/home/lacme-account lacme-accountd --debug 2>"$STDERR" & PID=$!
@@ -57,7 +59,11 @@ wait || fail
 grepstderr -Fxq "Using configuration file: /home/lacme-account/.config/lacme/lacme-accountd.conf"
 grepstderr -Fxq "Starting lacme Account Key Manager at /home/lacme-account/S.lacme"
 
-# spawn accountd
+# make sure errors are logged too
+grep -F "Error: " ~lacme-account/.local/share/lacme/accountd.log
+
+# rotate the log and start accountd
+rm -f ~lacme-account/.local/share/lacme/accountd.log
 runuser -u lacme-account -- lacme-accountd --socket="$SOCKET" --quiet & PID=$!
 
 # run lacme(8) multiple times using that single lacme-accountd(1) instance
@@ -70,4 +76,11 @@ kill $PID
 wait
 ! test -e "$SOCKET"
 
+# ensure signature requests are logged
+grep -Fq "Starting lacme Account Key Manager at /home/lacme-account/S.lacme" ~lacme-account/.local/share/lacme/accountd.log
+grep -Fq "[0] >>> Accepted new connection" ~lacme-account/.local/share/lacme/accountd.log
+grep -Fq "[1] >>> Accepted new connection" ~lacme-account/.local/share/lacme/accountd.log
+grep -Fq "Shutting down and closing lacme Account Key Manager" ~lacme-account/.local/share/lacme/accountd.log
+grep -F ">>> Incoming signature request for " ~lacme-account/.local/share/lacme/accountd.log
+
 # vim: set filetype=sh :
diff --git a/tests/accountd-remote b/tests/accountd-remote
index bd5d99f..05850c2 100644
--- a/tests/accountd-remote
+++ b/tests/accountd-remote
@@ -31,20 +31,25 @@ lacme newOrder --debug 2>"$STDERR" || fail # intentionally use --debug, ssh shou
 test /etc/lacme/simpletest.rsa.crt -nt /etc/lacme/simpletest.rsa.key
 
 # and now with an authorized_keys(5) restriction
-sed -ri "s|^[^#]|restrict,from=\"127.0.0.1\",command=\"/usr/bin/lacme-accountd --stdio\" &|" ~lacme-account/.ssh/authorized_keys
+sed -ri "s|^[^#]|restrict,from=\"127.0.0.1\",command=\"/usr/bin/lacme-accountd --quiet --stdio\" &|" ~lacme-account/.ssh/authorized_keys
 rm -vf /etc/lacme/simpletest.rsa.crt
 
 ! lacme newOrder 2>"$STDERR" || fail # --config= (and --debug) should be ignored
 grepstderr -Fxq "Error: 'privkey' is not specified"
 grepstderr -Fxq "[simpletest-rsa] Error: Couldn't issue X.509 certificate!"
 
-install -olacme-account -glacme-account -Ddm0700 ~lacme-account/.config/lacme
+install -olacme-account -glacme-account -Ddm0700 -- \
+    ~lacme-account/.config/lacme ~lacme-account/.local/share/lacme
 mv -t ~lacme-account/.config/lacme /etc/lacme/account.key
 cat >~lacme-account/.config/lacme/lacme-accountd.conf <<-EOF
 	privkey = file:%E/lacme/account.key
+	logfile = %h/.local/share/lacme/accountd.log
 EOF
 
-lacme newOrder || fail
+lacme newOrder
 test /etc/lacme/simpletest.rsa.crt -nt /etc/lacme/simpletest.rsa.key
 
+# ensure signature requests are logged
+grep -F ">>> Incoming signature request for " ~lacme-account/.local/share/lacme/accountd.log
+
 # vim: set filetype=sh :
diff --git a/tests/spec-expansion b/tests/spec-expansion
index 722bdfc..273fa51 100644
--- a/tests/spec-expansion
+++ b/tests/spec-expansion
@@ -48,11 +48,11 @@ grepstderr -Fxq "Reading /etc/lacme/certs.conf.d"
 # 'config' setting in [accountd] section (expands after privilege drop)
 sed -ri 's|^#?config\s*=\s*$|config = /nonexistent/%u:%g.conf|' /etc/lacme/lacme.conf
 ! lacme account 2>"$STDERR" || fail
-grepstderr -Fxq "Failed to open file '/nonexistent/root:root.conf' for reading: No such file or directory"
+grepstderr -Fxq "Error: Failed to open file '/nonexistent/root:root.conf' for reading: No such file or directory"
 
 sed -ri 's|^#?user\s*=\s*$|user = nobody|' /etc/lacme/lacme.conf
 ! lacme account 2>"$STDERR" || fail
-grepstderr -Fxq "Failed to open file '/nonexistent/nobody:root.conf' for reading: No such file or directory"
+grepstderr -Fxq "Error: Failed to open file '/nonexistent/nobody:root.conf' for reading: No such file or directory"
 
 # 'command' setting in [accountd] section (expands after privilege drop)
 sed -ri 's|^#?command\s*=.*/lacme-accountd$|command = /usr/bin/lacme-accountd --%u|' /etc/lacme/lacme.conf
@@ -68,12 +68,12 @@ grepstderr -Eq "^Can't exec \"/nonexistent/nobody/root\": No such file or direct
 
 # lacme-accountd --config=, all specifiers, root privileges
 ! lacme-accountd --config="%C %E %t %h %T %g %G %u %U %%.conf" 2>"$STDERR" || fail
-grepstderr -Fxq "Failed to open file '/var/cache /etc /run /root /tmp root 0 root 0 %.conf' for reading: No such file or directory"
+grepstderr -Fxq "Error: Failed to open file '/var/cache /etc /run /root /tmp root 0 root 0 %.conf' for reading: No such file or directory"
 
 # lacme-accountd --config=, all specifiers, root privileges, defined XDG_*
 ! env XDG_CACHE_HOME=/foo/cache XDG_CONFIG_HOME=/foo/config XDG_RUNTIME_DIR=/foo/run HOME=/foo/home USER=myuser TMPDIR=/foo/tmp \
     lacme-accountd --config="%C %E %t %h %T %g %G %u %U %%.conf" 2>"$STDERR" || fail
-grepstderr -Fxq "Failed to open file '/var/cache /etc /run /root /foo/tmp root 0 root 0 %.conf' for reading: No such file or directory"
+grepstderr -Fxq "Error: Failed to open file '/var/cache /etc /run /root /foo/tmp root 0 root 0 %.conf' for reading: No such file or directory"
 
 # lacme-accountd --config=, all specifiers, non-root, unset XDG_RUNTIME_DIR
 ! runuser -u nobody -- lacme-accountd --config="%C %E %t %h %T %g %G %u %U %%.conf" account 2>"$STDERR" || fail
@@ -82,12 +82,12 @@ grepstderr -Fxq "Error: undefined expansion %t in \"%C %E %t %h %T %g %G %u %U %
 # lacme-accountd --config=, all specifiers, non-root, defined XDG_RUNTIME_DIR, no other XDG_*
 ! runuser -u nobody -g www-data -- env XDG_RUNTIME_DIR=/foo/run \
     lacme-accountd --config="%C %E %t %h %T %g %G %u %U %%.conf" 2>"$STDERR" || fail
-grepstderr -Fxq "Failed to open file '/nonexistent/.cache /nonexistent/.config /foo/run /nonexistent /tmp www-data 33 nobody 65534 %.conf' for reading: No such file or directory"
+grepstderr -Fxq "Error: Failed to open file '/nonexistent/.cache /nonexistent/.config /foo/run /nonexistent /tmp www-data 33 nobody 65534 %.conf' for reading: No such file or directory"
 
 # lacme-accountd --config=, all specifiers, non-root, defined XDG_*
 ! runuser -u nobody -- env XDG_CACHE_HOME=/foo/cache XDG_CONFIG_HOME=/foo/config XDG_RUNTIME_DIR=/foo/run HOME=/foo/home USER=myuser TMPDIR=/foo/tmp \
     lacme-accountd --config="%C %E %t %h %T %g %G %u %U %%.conf" 2>"$STDERR" || fail
-grepstderr -Fxq "Failed to open file '/foo/cache /foo/config /foo/run /nonexistent /foo/tmp nogroup 65534 nobody 65534 %.conf' for reading: No such file or directory"
+grepstderr -Fxq "Error: Failed to open file '/foo/cache /foo/config /foo/run /nonexistent /foo/tmp nogroup 65534 nobody 65534 %.conf' for reading: No such file or directory"
 
 # lacme-accountd --privkey=
 ! lacme-accountd --privkey="file:%h/lacme-accountd.key" --debug 2>"$STDERR" || fail