search

darold / pgbadger

A fast PostgreSQL Log Analyzer
http://pgbadger.darold.net/
PostgreSQL License
3.45k stars 348 forks source link

Parsing of pg 8.2 log files with prepared statements #112

Closed jcarnu closed 10 years ago

jcarnu commented 10 years ago

Hi Gilles, pgBadger works fine on my log files; As I want detailed timings on my analysis, I switched all the config file log as asked in the documentation.

log_min_duration_statement = 0
log_duration = on
log_connections = on
log_disconnections = on
log_line_prefix = '%t [%p]: [%l-1] user=%u,db%d '
log_statement=all
lc_message = C

In my Log file I have such a lines 

2013-10-16 00:00:02 UTC [21921]: [2016-1] user=xxxx,db=yyyy LOG:  duration: 0.120 ms  parse <unnamed>: select this_.ID as ID3_0_, this_.NOM_TRAITEMENT as NOM2_3_0_, this_.TYPE_DECLENCHEUR as TYPE3_3_0_, this_.DATE_PROGRAMMATION as DATE4_3_0_, this_.DATE_DERNIER as DATE5_3_0_, this_.PERIODICITE as PERIODIC6_3_0_, this_.MASQUE as MASQUE3_0_, this_.REPERTOIRE as REPERTOIRE3_0_, this_.COMMENTAIRE as COMMENTA9_3_0_, this_.PROPRIETAIRE as PROPRIE10_3_0_, this_.MACHINE as MACHINE3_0_, this_.XML_COMPUTATION as XML12_3_0_, this_.XML_PARAMETRAGE as XML13_3_0_, this_.LOCAL_DIRECTORY as LOCAL14_3_0_, this_.FTP_LOGIN as FTP15_3_0_, this_.FTP_PASSWD as FTP16_3_0_, this_.FTP_ACTIF as FTP17_3_0_, this_.FTP_BINARY as FTP18_3_0_, this_.DECLENCHEUR_ACTIF as DECLENC19_3_0_, this_.ENCHAINEMENT as ENCHAIN20_3_0_, this_.TRIGGER_OK as TRIGGER21_3_0_, this_.TRIGGER_NOK as TRIGGER22_3_0_ from G_DECLENCHEUR this_ limit $1
2013-10-16 00:00:02 UTC [21921]: [2017-1] user=xxxx,db=yyyy LOG:  duration: 0.108 ms  bind <unnamed>: select this_.ID as ID3_0_, this_.NOM_TRAITEMENT as NOM2_3_0_, this_.TYPE_DECLENCHEUR as TYPE3_3_0_, this_.DATE_PROGRAMMATION as DATE4_3_0_, this_.DATE_DERNIER as DATE5_3_0_, this_.PERIODICITE as PERIODIC6_3_0_, this_.MASQUE as MASQUE3_0_, this_.REPERTOIRE as REPERTOIRE3_0_, this_.COMMENTAIRE as COMMENTA9_3_0_, this_.PROPRIETAIRE as PROPRIE10_3_0_, this_.MACHINE as MACHINE3_0_, this_.XML_COMPUTATION as XML12_3_0_, this_.XML_PARAMETRAGE as XML13_3_0_, this_.LOCAL_DIRECTORY as LOCAL14_3_0_, this_.FTP_LOGIN as FTP15_3_0_, this_.FTP_PASSWD as FTP16_3_0_, this_.FTP_ACTIF as FTP17_3_0_, this_.FTP_BINARY as FTP18_3_0_, this_.DECLENCHEUR_ACTIF as DECLENC19_3_0_, this_.ENCHAINEMENT as ENCHAIN20_3_0_, this_.TRIGGER_OK as TRIGGER21_3_0_, this_.TRIGGER_NOK as TRIGGER22_3_0_ from G_DECLENCHEUR this_ limit $1
2013-10-16 00:00:02 UTC [21921]: [2018-1] user=xxxx,db=yyyy DETAIL:  parameters: $1 = '5000'
2013-10-16 00:00:02 UTC [21921]: [2019-1] user=xxxx,db=yyyy LOG:  execute <unnamed>: select this_.ID as ID3_0_, this_.NOM_TRAITEMENT as NOM2_3_0_, this_.TYPE_DECLENCHEUR as TYPE3_3_0_, this_.DATE_PROGRAMMATION as DATE4_3_0_, this_.DATE_DERNIER as DATE5_3_0_, this_.PERIODICITE as PERIODIC6_3_0_, this_.MASQUE as MASQUE3_0_, this_.REPERTOIRE as REPERTOIRE3_0_, this_.COMMENTAIRE as COMMENTA9_3_0_, this_.PROPRIETAIRE as PROPRIE10_3_0_, this_.MACHINE as MACHINE3_0_, this_.XML_COMPUTATION as XML12_3_0_, this_.XML_PARAMETRAGE as XML13_3_0_, this_.LOCAL_DIRECTORY as LOCAL14_3_0_, this_.FTP_LOGIN as FTP15_3_0_, this_.FTP_PASSWD as FTP16_3_0_, this_.FTP_ACTIF as FTP17_3_0_, this_.FTP_BINARY as FTP18_3_0_, this_.DECLENCHEUR_ACTIF as DECLENC19_3_0_, this_.ENCHAINEMENT as ENCHAIN20_3_0_, this_.TRIGGER_OK as TRIGGER21_3_0_, this_.TRIGGER_NOK as TRIGGER22_3_0_ from G_DECLENCHEUR this_ limit $1
2013-10-16 00:00:02 UTC [21921]: [2020-1] user=xxxx,db=yyyy DETAIL:  parameters: $1 = '5000'
2013-10-16 00:00:02 UTC [21921]: [2021-1] user=xxxx,db=yyyy LOG:  duration: 6.972 ms

As you can see, this is prepared statements.

I could not manage to get pgBadger to generate detailed timings and cumulated times. This may be normal or not but this would be nice for me to get this work in order to perform a correct and meaningful analysis.

Thank you for reading and for any answer.

kind regards

darold commented 10 years ago

I don't know what documentation you are talking about but in the official pgbadger documentation it is said that log_duration must be set to off and log_statement to 'none'.

jcarnu commented 10 years ago

Hi Gilles,

That's quite true. I misunderstood that point. Thank you and sorry to have wasted your time.

Kind regards