date:20190302

RE: How to get the content of Bind variables

2019-03-02 Thread ROS Didier

Hi



   The SQL is not executed from a trigger.

   Here is an extract of my log file :

>>

2019-03-01 14:53:37 CET [24803]: [129-1] [3686] 
user=pgbd_preint_sg2,db=pgbd_preint_sg2 LOG:  process 24803 still waiting for 
ShareLock on transaction 3711 after 1000.476 ms

2019-03-01 14:53:37 CET [24803]: [130-1] [3686] 
user=pgbd_preint_sg2,db=pgbd_preint_sg2 DETAIL:  Process holding the lock: 
24786. Wait queue: 24803.

2019-03-01 14:53:37 CET [24803]: [131-1] [3686] 
user=pgbd_preint_sg2,db=pgbd_preint_sg2 CONTEXT:  while rechecking updated 
tuple (3,33) in relation "t_shared_liste_valeurs"

2019-03-01 14:53:37 CET [24803]: [132-1] [3686] 
user=pgbd_preint_sg2,db=pgbd_preint_sg2 STATEMENT:  update 
t_shared_liste_valeurs set deletion_date=$1, deletion_login=$2, 
modification_date=$3, modification_login=$4, administrable=$5, libelle=$6, 
niveau=$7 where code=$8

<<



After a fresh db restart, the result is the same : no content of Bind variables 
in the log file.


Best Regards[cid:[email protected]]


Didier ROS
Expertise SGBD
EDF - DTEO - DSIT - IT DMA
Département Solutions Groupe
Groupe Performance Applicative
32 avenue Pablo Picasso
92000 NANTERRE

[email protected]
Tél. : +33 6 49 51 11 88
[cid:[email protected]][cid:[email protected]]





-Message d'origine-
De : [email protected] [mailto:[email protected]]
Envoyé : vendredi 1 mars 2019 21:42
À : [email protected]
Objet : RE: How to get the content of Bind variables



Hi Didier,



I imagine that this is the sql executed from a trigger.

Could you provide the trigger pl/pgsql code ?

as the source and target tables (anonymized) definition ?



After a fresh db restart, are thoses logs the same for the 6 first executions 
and the following ones ?



Regards

PAscal







--

Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html





Ce message et toutes les pièces jointes (ci-après le 'Message') sont établis à 
l'intention exclusive des destinataires et les informations qui y figurent sont 
strictement confidentielles. Toute utilisation de ce Message non conforme à sa 
destination, toute diffusion ou toute publication totale ou partielle, est 
interdite sauf autorisation expresse.

Si vous n'êtes pas le destinataire de ce Message, il vous est interdit de le 
copier, de le faire suivre, de le divulguer ou d'en utiliser tout ou partie. Si 
vous avez reçu ce Message par erreur, merci de le supprimer de votre système, 
ainsi que toutes ses copies, et de n'en garder aucune trace sur quelque support 
que ce soit. Nous vous remercions également d'en avertir immédiatement 
l'expéditeur par retour du message.

Il est impossible de garantir que les communications par messagerie 
électronique arrivent en temps utile, sont sécurisées ou dénuées de toute 
erreur ou virus.


This message and any attachments (the 'Message') are intended solely for the 
addressees. The information contained in this Message is confidential. Any use 
of information contained in this Message not in accord with its purpose, any 
dissemination or disclosure, either whole or partial, is prohibited except 
formal approval.

If you are not the addressee, you may not copy, forward, disclose or use any 
part of it. If you have received this message in error, please delete it and 
all copies from your system and notify the sender immediately by return message.

E-mail communication cannot be guaranteed to be timely secure, error or 
virus-free.

RE: How to get the content of Bind variables

2019-03-02 Thread legrand legrand

Did16 wrote
> Hi
>The SQL is not executed from a trigger.
>Here is an extract of my log file :
>>>
> 
> 2019-03-01 14:53:37 CET [24803]: [129-1] [3686]
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 LOG:  process 24803 still waiting
> for ShareLock on transaction 3711 after 1000.476 ms
> 
> 2019-03-01 14:53:37 CET [24803]: [130-1] [3686]
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 DETAIL:  Process holding the lock:
> 24786. Wait queue: 24803.
> 
> 2019-03-01 14:53:37 CET [24803]: [131-1] [3686]
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 CONTEXT:  while rechecking updated
> tuple (3,33) in relation "t_shared_liste_valeurs"
> 
> 2019-03-01 14:53:37 CET [24803]: [132-1] [3686]
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 STATEMENT:  update
> t_shared_liste_valeurs set deletion_date=$1, deletion_login=$2,
> modification_date=$3, modification_login=$4, administrable=$5, libelle=$6,
> niveau=$7 where code=$8
> 
> <<
> 
> After a fresh db restart, the result is the same : no content of Bind
> variables in the log file.
> 
> Best Regards
> 
> Didier ROS
> Expertise SGBD
> EDF - DTEO - DSIT - IT DMA
> Département Solutions Groupe
> Groupe Performance Applicative
> 32 avenue Pablo Picasso
> 92000 NANTERRE

OK, In case of a trigger or any pl/pgsql program I would have tryed to write
the content of bind variables using RAISE command or someting similar before
executing the UPDATE command.

But your log is now much more explicit: you where waiting on a LOCK ...

Regards
PAscal



--
Sent from: 
http://www.postgresql-archive.org/PostgreSQL-performance-f2050081.html

Re: How to get the content of Bind variables

2019-03-02 Thread Justin Pryzby

On Fri, Mar 01, 2019 at 06:47:06PM +, ROS Didier wrote:
> log_line_prefix = '%t [%p]: [%l-1] [%x] user=%u,db=%d,client=%h'

On Sat, Mar 02, 2019 at 01:14:44PM +, ROS Didier wrote:
> 2019-03-01 14:53:37 CET [24803]: [129-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 LOG:  process 24803 still waiting for 
> ShareLock on transaction 3711 after 1000.476 ms
> 2019-03-01 14:53:37 CET [24803]: [130-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 DETAIL:  Process holding the lock: 
> 24786. Wait queue: 24803.
> 2019-03-01 14:53:37 CET [24803]: [131-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 CONTEXT:  while rechecking updated 
> tuple (3,33) in relation "t_shared_liste_valeurs"
> 2019-03-01 14:53:37 CET [24803]: [132-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 STATEMENT:  update 
> t_shared_liste_valeurs set deletion_date=$1, deletion_login=$2, 
> modification_date=$3, modification_login=$4, administrable=$5, libelle=$6, 
> niveau=$7 where code=$8

I just realized that your log is showing "STATEMENT:  [...]" which I think
means that's using libpq PQexec (simple query protocol), which means it doesn't
use or support bind parameters at all.  If it were using PQexecParams (protocol
2.0 "extended" query), it would show "execute : [...]", with any bind
params in DETAIL.  And if you were using PQexecPrepared, it'd show "execute
FOO: [...]" where FOO is the name of the statement "prepared" by PQprepare
(plus bind params).

https://www.postgresql.org/docs/current/libpq-exec.html
https://www.postgresql.org/docs/current/protocol.html

What client application is this ?  It looks like it's going to set
deletion_date to the literal string "$1" .. except that it's not quoted, so the
statement will just cause an error.  Am I wrong ?

Could you grep the entire logfile for pid 24803 and post the output on dropbox
or pastebin or show 10 lines of context by email ?

I've just used my messages and test cases on this patch as a reference to check
what I wrote above is accurate.
https://www.postgresql.org/message-id/flat/20190210015707.GQ31721%40telsasoft.com#037d17567f4c84a5f436960ef1ed8c49

On Fri, Mar 01, 2019 at 06:47:06PM +, ROS Didier wrote:
> *) -> suggestion : It would be nice to have the content of bind variable of a 
> query in a table of pg_catalog. (cf ORACLE) 

As I mentioned, you can set log_destination=csvlog,stderr and import them with
COPY (and add indices and analysis and monitoring..).  It look like DETAILs are
being logged, so that's not the issue, but CSV also has the nice benefit of
being easily imported to SQL where escaping and linebreaks and similar are not
confusing the issue, which I think can be the case for text logs.

Justin

Re: How to get the content of Bind variables

2019-03-02 Thread Tom Lane

Justin Pryzby  writes:
> On Fri, Mar 01, 2019 at 06:47:06PM +, ROS Didier wrote:
>> log_line_prefix = '%t [%p]: [%l-1] [%x] user=%u,db=%d,client=%h'

> On Sat, Mar 02, 2019 at 01:14:44PM +, ROS Didier wrote:
>> 2019-03-01 14:53:37 CET [24803]: [129-1] [3686] 
>> user=pgbd_preint_sg2,db=pgbd_preint_sg2 LOG:  process 24803 still waiting 
>> for ShareLock on transaction 3711 after 1000.476 ms
>> 2019-03-01 14:53:37 CET [24803]: [130-1] [3686] 
>> user=pgbd_preint_sg2,db=pgbd_preint_sg2 DETAIL:  Process holding the lock: 
>> 24786. Wait queue: 24803.
>> 2019-03-01 14:53:37 CET [24803]: [131-1] [3686] 
>> user=pgbd_preint_sg2,db=pgbd_preint_sg2 CONTEXT:  while rechecking updated 
>> tuple (3,33) in relation "t_shared_liste_valeurs"
>> 2019-03-01 14:53:37 CET [24803]: [132-1] [3686] 
>> user=pgbd_preint_sg2,db=pgbd_preint_sg2 STATEMENT:  update 
>> t_shared_liste_valeurs set deletion_date=$1, deletion_login=$2, 
>> modification_date=$3, modification_login=$4, administrable=$5, libelle=$6, 
>> niveau=$7 where code=$8

> I just realized that your log is showing "STATEMENT:  [...]" which I think
> means that's using libpq PQexec (simple query protocol), which means it 
> doesn't
> use or support bind parameters at all.

No, what's shown above is a case of the current statement being printed
as detail for some log message (a log_lock_waits message in this case).
This has nothing to do with whether statement logging is on overall.

I now realize that what the OP is probably wishing for is that bind
parameter values would be included as a detail line in messages other
than log_all_statements or statement-duration messages.  Sorry, that
feature doesn't exist, and there'd be pretty serious technical
impediments to making it happen.

regards, tom lane

Re: How to get the content of Bind variables

2019-03-02 Thread Sergei Kornilov

Hello

Postgresql does not log statement parameters on log_lock_wait. Because this is 
not implemented: 
https://github.com/postgres/postgres/blob/REL_10_STABLE/src/backend/storage/lmgr/proc.c#L1461
Compare with errdetail_params routine in this file: 
https://github.com/postgres/postgres/blob/REL_10_STABLE/src/backend/tcop/postgres.c#L1847
 

Currently query parameters can be logged only at the end of successful query 
execution.

regards, Sergei

RE: How to get the content of Bind variables

2019-03-02 Thread ROS Didier

Hi

I have executed grep command on the entire logfile for pid 24803. See the 
attached file
NB : I have no DETAIL section in my entire log file. Is it normal ?

Best Reagrds

Didier ROS

-Message d'origine-
De : [email protected] [mailto:[email protected]] 
Envoyé : samedi 2 mars 2019 16:57
À : ROS Didier 
Cc : [email protected]; [email protected]; 
[email protected]
Objet : Re: How to get the content of Bind variables

On Fri, Mar 01, 2019 at 06:47:06PM +, ROS Didier wrote:
> log_line_prefix = '%t [%p]: [%l-1] [%x] user=%u,db=%d,client=%h'

On Sat, Mar 02, 2019 at 01:14:44PM +, ROS Didier wrote:
> 2019-03-01 14:53:37 CET [24803]: [129-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 LOG:  process 24803 still 
> waiting for ShareLock on transaction 3711 after 1000.476 ms
> 2019-03-01 14:53:37 CET [24803]: [130-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 DETAIL:  Process holding the lock: 
> 24786. Wait queue: 24803.
> 2019-03-01 14:53:37 CET [24803]: [131-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 CONTEXT:  while rechecking updated 
> tuple (3,33) in relation "t_shared_liste_valeurs"
> 2019-03-01 14:53:37 CET [24803]: [132-1] [3686] 
> user=pgbd_preint_sg2,db=pgbd_preint_sg2 STATEMENT:  update 
> t_shared_liste_valeurs set deletion_date=$1, deletion_login=$2, 
> modification_date=$3, modification_login=$4, administrable=$5, 
> libelle=$6, niveau=$7 where code=$8

I just realized that your log is showing "STATEMENT:  [...]" which I think 
means that's using libpq PQexec (simple query protocol), which means it doesn't 
use or support bind parameters at all.  If it were using PQexecParams (protocol
2.0 "extended" query), it would show "execute : [...]", with any bind 
params in DETAIL.  And if you were using PQexecPrepared, it'd show "execute
FOO: [...]" where FOO is the name of the statement "prepared" by PQprepare 
(plus bind params).

https://www.postgresql.org/docs/current/libpq-exec.html
https://www.postgresql.org/docs/current/protocol.html

What client application is this ?  It looks like it's going to set 
deletion_date to the literal string "$1" .. except that it's not quoted, so the 
statement will just cause an error.  Am I wrong ?

Could you grep the entire logfile for pid 24803 and post the output on dropbox 
or pastebin or show 10 lines of context by email ?

I've just used my messages and test cases on this patch as a reference to check 
what I wrote above is accurate.
https://www.postgresql.org/message-id/flat/20190210015707.GQ31721%40telsasoft.com#037d17567f4c84a5f436960ef1ed8c49

On Fri, Mar 01, 2019 at 06:47:06PM +, ROS Didier wrote:
> *) -> suggestion : It would be nice to have the content of bind 
> variable of a query in a table of pg_catalog. (cf ORACLE)

As I mentioned, you can set log_destination=csvlog,stderr and import them with 
COPY (and add indices and analysis and monitoring..).  It look like DETAILs are 
being logged, so that's not the issue, but CSV also has the nice benefit of 
being easily imported to SQL where escaping and linebreaks and similar are not 
confusing the issue, which I think can be the case for text logs.

Justin

Ce message et toutes les pièces jointes (ci-après le 'Message') sont établis à 
l'intention exclusive des destinataires et les informations qui y figurent sont 
strictement confidentielles. Toute utilisation de ce Message non conforme à sa 
destination, toute diffusion ou toute publication totale ou partielle, est 
interdite sauf autorisation expresse.

Si vous n'êtes pas le destinataire de ce Message, il vous est interdit de le 
copier, de le faire suivre, de le divulguer ou d'en utiliser tout ou partie. Si 
vous avez reçu ce Message par erreur, merci de le supprimer de votre système, 
ainsi que toutes ses copies, et de n'en garder aucune trace sur quelque support 
que ce soit. Nous vous remercions également d'en avertir immédiatement 
l'expéditeur par retour du message.

Il est impossible de garantir que les communications par messagerie 
électronique arrivent en temps utile, sont sécurisées ou dénuées de toute 
erreur ou virus.

This message and any attachments (the 'Message') are intended solely for the 
addressees. The information contained in this Message is confidential. Any use 
of information contained in this Message not in accord with its purpose, any 
dissemination or disclosure, either whole or partial, is prohibited except 
formal approval.

If you are not the addressee, you may not copy, forward, disclose or use any 
part of it. If you have received this message in error, please delete it and 
all copies from your system and notify the sender immediately by return message.

E-mail communication cannot be guaranteed to be timely secure, error or 
virus-free.
[postgres@noeyypvd pg_log]$ grep 24803 postgresql.log
2019-03-01 14:44:40 CET [24803]: [1-1] [0] user=[unknown],db=[unknown] LOG:  
connection re

RE: How to get the content of Bind variables

2019-03-02 Thread ROS Didier

Hi Sergei

Thank you for your explanation. I can understand for the lock wait
message, but I have no DETAIL section in my entire log file. Why ?
I have plenty of STATEMENT sections ...

Thanks in advance

Best Regards
Didier ROS

-Message d'origine-
De : [email protected] [mailto:[email protected]]
Envoyé : samedi 2 mars 2019 17:34
À : ROS Didier ; [email protected];
[email protected]
Objet : Re: How to get the content of Bind variables

Hello

Postgresql does not log statement parameters on log_lock_wait. Because this is
not implemented:
https://github.com/postgres/postgres/blob/REL_10_STABLE/src/backend/storage/lmgr/proc.c#L1461
Compare with errdetail_params routine in this file:
https://github.com/postgres/postgres/blob/REL_10_STABLE/src/backend/tcop/postgres.c#L1847

Currently query parameters can be logged only at the end of successful query
execution.

regards, Sergei

Ce message et toutes les pièces jointes (ci-après le 'Message') sont établis à
l'intention exclusive des destinataires et les informations qui y figurent sont
strictement confidentielles. Toute utilisation de ce Message non conforme à sa
destination, toute diffusion ou toute publication totale ou partielle, est
interdite sauf autorisation expresse.

Si vous n'êtes pas le destinataire de ce Message, il vous est interdit de le
copier, de le faire suivre, de le divulguer ou d'en utiliser tout ou partie. Si
vous avez reçu ce Message par erreur, merci de le supprimer de votre système,
ainsi que toutes ses copies, et de n'en garder aucune trace sur quelque support
que ce soit. Nous vous remercions également d'en avertir immédiatement
l'expéditeur par retour du message.

Il est impossible de garantir que les communications par messagerie
électronique arrivent en temps utile, sont sécurisées ou dénuées de toute
erreur ou virus.

This message and any attachments (the 'Message') are intended solely for the
addressees. The information contained in this Message is confidential. Any use
of information contained in this Message not in accord with its purpose, any
dissemination or disclosure, either whole or partial, is prohibited except
formal approval.

If you are not the addressee, you may not copy, forward, disclose or use any
part of it. If you have received this message in error, please delete it and
all copies from your system and notify the sender immediately by return message.

E-mail communication cannot be guaranteed to be timely secure, error or
virus-free.

RE: How to get the content of Bind variables

RE: How to get the content of Bind variables

Re: How to get the content of Bind variables

Re: How to get the content of Bind variables

Re: How to get the content of Bind variables

RE: How to get the content of Bind variables

RE: How to get the content of Bind variables

7 matches

Site Navigation

Mail list logo

Footer information