Re: libpq debug log - Mailing list pgsql-hackers

From 'alvherre@alvh.no-ip.org'
Subject Re: libpq debug log
Date
Msg-id 20210331002400.GA21316@alvherre.pgsql
Whole thread Raw
In response to Re: libpq debug log  ("'alvherre@alvh.no-ip.org'" <alvherre@alvh.no-ip.org>)
Responses Re: libpq debug log  ("'alvherre@alvh.no-ip.org'" <alvherre@alvh.no-ip.org>)
Re: libpq debug log  (Tom Lane <tgl@sss.pgh.pa.us>)
List pgsql-hackers
So crake failed.  The failure is that it doesn't print the DataRow
messages.  That's quite odd.  We see this in the trace log:

Mar 30 20:05:15 # F    54    Parse     "" "SELECT 1.0/g FROM generate_series(3, -1, -1) g" 0
Mar 30 20:05:15 # F    12    Bind     "" "" 0 0 0
Mar 30 20:05:15 # F    6    Describe     P ""
Mar 30 20:05:15 # F    9    Execute     "" 0
Mar 30 20:05:15 # F    4    Sync
Mar 30 20:05:15 # B    4    ParseComplete
Mar 30 20:05:15 # B    4    BindComplete
Mar 30 20:05:15 # B    33    RowDescription     1 "?column?" NNNN 0 NNNN 65535 -1 0
Mar 30 20:05:15 # B    70    ErrorResponse     S "ERROR" V "ERROR" C "22012" M "division by zero" F "SSSS" L "SSSS" R
"SSSS"\\x00
 
Mar 30 20:05:15 # B    5    ReadyForQuery     I

and the expected is this:

Mar 30 20:05:15 # F    54    Parse     "" "SELECT 1.0/g FROM generate_series(3, -1, -1) g" 0
Mar 30 20:05:15 # F    12    Bind     "" "" 0 0 0
Mar 30 20:05:15 # F    6    Describe     P ""
Mar 30 20:05:15 # F    9    Execute     "" 0
Mar 30 20:05:15 # F    4    Sync
Mar 30 20:05:15 # B    4    ParseComplete
Mar 30 20:05:15 # B    4    BindComplete
Mar 30 20:05:15 # B    33    RowDescription     1 "?column?" NNNN 0 NNNN 65535 -1 0
Mar 30 20:05:15 # B    32    DataRow     1 22 '0.33333333333333333333'
Mar 30 20:05:15 # B    32    DataRow     1 22 '0.50000000000000000000'
Mar 30 20:05:15 # B    32    DataRow     1 22 '1.00000000000000000000'
Mar 30 20:05:15 # B    70    ErrorResponse     S "ERROR" V "ERROR" C "22012" M "division by zero" F "SSSS" L "SSSS" R
"SSSS"\\x00
 
Mar 30 20:05:15 # B    5    ReadyForQuery     I


...

I wonder if this is a libpq pipeline problem rather than a PQtrace
problem.  In that test case we're using the libpq singlerow mode, so we
should see three rows before the error is sent, but for some reason
crake is not doing that.

aborted pipeline... NOTICE:  table "pq_pipeline_demo" does not exist, skipping
ok
got expected ERROR:  cannot insert multiple commands into a prepared statement
got expected division-by-zero
ok 5 - libpq_pipeline pipeline_abort
not ok 6 - pipeline_abort trace match


Other hosts seem to get it right:

# Running: libpq_pipeline -t
/Users/buildfarm/bf-data/HEAD/pgsql.build/src/test/modules/libpq_pipeline/tmp_check/log/pipeline_abort.trace
pipeline_abortport=49797 host=/var/folders/md/8mp8j5m5169ccgy11plb4w_80000gp/T/iA9YP9_IHa dbname='postgres' 10000
 
aborted pipeline... NOTICE:  table "pq_pipeline_demo" does not exist, skipping
ok
got expected ERROR:  cannot insert multiple commands into a prepared statement
got row: 0.33333333333333333333
got row: 0.50000000000000000000
got row: 1.00000000000000000000
got expected division-by-zero
ok 5 - libpq_pipeline pipeline_abort
ok 6 - pipeline_abort trace match


-- 
Álvaro Herrera       Valdivia, Chile
"This is what I like so much about PostgreSQL.  Most of the surprises
are of the "oh wow!  That's cool" Not the "oh shit!" kind.  :)"
Scott Marlowe, http://archives.postgresql.org/pgsql-admin/2008-10/msg00152.php



pgsql-hackers by date:

Previous
From: Joe Conway
Date:
Subject: Re: "has_column_privilege()" issue with attnums and non-existent columns
Next
From: Michael Paquier
Date:
Subject: Re: Outdated comment for CreateStmt.inhRelations