Обсуждение: Broken PQtrace CopyData display

I used PQtrace to trace a logical decoding session, and was confused to see
lines like this:

2025-08-29 22:09:57.633980    F    38    CopyData
'r\x00\x00\x00\x00\xffffff8e\x07\xffffff85x\x00\x00\x00\x00\xffffff8e\x07\xffffff85x\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\xffffffe0\xffffff84\xffffff89R\xffffffd7\xffffffb8\x00'

The data doesn't make sense and has the wrong length. A quick look shows that
the \xffffff85 parts are a signedness issue (on my compiler char is signed).

I instead expect to see output like this:

2025-08-29 22:39:17.041261    F    38    CopyData
'r\x00\x00\x00\x00\x8e\x07\x89\xf8\x00\x00\x00\x00\x8e\x07\x89\xf8\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\xe0\x84\xf21Dh\x00'

The diff below fixes this particular problem, though they say bugs are like
mushrooms, if you find one then there are probably others nearby, so a more
comprehensive fix may be warranted.

diff --git i/src/interfaces/libpq/fe-trace.c w/src/interfaces/libpq/fe-trace.c
index a45f0d85587..f487c111fc7 100644
--- i/src/interfaces/libpq/fe-trace.c
+++ w/src/interfaces/libpq/fe-trace.c
@@ -212,7 +212,7 @@ pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor, bool s
         else
         {
             fwrite(v + next, 1, i - next, pfdebug);
-            fprintf(pfdebug, "\\x%02x", v[i]);
+            fprintf(pfdebug, "\\x%02x", (unsigned char) v[i]);
             next = i + 1;
         }
     }

On Fri, Aug 29, 2025 at 10:45:18PM +0300, Ran Benita wrote:
> I used PQtrace to trace a logical decoding session, and was confused to see
> lines like this:
>
> 2025-08-29 22:09:57.633980    F    38    CopyData
'r\x00\x00\x00\x00\xffffff8e\x07\xffffff85x\x00\x00\x00\x00\xffffff8e\x07\xffffff85x\x00\x00\x00\x00\x00\x00\x00\x00\x00\x02\xffffffe0\xffffff84\xffffff89R\xffffffd7\xffffffb8\x00'
>
> The data doesn't make sense and has the wrong length. A quick look shows that
> the \xffffff85 parts are a signedness issue (on my compiler char is signed).
>
> @@ -212,7 +212,7 @@ pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor, bool s
>          else
>          {
>              fwrite(v + next, 1, i - next, pfdebug);
> -            fprintf(pfdebug, "\\x%02x", v[i]);
> +            fprintf(pfdebug, "\\x%02x", (unsigned char) v[i]);
>              next = i + 1;
>          }
>      }

Yeah.  Not a lot of people use the libpq tracing, but it would be
better to show non-printable data in a consistent way.

> The diff below fixes this particular problem, though they say bugs are like
> mushrooms, if you find one then there are probably others nearby, so a more
> comprehensive fix may be warranted.

There's one more mushroom: pqTraceOutputByte1() also uses a %02X
without a cast for non-printable data.  Note as well
logicalmsg_desc(), auth-oauth.c, mbprint.c (which uses an unsigned
char type in input to force things).
--
Michael

On Sun, Aug 31, 2025 at 01:53:50PM +0900, Michael Paquier wrote:
> Yeah.  Not a lot of people use the libpq tracing, but it would be
> better to show non-printable data in a consistent way.

Done this one with db9405493b48.
--
Michael

On 2025-Sep-03, Michael Paquier wrote:

> On Sun, Aug 31, 2025 at 01:53:50PM +0900, Michael Paquier wrote:
> > Yeah.  Not a lot of people use the libpq tracing, but it would be
> > better to show non-printable data in a consistent way.
> 
> Done this one with db9405493b48.

Thanks!

-- 
Álvaro Herrera               48°01'N 7°57'E  —  https://www.EnterpriseDB.com/
"La persona que no quería pecar / estaba obligada a sentarse
 en duras y empinadas sillas    / desprovistas, por cierto
 de blandos atenuantes"                          (Patricio Vogel)