Subject: Re: log bind parameter values on error
To: Alexey Bashtanov <bashtanov@imap.cc>,
 PostgreSQL Hackers <pgsql-hackers@postgresql.org>
References: <0146a67b-a22a-0519-9082-bc29756b93a2@imap.cc>
 <c4891f99-8385-5c31-1aac-e226356ec964@2ndquadrant.com>
 <ad08f6a3-e38c-f851-a5a2-0bf68d1d7f72@imap.cc>
 <896ac2ed-7735-1f24-d877-3249b38bb6fe@2ndquadrant.com>
 <8efd95fe-3886-61f0-0faa-6c661cd2f874@imap.cc>
 <084a044f-9d77-b931-0658-5d871df8a2f8@imap.cc>
From: Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
Openpgp: preference=signencrypt
Autocrypt: addr=peter.eisentraut@2ndquadrant.com; prefer-encrypt=mutual;
 keydata=
 xsFNBFUUt6kBEADZd9NNTBJbHmAXXJgPGOdd6Q73l80oifIVgn2tRxP9dYkCfTlo/yLqbKTl
 JNqTcyM6XrJDnB2sMEUGYCewYZXl+9C4bBJWyNqcEI1ae9u71vEq/fknFLArJ+2wN+f7QuRx
 Q8d94ZJAiJQ5g3fNk2HVeedCQCKP5dCzU+ZLt2dbsx1PDZLjTO9gf+JswWuGFb5wY5PZVM5V
 hq66Xk7ZJzHuARacza2RT7J2fkMmQBY+kr7L98Perb0GhafnlhXB0PvUB+N3xpmggMfwuhTu
 BngS/G/r3GvemxJuFxouw8xsMqrsfdksJXA2gLXYtwRCssdPV3PO0rlD9twqDo8URfIJ5fb6
 1g/MV8aTOKjg3Q8MpJPtkwJqN4o3PvbwYdedeFnOVkkYAJdu/aX1v1BeCBDu7Hy3sF52scD3
 pQbyQSl9vUDpTLarASAxNbAV0NRJE8dp4vfW6AH1ccryGiFqw/czPK/iN0+MT8wsjAW6WW4w
 hvjm5UPA1KTwi3ZT8eT5uycuH7QpuNk7LnGGXQ6KaRALFywzkr0A0V0AvFNa+l4wstMaXaB6
 dmMXyF0/hfryqyOeu1gAdq4q0/PNC2dPgb/6uoh4eMjN6A5GXcprilhz5DulmsilY21hfSoU
 S64ODed96pKhprsOxjZiDRsN1QM5MwB+uwVWUNfsX7fIxE0BrwARAQABzSdQZXRlciBFaXNl
 bnRyYXV0IDxwZXRlckBlaXNlbnRyYXV0Lm9yZz7CwXoEEwEIACQCGwMFCwkIBwMFFQoJCAsF
 FgIDAQACHgECF4AFAlUUuKQCGQEACgkQoZ8SQ+xBJp8llw//RbGoXnF72FZTlOFsnNyxnWbF
 vViPCfdAlZl1GGK9OYCvV1dp/956HuhB0wpaGQHiBmQfOPJf/jLOPjXFYm2iEChEycrBChuE
 j4TSYemMp5BSPILYk9Uwd16kVD/+U6fQfK6H5pOhfBvbM6asMnmpY2wQuvktxHvaGlytFw84
 EzFWNZtAZfxkw28w3AhIQkKe9hJanfyDL750RcbyEr8AAHty5IErrvS7tM5vQwIeh5BF26ND
 CyKPRdZgOgMpcwFfROKBDpAt052CgWIpNdhBdfIKlkCs4/ILxmC3rT/Mb/qZiHcoMMwEu6k+
 T7vRAFZZAk62Yrr/U8/vUGKlzRZQoo86fyojCfI0ibCIc0z8rwCVY9P40G9wD9BTCZS/z8Vh
 jjpBlNnIKw2hM6hbxavKndCJjFFJD08rXrTyrLF/of18xD37vNdYooP9VATB5QjOWFRrscSZ
 4a89e+to3m7YVnd4xdXwGp47dYusoax84C8tg1gZrH38ol9dPmnKX6GZrXeS7tH9k8VeUpJ8
 HQbRThQRWAT936QpYbLConBmOtmbLmjQOGtiXPo1oK57X/7U/WBja5vWmm2q+Yxtt+3uHGVg
 DdDU4CJpXo4lX0v2n3QV5EBSW9hjdF3bNfl6GFBb1pPEhqNcMDUc7zkx/2uENdAdk/BnqMgH
 umip7b0pVfvOwU0EVRS3qQEQAJf6p0P7D+hMYUgCPkvgrcz6OJYsAYdUMUmokfqmkKwK0oJM
 ew8TNGM53ocKAgQGma5f10rwbZNPlpVPNRX5hwUmwVlcwSut0oE+JfUBH7mpysWvpF05RKIy
 q9RCoJZrAbXS7Tig56A1QD8IcM00rERZMcCOlI1+q9m4u9AOI+0LyGGSH+VvoyDHD/Jew4R2
 TmPEF8Pu7lYiNYK88Q6u0kBkc+Tz3BNlyc6fi3HxnFfp0b75HLXPSTu2SwA/0Q31wHZXwrEU
 BR9KgSn/qbgy8ydPc97i82fhiFE3cbGexfPrQSMYmDGi+dcQ0s+AMQwC3XyMC0JkHpYUuFkR
 QdlIvaIhgFUUN2Vr4xF2ADaNTNFc4DYaiPHFAgHZw+3pZWqS4uIiWgJynrEaHw4F3QWU8/JB
 iyEWDhNq4WBrRA0u914TCCAoFOOKMnRdl8eJrRQKM/5/lXbHFjjlI/LDKhLRFsuQsnJJ3331
 RjCzpHPZG5/p5KR1RHiAXa0p/DW5lXyq21hS3kjDlleoHqOxCN/cy0Jgz7qLDq1vZoCl67Sy
 RAH60c2Xu4may9SVltmot0OzWVHdrfS+85FQGp9580DaeLio7YMFKy2bfEvwQJ/c9xD2QPB+
 oSb3V8ueSznXBG5+dyfOsZFRPxceA0wA2rSWZSjxLdKxvyGTj9vsCjaDu13rABEBAAHCwV8E
 GAEIAAkFAlUUt6kCGwwACgkQoZ8SQ+xBJp+HJhAAxmSTsC5y7p9Zu+nnLpucv/h88oEx985e
 qWeXzQiwM3pfRZS+PdTH9TyzHK0KOgKoAiubk0vt+BrT91D9d0G5kVQaTctAErGBoMkTaZJT
 XVEcNphiPzysdSqvprjojMp1y7rG8AP+Xd6m0rE1LRnkRRm8HyI8vdXsuLQPITGWXDLMjaNq
 AOV3BUnzkgtjMuIYw7SCr+12ZOb5dEKvaG4kjC4kaJ/TLbuBhVANcXkC90yp0AOZLs/cB1Dj
 OAXno/RUUruJ3r27a+pFv768UAi9QWcdw58yPxreMNMLqAgsS9oTHwHfGNWcB2dJ4UW+GMLJ
 hTf9TjQ2f+N/sIx5XMQ9pYw6CAJMK29qPx6/ZayrPxf22EXf0D3zTwIEZgwfSkynFVwV25L7
 awQq60fifdMYheSxq7GbhpsixmcD+e161cCmLIt75YDt5bQ0B1yf7EmxG8n7pGZAOM6LoNsU
 fkSldba5XVwh8LuN5mK0nQBELGW6Os4TDq4REggLpfcvFC215zpuo0iCGnmE/Bns4nowqUSP
 u4tkWL+nxW4qgv8wo8HJ52jd79EJ8iqfIBoidBfy9AIUiEUApGQzWPu6yWcI8fY0rN5D+tc+
 Yw1Zt6Mm+huYJpgCRsTcfzEcahnBn521CWcWvhW1ff3KFileFMtNmnBBhMncmRKHphtTKEpN
 3jI=
Organization: 2ndQuadrant
Message-ID: <96007f6e-1e42-e454-9db4-e7842e137508@2ndquadrant.com>
Date: Thu, 17 Jan 2019 09:41:50 +0100
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:52.0)
 Gecko/20100101 Thunderbird/52.9.1
MIME-Version: 1.0
In-Reply-To: <084a044f-9d77-b931-0658-5d871df8a2f8@imap.cc>
Content-Type: text/plain; charset=utf-8
Content-Language: en-US
Content-Transfer-Encoding: 8bit
Precedence: bulk

There appears to be a problem with how this affects current logging
behavior.

I'm using

    pgbench -M extended -S -T 10 bench

to test the extended protocol.

Unpatched, with log_statement=all, you get something like

LOG:  execute <unnamed>: SELECT abalance FROM pgbench_accounts WHERE aid
= $1;
DETAIL:  parameters: $1 = '30223'

With your patch, with log_statement=all and log_parameters=on, you get
the same, but with log_statement=all and log_parameters=off you get

LOG:  execute <unnamed>: SELECT abalance FROM pgbench_accounts WHERE aid
= $1;
DETAIL:  parameters: $1 = UNKNOWN TYPE

We should probably keep the existing parameter logging working as before.

This also raises the question of the new parameter name.  Parameters are
already logged.  So the name should perhaps be more like
log_parameters_on_error.

Some API notes on your patch:  I think you can change
get_portal_bind_parameters() to take a ParamListInfo, since you're not
doing anything with the Portal other than grab the parameters.  And that
would allow you to keep the signature of errdetail_params() unchanged.

I did some performance tests using the commands shown above and didn't
find any problems.  Obviously the default pgbench stuff isn't very
parameter-intensive.  Do you have tests with more and larger parameter
values?

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services