Re: libpq debug log

Alvaro Herrera <alvherre@alvh.no-ip.org>

From: "alvherre@alvh.no-ip.org" <alvherre@alvh.no-ip.org>
To: "tsunakawa.takay@fujitsu.com" <tsunakawa.takay@fujitsu.com>
Cc: "iwata.aya@fujitsu.com" <iwata.aya@fujitsu.com>, 'Kyotaro Horiguchi' <horikyota.ntt@gmail.com>, "tgl@sss.pgh.pa.us" <tgl@sss.pgh.pa.us>, "k.jamison@fujitsu.com" <k.jamison@fujitsu.com>, "pgsql-hackers@lists.postgresql.org" <pgsql-hackers@lists.postgresql.org>
Date: 2021-03-26T19:48:42Z
Lists: pgsql-hackers
Hello

I added an option to the new libpq_pipeline program that it activates
libpq trace.  It works nicely and I think we can add that to the
regression tests.  However I have two observations.

1. The trace output for the error message won't be very nice, because it
prints line numbers.  So if I want to match the output to an "expected"
file, it would break every time somebody edits the source file where the
error originates and the ereport() line is moved.  For example:

	<	70	ErrorResponse	 S "ERROR" V "ERROR" C "22012" M "division by zero" F "numeric.c" L "8366" R "div_var" \x00 "Z"

The line number 8366 in this line would be problematic.  I think if we
want regression testing for this, we should have another trace flag to
suppress output of a few of these fields.  I would have it print only S,
C and M.

(Hey, what the heck is that "Z" at the end of the message?  I thought
the error ended right at the \x00 ...)


2. The < and > characters are not good for visual inspection.  I
replaced them with F and B and I think it's much clearer.  Compare:

	>	27	Query	 "SET lc_messages TO "C""
	<	8	CommandComplete	 "SET"
	<	5	ReadyForQuery	 I
	>	21	Parse	 "" "SELECT $1" 1 23
	>	19	Bind	 "" "" 0 1 1 '1' 1 0
	>	6	Describe	 P ""
	>	9	Execute	 "" 0
	>	4	Sync
	<	4	ParseComplete
	<	4	BindComplete
	<	33	RowDescription	 1 "?column?" 0 0 23 4 -1 0
	<	11	DataRow	 1 1 '1'
	<	13	CommandComplete	 "SELECT 1"
	<	5	ReadyForQuery	 I
	>	4	Terminate

with

	F	27	Query	 "SET lc_messages TO "C""
	B	8	CommandComplete	 "SET"
	B	5	ReadyForQuery	 I
	F	21	Parse	 "" "SELECT $1" 1 23
	F	19	Bind	 "" "" 0 1 1 '1' 1 0
	F	6	Describe	 P ""
	F	9	Execute	 "" 0
	F	4	Sync
	B	4	ParseComplete
	B	4	BindComplete
	B	33	RowDescription	 1 "?column?" 0 0 23 4 -1 0
	B	11	DataRow	 1 1 '1'
	B	13	CommandComplete	 "SELECT 1"
	B	5	ReadyForQuery	 I
	F	4	Terminate

I think the second one is much easier on the eye.

(This one is the output from "libpq_pipeline simple_pipeline").

-- 
Álvaro Herrera       Valdivia, Chile
"Saca el libro que tu religión considere como el indicado para encontrar la
oración que traiga paz a tu alma. Luego rebootea el computador
y ve si funciona" (Carlos Duclós)



Commits

  1. Rename PQtraceSetFlags() to PQsetTraceFlags().

  2. Suppress length of Notice/Error msgs in PQtrace regress mode

  3. Strip file names reported in error messages on Windows, too.

  4. Fix setvbuf()-induced crash in libpq_pipeline

  5. libpq_pipeline: Must strdup(optarg) to avoid crash

  6. Remove setvbuf() call from PQtrace()

  7. Initialize conn->Pfdebug to NULL when creating a connection

  8. Disable force_parallel_mode in libpq_pipeline

  9. libpq_pipeline: add PQtrace() support and tests

  10. Improve PQtrace() output format

  11. Re-simplify management of inStart in pqParseInput3's subroutines.