From 817fa600d0ccc66bdc2e6d0e501e557a01be69d9 Mon Sep 17 00:00:00 2001
From: Yorhel <git@yorhel.nl>
Date: Sun, 27 Apr 2025 11:17:54 +0200
Subject: [PATCH] FU: Add fu->log_verbose() + include request body in error
 logs

---
 FU.pm | 44 ++++++++++++++++++++++++++++++++------------
 1 file changed, 32 insertions(+), 12 deletions(-)

diff --git a/FU.pm b/FU.pm
index 04809b5..11c58ff 100644
--- a/FU.pm
+++ b/FU.pm
@@ -303,7 +303,7 @@ sub _read_req($c) {
 
     ($REQ->{path}, my $qs) = split /\?/, $REQ->{path}//'', 2;
     $REQ->{qs} //= $qs;
-    $REQ->{path} = FU::Util::uri_unescape($REQ->{path});
+    eval { $REQ->{path} = FU::Util::uri_unescape($REQ->{path}); 1; } || fu->error(400, $@);
 }
 
 
@@ -313,17 +313,8 @@ sub _log_err($e) {
     return if !$e;
     my $crit = $e isa 'FU::err' ? $e->[0] == 500 : !($e isa 'FU::Validate::err');
     return if !debug && !$crit;
-    if ($crit && !$REQ->{full_err}++) {
-        $e =~ s/^\s+//;
-        $e =~ s/\s+$//;
-        log_write join "\n",
-            'IP: '.($REQ->{ip}||'-'),
-            'Headers:', (map "  $_: $REQ->{hdr}{$_}", sort keys $REQ->{hdr}->%*),
-            'ERROR:'.($e =~ s/(^|\n)/\n  /rg);
-            # TODO: decoded body, if we have that.
-    } else {
-        log_write $e;
-    }
+    return fu->log_verbose($e) if $crit;
+    log_write $e;
 }
 
 sub _do_req($c) {
@@ -643,6 +634,27 @@ sub db {
 sub sql { shift->db->q(@_) }
 sub SQL { shift->db->Q(@_) }
 
+sub _fmt_section($s) { $s =~ s/^\s*/  /r =~ s/\s+$//r =~ s/\n/\n  /rg }
+
+sub log_verbose($,$msg) {
+    my $r = $FU::REQ;
+    return FU::Log::log_write($msg) if $r->{log_verbose}++;
+    FU::Log::log_write(join "\n",
+        'IP: '.($r->{ip}||'-'),
+        'Headers:', (map "  $_: $r->{hdr}{$_}", sort keys $r->{hdr}->%*),
+        $r->{multipart} ? ('Body (multipart):', _fmt_section join "\n", map $_->describe, $r->{multipart}->@*) :
+        $r->{json} ? ('Body (JSON):', _fmt_section FU::Util::json_format($r->{json}, pretty => 1, canonical => 1)) :
+        $r->{formdata} ? ('Body (formdata):', _fmt_section FU::Util::json_format($r->{json}, pretty => 1, canonical => 1)) :
+        length $r->{body} ? do {
+            my $b = substr $r->{body}, 0, 4096;
+            my $trunc = length $r->{body} > 4096 ? ', truncated' : '';
+            utf8::decode($b) ? ("Body (utf8$trunc)", _fmt_section($b =~ s/\r//rg =~ s/\n{4,}/\n[..]\n/rg))
+                             : ("Body (hex$trunc)", _fmt_section(unpack('H*', $b) =~ s/(.{128})/$1\n/rg))
+        } : (),
+        'Message:', _fmt_section $msg
+    );
+}
+
 
 
 
@@ -1286,6 +1298,14 @@ Convenient short-hand for C<< fu->db->q($query, @params) >>.
 
 Convenient short-hand for C<< fu->db->Q(@args) >>.
 
+=item fu->log_verbose($message)
+
+Write a verbose multi-line message to the log, including a full dump of
+information about the request: IP, headers and (potentially reformatted and/or
+truncated) body. This extra info is only written once per request, further
+calls to C<log_verbose()> just go directly to L<FU::Log>'s C<log_write()>
+instead.
+
 =back
 
 =head1 Request Information