From 87fa9468a26c1902423839473049cd3325098c1a Mon Sep 17 00:00:00 2001 From: Guilhem Moulin Date: Mon, 22 Feb 2021 14:49:00 +0100 Subject: lacme-account: Improve log messages. MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Again… --- Changelog | 1 + lacme-accountd | 23 ++++++++++++----------- tests/accountd | 6 +++--- tests/accountd-kid | 8 ++++---- tests/accountd-remote | 2 +- 5 files changed, 21 insertions(+), 19 deletions(-) diff --git a/Changelog b/Changelog index 3765bf9..faf32a8 100644 --- a/Changelog +++ b/Changelog @@ -1,5 +1,6 @@ lacme (0.8.1) upstream; + + lacme-accountd: improve log messages. - lacme: in the [accountd] config, let lacme-accountd(1) do the %-expansion for 'config', not lacme(8) when building the command. diff --git a/lacme-accountd b/lacme-accountd index 5794ec1..68d0f39 100755 --- a/lacme-accountd +++ b/lacme-accountd @@ -83,7 +83,8 @@ sub error(@) { } sub panic(@) { my @loc = caller; - my @msg = (@_, " at line $loc[2] in $loc[1]"); + my @msg = ("PANIC at line $loc[2] in $loc[1]"); + push @msg, ": ", @_ if @_; info(@msg); exit 255; } @@ -234,29 +235,29 @@ sub conn($$$) { $out->printflush( "$PROTOCOL_VERSION OK ", $EXTRA_GREETING_STR, "\r\n", $JWK_STR, "\r\n" ) or warn "print: $!"; - # sign whatever comes in while (defined (my $data = $in->getline())) { $data =~ s/\r\n\z// or panic(); + # validate JWS Signing Input from RFC 7515: + # ASCII(BASE64URL(UTF8(JWS Protected Header)) || '.' || BASE64URL(JWS Payload)) my ($header, $payload) = split(/\./, $data, 2); if (defined $header and $header =~ /\A[A-Za-z0-9\-_]+\z/) { $header = decode_base64url($header); } else { - info("[$id] >>> Error: Refusing to sign request: Malformed protected header"); + info("[$id] NOSIGN [malformed JWS Protected Header]"); last; } if (defined $payload and $payload =~ /\A[A-Za-z0-9\-_]*\z/) { - # empty payloads are valid, cf. POST-as-GET + # empty payloads are valid, and used for POST-as-GET (RFC 8555 sec. 6.3) $payload = decode_base64url($payload); } else { - info("[$id] >>> Error: Refusing to sign request: Malformed payload"); + info("[$id] NOSIGN [malformed JWS Payload]"); last; } - my $req = "header=base64url($header); playload=base64url($payload)"; - logmsg(noquiet => "[$id] >>> OK signing request: ", $req); - - my $sig = $SIGN->($data); + my $req = "header=base64url($header) playload=base64url($payload)"; + my $sig = $SIGN->($data) // panic(); + logmsg(noquiet => "[$id] SIGNED ", $req); $out->printflush( encode_base64url($sig), "\r\n" ) or warn "print: $!"; } } @@ -270,9 +271,9 @@ if (defined $OPTS{stdio}) { next if $! == EINTR; # try again if accept(2) was interrupted by a signal panic("accept: $!"); }; - logmsg(noquiet => "[$count] >>> Accepted new connection"); + logmsg(noquiet => "[$count] Accepted new connection"); conn($conn, $conn, $count); - logmsg(noquiet => "[$count] >>> Connection terminated"); + logmsg(noquiet => "[$count] Connection terminated"); $conn->close() or warn "close: $!"; } } diff --git a/tests/accountd b/tests/accountd index a603c16..7e8fd4c 100644 --- a/tests/accountd +++ b/tests/accountd @@ -79,9 +79,9 @@ wait # 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 "[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 ">>> OK signing request:" ~lacme-account/.local/share/lacme/accountd.log +grep -F "] SIGNED header=base64url({" ~lacme-account/.local/share/lacme/accountd.log # vim: set filetype=sh : diff --git a/tests/accountd-kid b/tests/accountd-kid index e1bd63d..f55facf 100644 --- a/tests/accountd-kid +++ b/tests/accountd-kid @@ -28,8 +28,8 @@ runuser -u lacme-account -- lacme-accountd --socket="$SOCKET" --quiet & PID=$! ! lacme --socket="$SOCKET" account 2>"$STDERR" || fail grepstderr -Fxq "WARNING: lacme-accountd supplied an empty JWK; try removing 'keyid' setting from lacme-accountd.conf if the ACME resource request fails." grepstderr -Fxq "400 Bad Request (Parse error reading JWS)" -! grep -F ">>> OK signing request: header=" ~lacme-account/.local/share/lacme/accountd.log | \ - grep -vF ">>> OK signing request: header=base64url({\"alg\":\"RS256\",\"jwk\":{}," || exit 1 +grep -F "] SIGNED header=base64url({" ~lacme-account/.local/share/lacme/accountd.log >/tmp/signed +! grep -vF "] SIGNED header=base64url({\"alg\":\"RS256\",\"jwk\":{}," >> OK signing request: header=" ~lacme-account/.local/share/lacme/accountd.log | \ - grep -vF ">>> OK signing request: header=base64url({\"alg\":\"RS256\",\"kid\":\"$keyid\"," || exit 1 +grep -F "] SIGNED header=base64url({" ~lacme-account/.local/share/lacme/accountd.log >/tmp/signed +! grep -vF "] SIGNED header=base64url({\"alg\":\"RS256\",\"kid\":\"$keyid\"," >> OK signing request:" ~lacme-account/.local/share/lacme/accountd.log +grep -F "] SIGNED header=base64url({" ~lacme-account/.local/share/lacme/accountd.log # vim: set filetype=sh : -- cgit v1.2.3