BUG #8383: SQL statement error log misses query parameters - Mailing list pgsql-bugs

From aschetinin@gmail.com
Subject BUG #8383: SQL statement error log misses query parameters
Date
Msg-id E1V9Y5X-0000Qp-B7@wrigleys.postgresql.org
Whole thread Raw
List pgsql-bugs
The following bug has been logged on the website:

Bug reference:      8383
Logged by:          Andrew Schetinin
Email address:      aschetinin@gmail.com
PostgreSQL version: 9.1.9
Operating system:   Debian Linux (kernel 3.9.8-1)
Description:

Hi,


I was debugging some problematic SQL INSERT statement which complained about
one of the parameters. In order to try to understand what's wrong with the
parameter in question, I configured detailed SQL statement logs to be
printed by PostgreSQL.


This is the error message (with the SQL statement) I received:


2013-08-14 12:45:47 IDT ERROR:  column "properties" is of type hstore but
expression is of type character varying at character 216
2013-08-14 12:45:47 IDT HINT:  You will need to rewrite or cast the
expression.
2013-08-14 12:45:47 IDT STATEMENT:  INSERT INTO pesticide_rule (id,
active_from, active_until, allowed, classifier, external_id, last_update,
priority, properties, first_id, pesticide_id, project_id, second_id) VALUES
($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13)
2013-08-14 12:45:47 IDT ERROR:  current transaction is aborted, commands
ignored until end of transaction block


As you may see, there is no any clue on what the parameters are. So,
unfortunately, it did not help me at all in my troubleshooting.


Surprisingly, when I finally succeeded to guess and solve the problem with
the parameter, it started printing the parameters just fine:


2013-08-14 12:49:12 IDT LOG:  execute <unnamed>: INSERT INTO pesticide_rule
(id, active_from, active_until, allowed, classifier, external_id,
last_update, priority, properties, first_id, pesticide_id, project_id,
second_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13)
2013-08-14 12:49:12 IDT DETAIL:  parameters: $1 = '72147802620887041', $2 =
NULL, $3 = NULL, $4 = 't', $5 = NULL, $6 = NULL, $7 = '2013-08-14
12:49:12.54895', $8 = '0', $9 = '', $10 = '200035', $11 = '320002', $12 =
'72142057617948673', $13 = '210009'
2013-08-14 12:49:12 IDT LOG:  duration: 51.290 ms


My trouble with this story is that the troubleshooting of problematic SQL
queries is complicated by the fact that the parameters are not reported to
the log. Especially in cases when the error refers to some problem with the
parameters.


Regards,


Andrew Schetinin

pgsql-bugs by date:

Previous
From: David Fetter
Date:
Subject: Re: BUG #8381: data base inconsistancy
Next
From: Michael Paquier
Date:
Subject: Re: BUG #8381: data base inconsistancy