pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
General DB Tuning
12+ messages / 6 participants
[nested] [flat]

* General DB Tuning
@ 2005-07-12 06:22 Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  0 siblings, 1 reply; 12+ messages in thread

From: Brent Henry @ 2005-07-12 06:22 UTC (permalink / raw)
  To: pgsql-performance

Help!  After recently migrating to Postgres 8, I've
discovered to my horror that I can't determine which
queries are poorly performing anymore because the
logging has drastically changed and no longer shows
durations for anything done through JDBC.

So I'm desperately trying to do performance tuning on
my servers and have no way to sort out which
statements are the slowest.

Does anyone have any suggestions?  How do you
determine what queries are behaving badly when you
can't get durations out of the logs?

I have a perl script that analyzes the output from
Postgres 7 logs and it works great!  But it relies on
the duration being there.

I did some searches on postgresql.org mailing lists
and have seen a few people discussing this problem,
but noone seems to be too worried about it.  Is there
a simple work-around?

Sincerely,

Brent


		
____________________________________________________
Sell on Yahoo! Auctions – no fees. Bid on great items.  
http://auctions.yahoo.com/



^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
@ 2005-07-12 21:54 ` Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  0 siblings, 1 reply; 12+ messages in thread

From: Tom Arthurs @ 2005-07-12 21:54 UTC (permalink / raw)
  To: Brent Henry <bh_pgperf@yahoo.com>; +Cc: pgsql-performance

I have this in my postgresql.conf file and it works fine (set the min to 
whatever you want to log)
log_min_duration_statement = 3000 # -1 is disabled, in milliseconds.

Another setting that might get what you want:

#log_duration = false

uncomment and change to true.

 From the docs: 
(http://www.postgresql.org/docs/8.0/interactive/runtime-config.html)

  Causes the duration of every completed statement which satisfies 
log_statement to be logged. When using this option, if you are not using 
syslog, it is recommended that you log the PID or session ID using 
log_line_prefix so that you can link the statement to the duration using 
the process ID or session ID. The default is off. Only superusers can 
change this setting.

Brent Henry wrote:
> Help!  After recently migrating to Postgres 8, I've
> discovered to my horror that I can't determine which
> queries are poorly performing anymore because the
> logging has drastically changed and no longer shows
> durations for anything done through JDBC.
> 
> So I'm desperately trying to do performance tuning on
> my servers and have no way to sort out which
> statements are the slowest.
> 
> Does anyone have any suggestions?  How do you
> determine what queries are behaving badly when you
> can't get durations out of the logs?
> 
> I have a perl script that analyzes the output from
> Postgres 7 logs and it works great!  But it relies on
> the duration being there.
> 
> I did some searches on postgresql.org mailing lists
> and have seen a few people discussing this problem,
> but noone seems to be too worried about it.  Is there
> a simple work-around?
> 
> Sincerely,
> 
> Brent
> 
> 
> 		
> ____________________________________________________
> Sell on Yahoo! Auctions – no fees. Bid on great items.  
> http://auctions.yahoo.com/
> 
> ---------------------------(end of broadcast)---------------------------
> TIP 5: don't forget to increase your free space map settings
> 
> 
> 



^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
@ 2005-07-12 23:32   ` Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  0 siblings, 1 reply; 12+ messages in thread

From: Brent Henry @ 2005-07-12 23:32 UTC (permalink / raw)
  To: Tom Arthurs <tarthurs@jobflash.com>; +Cc: pgsql-performance

Yes, that is exactly what I want to use!

Unfortunately, it doesn't work if you access postgres
through a JDBC connection.  I don't know why.  I found
a posting from back in February which talks aobut this
a little:

http://archives.postgresql.org/pgsql-admin/2005-02/msg00055.php

But I can't find anywhere where someone has fixed it. 
Am I the only one accessing postgres through JDBC?

-Brent


--- Tom Arthurs <tarthurs@jobflash.com> wrote:

> I have this in my postgresql.conf file and it works
> fine (set the min to 
> whatever you want to log)
> log_min_duration_statement = 3000 # -1 is disabled,
> in milliseconds.
> 
> Another setting that might get what you want:
> 
> #log_duration = false
> 
> uncomment and change to true.
> 
>  From the docs: 
>
(http://www.postgresql.org/docs/8.0/interactive/runtime-config.html)
> 
>   Causes the duration of every completed statement
> which satisfies 
> log_statement to be logged. When using this option,
> if you are not using 
> syslog, it is recommended that you log the PID or
> session ID using 
> log_line_prefix so that you can link the statement
> to the duration using 
> the process ID or session ID. The default is off.
> Only superusers can 
> change this setting.
> 
> Brent Henry wrote:
> > Help!  After recently migrating to Postgres 8,
> I've
> > discovered to my horror that I can't determine
> which
> > queries are poorly performing anymore because the
> > logging has drastically changed and no longer
> shows
> > durations for anything done through JDBC.
> > 
> > So I'm desperately trying to do performance tuning
> on
> > my servers and have no way to sort out which
> > statements are the slowest.
> > 
> > Does anyone have any suggestions?  How do you
> > determine what queries are behaving badly when you
> > can't get durations out of the logs?
> > 
> > I have a perl script that analyzes the output from
> > Postgres 7 logs and it works great!  But it relies
> on
> > the duration being there.
> > 
> > I did some searches on postgresql.org mailing
> lists
> > and have seen a few people discussing this
> problem,
> > but noone seems to be too worried about it.  Is
> there
> > a simple work-around?
> > 
> > Sincerely,
> > 
> > Brent
> > 
> > 
> > 		
> >
> ____________________________________________________
> > Sell on Yahoo! Auctions – no fees. Bid on great
> items.  
> > http://auctions.yahoo.com/
> > 
> > ---------------------------(end of
> broadcast)---------------------------
> > TIP 5: don't forget to increase your free space
> map settings
> > 
> > 
> > 
> 
> ---------------------------(end of
> broadcast)---------------------------
> TIP 2: Don't 'kill -9' the postmaster
> 


__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com 



^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
@ 2005-07-13 00:36     ` Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
  0 siblings, 1 reply; 12+ messages in thread

From: Tom Arthurs @ 2005-07-13 00:36 UTC (permalink / raw)
  To: Brent Henry <bh_pgperf@yahoo.com>; +Cc: pgsql-performance

we are using jdbc -- the "log_min_duration_statement = 3000 " statement 
works fine for me.  Looks like there's no other work around for the 
bug(?).  Not sure since I have no interest in logging a million 
statements a day, I only want to see the poorly performing hits.

Brent Henry wrote:
> Yes, that is exactly what I want to use!
> 
> Unfortunately, it doesn't work if you access postgres
> through a JDBC connection.  I don't know why.  I found
> a posting from back in February which talks aobut this
> a little:
> 
> http://archives.postgresql.org/pgsql-admin/2005-02/msg00055.php
> 
> But I can't find anywhere where someone has fixed it. 
> Am I the only one accessing postgres through JDBC?
> 
> -Brent
> 
> 
> --- Tom Arthurs <tarthurs@jobflash.com> wrote:
> 
> 
>>I have this in my postgresql.conf file and it works
>>fine (set the min to 
>>whatever you want to log)
>>log_min_duration_statement = 3000 # -1 is disabled,
>>in milliseconds.
>>
>>Another setting that might get what you want:
>>
>>#log_duration = false
>>
>>uncomment and change to true.
>>
>> From the docs: 
>>
> 
> (http://www.postgresql.org/docs/8.0/interactive/runtime-config.html)
> 
>>  Causes the duration of every completed statement
>>which satisfies 
>>log_statement to be logged. When using this option,
>>if you are not using 
>>syslog, it is recommended that you log the PID or
>>session ID using 
>>log_line_prefix so that you can link the statement
>>to the duration using 
>>the process ID or session ID. The default is off.
>>Only superusers can 
>>change this setting.
>>
>>Brent Henry wrote:
>>
>>>Help!  After recently migrating to Postgres 8,
>>
>>I've
>>
>>>discovered to my horror that I can't determine
>>
>>which
>>
>>>queries are poorly performing anymore because the
>>>logging has drastically changed and no longer
>>
>>shows
>>
>>>durations for anything done through JDBC.
>>>
>>>So I'm desperately trying to do performance tuning
>>
>>on
>>
>>>my servers and have no way to sort out which
>>>statements are the slowest.
>>>
>>>Does anyone have any suggestions?  How do you
>>>determine what queries are behaving badly when you
>>>can't get durations out of the logs?
>>>
>>>I have a perl script that analyzes the output from
>>>Postgres 7 logs and it works great!  But it relies
>>
>>on
>>
>>>the duration being there.
>>>
>>>I did some searches on postgresql.org mailing
>>
>>lists
>>
>>>and have seen a few people discussing this
>>
>>problem,
>>
>>>but noone seems to be too worried about it.  Is
>>
>>there
>>
>>>a simple work-around?
>>>
>>>Sincerely,
>>>
>>>Brent
>>>
>>>
>>>		
>>>
>>
>>____________________________________________________
>>
>>>Sell on Yahoo! Auctions – no fees. Bid on great
>>
>>items.  
>>
>>>http://auctions.yahoo.com/
>>>
>>>---------------------------(end of
>>
>>broadcast)---------------------------
>>
>>>TIP 5: don't forget to increase your free space
>>
>>map settings
>>
>>>
>>>
>>---------------------------(end of
>>broadcast)---------------------------
>>TIP 2: Don't 'kill -9' the postmaster
>>
> 
> 
> 
> __________________________________________________
> Do You Yahoo!?
> Tired of spam?  Yahoo! Mail has the best spam protection around 
> http://mail.yahoo.com 
> 
> ---------------------------(end of broadcast)---------------------------
> TIP 6: explain analyze is your friend
> 
> 
> 



^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
@ 2005-07-13 01:05       ` Dennis <dennis@works4me.com>
  2005-07-13 01:17         ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 01:30         ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  0 siblings, 2 replies; 12+ messages in thread

From: Dennis @ 2005-07-13 01:05 UTC (permalink / raw)
  To: pgsql-performance

Tom Arthurs wrote:

> we are using jdbc -- the "log_min_duration_statement = 3000 " 
> statement works fine for me.  Looks like there's no other work around 
> for the bug(?).  Not sure since I have no interest in logging a 
> million statements a day, I only want to see the poorly performing hits. 


Doesn't it depend on what jdbc driver you are using?

Dennis



^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
@ 2005-07-13 01:17         ` Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 01:36           ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  1 sibling, 1 reply; 12+ messages in thread

From: Christopher Kings-Lynne @ 2005-07-13 01:17 UTC (permalink / raw)
  To: Dennis <dennis@works4me.com>; +Cc: pgsql-performance

>> we are using jdbc -- the "log_min_duration_statement = 3000 " 
>> statement works fine for me.  Looks like there's no other work around 
>> for the bug(?).  Not sure since I have no interest in logging a 
>> million statements a day, I only want to see the poorly performing hits. 
> 
> Doesn't it depend on what jdbc driver you are using?

It depends if he's using new-protocol prepared queries which don't get 
logged properly.  Wasn't that fixed for 8.1 or something?

Chris




^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
  2005-07-13 01:17         ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
@ 2005-07-13 01:36           ` Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 01:52             ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 01:53             ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  0 siblings, 2 replies; 12+ messages in thread

From: Brent Henry @ 2005-07-13 01:36 UTC (permalink / raw)
  To: Christopher Kings-Lynne <chriskl@familyhealth.com.au>; Dennis <dennis@works4me.com>; Tom Arthurs <tarthurs@jobflash.com>; +Cc: pgsql-performance

We are running Postgres 8.0.2 with the 8.0.2 jdbc
driver.  And yes we are using prepared statements. 
I've spent hours trying to get the
'log_min_duration_statement' and 'log_duration'
options to work with no luck.  I never get any
duration from the statement.  I also never see 'begin'
or 'commit' in the log so I can't tell how long my
batch commands are taking to commit to the DB.

Is there a different kind of 'prepared' statements
that we should be using in the driver to get logging
to work properly?  What is the 'new' protocol?

Tom, what version are you using?  Are you using
prepared statements in JDBC?

-Brent


--- Christopher Kings-Lynne
<chriskl@familyhealth.com.au> wrote:

> >> we are using jdbc -- the
> "log_min_duration_statement = 3000 " 
> >> statement works fine for me.  Looks like there's
> no other work around 
> >> for the bug(?).  Not sure since I have no
> interest in logging a 
> >> million statements a day, I only want to see the
> poorly performing hits. 
> > 
> > Doesn't it depend on what jdbc driver you are
> using?
> 
> It depends if he's using new-protocol prepared
> queries which don't get 
> logged properly.  Wasn't that fixed for 8.1 or
> something?
> 
> Chris
> 
> 
> ---------------------------(end of
> broadcast)---------------------------
> TIP 3: Have you checked our extensive FAQ?
> 
>                http://www.postgresql.org/docs/faq
> 



		
____________________________________________________
Start your day with Yahoo! - make it your home page
http://www.yahoo.com/r/hs
 



^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
  2005-07-13 01:17         ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 01:36           ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
@ 2005-07-13 01:52             ` Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 10:07               ` Re: General DB Tuning Mark Rae <mrae@purplebat.com>
  2005-07-13 16:10               ` Re: General DB Tuning Simon Riggs <simon@2ndquadrant.com>
  1 sibling, 2 replies; 12+ messages in thread

From: Christopher Kings-Lynne @ 2005-07-13 01:52 UTC (permalink / raw)
  To: Brent Henry <bh_pgperf@yahoo.com>; +Cc: Dennis <dennis@works4me.com>; Tom Arthurs <tarthurs@jobflash.com>; pgsql-performance

> Is there a different kind of 'prepared' statements
> that we should be using in the driver to get logging
> to work properly?  What is the 'new' protocol?

The 8.0.2 jdbc driver uses real prepared statements instead of faked 
ones.  The problem is the new protocol (that the 8.0.2 driver users) has 
a bug where protocol-prepared queries don't get logged properly.

I don't know if it's been fixed...

Chris




^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
  2005-07-13 01:17         ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 01:36           ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 01:52             ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
@ 2005-07-13 10:07               ` Mark Rae <mrae@purplebat.com>
  1 sibling, 0 replies; 12+ messages in thread

From: Mark Rae @ 2005-07-13 10:07 UTC (permalink / raw)
  To: Christopher Kings-Lynne <chriskl@familyhealth.com.au>; +Cc: Brent Henry <bh_pgperf@yahoo.com>; Dennis <dennis@works4me.com>; Tom Arthurs <tarthurs@jobflash.com>; pgsql-performance

On Wed, Jul 13, 2005 at 09:52:20AM +0800, Christopher Kings-Lynne wrote:
> The 8.0.2 jdbc driver uses real prepared statements instead of faked 
> ones.  The problem is the new protocol (that the 8.0.2 driver users) has 
> a bug where protocol-prepared queries don't get logged properly.
> I don't know if it's been fixed...

It's not in 8.0.3, but I was having the same problems with DBD::Pg so
I backported some of it and also changed the code so that it listed the
values of the bind parameters, so you get something like

LOG:  statement: SELECT sr.name,sr.seq_region_id, sr.length, 1 FROM seq_region sr  WHERE sr.name = $1 AND sr.coord_system_id = $2
LOG:  binding: "dbdpg_2" with 2 parameters
LOG:  bind "dbdpg_2" $1 = "20"
LOG:  bind "dbdpg_2" $2 = "1"
LOG:  statement: EXECUTE   [PREPARE:  SELECT sr.name,sr.seq_region_id, sr.length, 1 FROM seq_region sr  WHERE sr.name = $1 AND sr.coord_system_id = $2]
LOG:  duration: 0.164 ms

I've attached a patch in case anyone finds it useful.

    -Mark

Attachments:

timing.patch (text/plain, 3.8K) download *** postgresql-8.0.3/src/backend/tcop/postgres.c 2005-07-13 09:42:04.997669193 +0100 --- postgresql-8.0.3/src/backend/tcop/postgres.c 2005-07-13 09:34:24.618195580 +0100 *************** *** 1370,1375 **** --- 1370,1378 ---- else portal = CreatePortal(portal_name, false, false); + if (log_statement == LOGSTMT_ALL) + ereport(LOG, (errmsg("binding: \"%s\" with %d parameters", stmt_name, numParams))); + /* * Fetch parameters, if any, and store in the portal's memory context. * *************** *** 1428,1433 **** --- 1431,1439 ---- * grotty but is a big win when dealing with very * large parameter strings. */ + if (log_statement == LOGSTMT_ALL) + ereport(LOG, (errmsg("bind \"%s\" $%d = \"%s\"", stmt_name, i+1, pvalue))); + pbuf.data = (char *) pvalue; pbuf.maxlen = plength + 1; pbuf.len = plength; *************** *** 1578,1583 **** --- 1584,1593 ---- bool is_trans_exit = false; bool completed; char completionTag[COMPLETION_TAG_BUFSIZE]; + struct timeval start_t, stop_t; + bool save_log_duration = log_duration; + int save_log_min_duration_statement = log_min_duration_statement; + bool save_log_statement_stats = log_statement_stats; /* Adjust destination to tell printtup.c what to do */ dest = whereToSendOutput; *************** *** 1614,1619 **** --- 1624,1647 ---- set_ps_display(portal->commandTag); + /* + * We use save_log_* so "SET log_duration = true" and "SET + * log_min_duration_statement = true" don't report incorrect time + * because gettimeofday() wasn't called. Similarly, + * log_statement_stats has to be captured once. + */ + if (save_log_duration || save_log_min_duration_statement != -1) + gettimeofday(&start_t, NULL); + + if (save_log_statement_stats) + ResetUsage(); + + if (log_statement == LOGSTMT_ALL) + /* We have the portal, so output the source query. */ + ereport(LOG, + (errmsg("statement: EXECUTE %s [PREPARE: %s]", portal_name, + portal->sourceText ? portal->sourceText : ""))); + BeginCommand(portal->commandTag, dest); /* Check for transaction-control commands */ *************** *** 1708,1713 **** --- 1736,1785 ---- pq_putemptymessage('s'); } + /* + * Combine processing here as we need to calculate the query duration + * in both instances. + */ + if (save_log_duration || save_log_min_duration_statement != -1) + { + long usecs; + + gettimeofday(&stop_t, NULL); + if (stop_t.tv_usec < start_t.tv_usec) + { + stop_t.tv_sec--; + stop_t.tv_usec += 1000000; + } + usecs = (long) (stop_t.tv_sec - start_t.tv_sec) * 1000000 + + (long) (stop_t.tv_usec - start_t.tv_usec); + + /* Only print duration if we previously printed the statement. */ + if (log_statement == LOGSTMT_ALL && save_log_duration) + ereport(LOG, + (errmsg("duration: %ld.%03ld ms", + (long) ((stop_t.tv_sec - start_t.tv_sec) * 1000 + + (stop_t.tv_usec - start_t.tv_usec) / 1000), + (long) (stop_t.tv_usec - start_t.tv_usec) % 1000))); + + /* + * Output a duration_statement to the log if the query has + * exceeded the min duration, or if we are to print all durations. + */ + if (save_log_min_duration_statement == 0 || + (save_log_min_duration_statement > 0 && + usecs >= save_log_min_duration_statement * 1000)) + ereport(LOG, + (errmsg("duration: %ld.%03ld ms statement: EXECUTE %s [PREPARE: %s]", + (long) ((stop_t.tv_sec - start_t.tv_sec) * 1000 + + (stop_t.tv_usec - start_t.tv_usec) / 1000), + (long) (stop_t.tv_usec - start_t.tv_usec) % 1000, + portal_name, + portal->sourceText ? portal->sourceText : ""))); + } + + if (save_log_statement_stats) + ShowUsage("QUERY STATISTICS"); + debug_query_string = NULL; }
^ permalink raw reply [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
  2005-07-13 01:17         ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 01:36           ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 01:52             ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
@ 2005-07-13 16:10               ` Simon Riggs <simon@2ndquadrant.com>
  1 sibling, 0 replies; 12+ messages in thread

From: Simon Riggs @ 2005-07-13 16:10 UTC (permalink / raw)
  To: Christopher Kings-Lynne <chriskl@familyhealth.com.au>; +Cc: Brent Henry <bh_pgperf@yahoo.com>; Dennis <dennis@works4me.com>; Tom Arthurs <tarthurs@jobflash.com>; pgsql-performance

On Wed, 2005-07-13 at 09:52 +0800, Christopher Kings-Lynne wrote:
> > Is there a different kind of 'prepared' statements
> > that we should be using in the driver to get logging
> > to work properly?  What is the 'new' protocol?
> 
> The 8.0.2 jdbc driver uses real prepared statements instead of faked 
> ones.  The problem is the new protocol (that the 8.0.2 driver users) has 
> a bug where protocol-prepared queries don't get logged properly.
> 
> I don't know if it's been fixed...

Yes, there is a fix for this in 8.1

Brent has been sent the details.

Best Regards, Simon Riggs




^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
  2005-07-13 01:17         ` Re: General DB Tuning Christopher Kings-Lynne <chriskl@familyhealth.com.au>
  2005-07-13 01:36           ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
@ 2005-07-13 01:53             ` Tom Arthurs <tarthurs@jobflash.com>
  1 sibling, 0 replies; 12+ messages in thread

From: Tom Arthurs @ 2005-07-13 01:53 UTC (permalink / raw)
  To: Brent Henry <bh_pgperf@yahoo.com>; +Cc: Christopher Kings-Lynne <chriskl@familyhealth.com.au>; Dennis <dennis@works4me.com>; pgsql-performance

Here's the answer for you from the jdbc list:

> Alvin Hung wrote:
> 
> 
>>> Currently, 8.0.2 / JDBC 8.0-310, log_min_duration_statement does not
>>> work with JDBC.  Nothing will get logged.  This makes it very
>>> difficult to tune a java application.  Can you tell me when will this
>>> be fixed?  Thanks.
> 
> 
> This is a server limitation: it does not handle logging of the V3
> extended query protocol very well. There's gradual progress being made
> on it; you might want to search the pgsql-hackers and pgsql-patches
> archives for details.
==========================================================================================


We are using prepared statements, but we are using the 7.4 driver with 
the 8.0.3 server.  I think it comes down to locally (on the client) 
prepared statements vs using server side prepared statments.  I never 
got past this issue (changing the code is in our todo list, but pretty 
far down it) so I never noticed the logging issues.)

I had a problem with prepared statements with the 8.x drivers -- here's 
what I got from the jdbc list when I asked the question:

>>1.  What changed between the driver versions that generate this error?
> 
> 
> The driver started to use server-side prepared statements for
> parameterization of queries (i.e. the driver translates ? to $n in the
> main query string, and sends the actual parameter values out-of-band
> from the query itself). One sideeffect of this is that parameters are
> more strongly typed than in the 7.4.x versions where the driver would do
> literal parameter substitution into the query string before sending it
> to the backend. Also, you can use parameters in fewer places (they must
> fit the backend's idea of where parameterizable expressions are allowed)
> -- e.g. see the recent thread about "ORDER BY ?" changing behaviour with
> the newer driver.
> 
> 
>>> 2.  What is the downside of continuing to use the 7.x version of the
>>> driver -- or are there better alternatives (patch, new version, etc).  I
>>> am using build 311 of the driver.
> 
> 
> Most active development happens on the 8.0 version; 7.4.x is maintained
> for bugfixes but that's about it, you won't get the benefit of any
> performance improvements or added features that go into 8.0. Also, the
> 7.4.x driver won't necessarily work with servers >= 8.0.
> 
> In the longer term, the 7.4.x version will eventually become unmaintained.

So for the short term, you could downgrade your driver.


Brent Henry wrote:
> We are running Postgres 8.0.2 with the 8.0.2 jdbc
> driver.  And yes we are using prepared statements. 
> I've spent hours trying to get the
> 'log_min_duration_statement' and 'log_duration'
> options to work with no luck.  I never get any
> duration from the statement.  I also never see 'begin'
> or 'commit' in the log so I can't tell how long my
> batch commands are taking to commit to the DB.
> 
> Is there a different kind of 'prepared' statements
> that we should be using in the driver to get logging
> to work properly?  What is the 'new' protocol?
> 
> Tom, what version are you using?  Are you using
> prepared statements in JDBC?
> 
> -Brent
> 
> 
> --- Christopher Kings-Lynne
> <chriskl@familyhealth.com.au> wrote:
> 
> 
>>>>we are using jdbc -- the
>>
>>"log_min_duration_statement = 3000 " 
>>
>>>>statement works fine for me.  Looks like there's
>>
>>no other work around 
>>
>>>>for the bug(?).  Not sure since I have no
>>
>>interest in logging a 
>>
>>>>million statements a day, I only want to see the
>>
>>poorly performing hits. 
>>
>>>Doesn't it depend on what jdbc driver you are
>>
>>using?
>>
>>It depends if he's using new-protocol prepared
>>queries which don't get 
>>logged properly.  Wasn't that fixed for 8.1 or
>>something?
>>
>>Chris
>>
>>
>>---------------------------(end of
>>broadcast)---------------------------
>>TIP 3: Have you checked our extensive FAQ?
>>
>>               http://www.postgresql.org/docs/faq
>>
> 
> 
> 
> 
> 		
> ____________________________________________________
> Start your day with Yahoo! - make it your home page
> http://www.yahoo.com/r/hs
>  
> 
> 
> 



^ permalink  raw  reply  [nested|flat] 12+ messages in thread

* Re: General DB Tuning
  2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-12 21:54 ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-12 23:32   ` Re: General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
  2005-07-13 00:36     ` Re: General DB Tuning Tom Arthurs <tarthurs@jobflash.com>
  2005-07-13 01:05       ` Re: General DB Tuning Dennis <dennis@works4me.com>
@ 2005-07-13 01:30         ` Tom Arthurs <tarthurs@jobflash.com>
  1 sibling, 0 replies; 12+ messages in thread

From: Tom Arthurs @ 2005-07-13 01:30 UTC (permalink / raw)
  To: Dennis <dennis@works4me.com>; +Cc: pgsql-performance

hmm, yea maybe -- we are using the 7.4 driver with 8.0.x db.

Dennis wrote:
> Tom Arthurs wrote:
> 
>> we are using jdbc -- the "log_min_duration_statement = 3000 " 
>> statement works fine for me.  Looks like there's no other work around 
>> for the bug(?).  Not sure since I have no interest in logging a 
>> million statements a day, I only want to see the poorly performing hits. 
> 
> 
> 
> Doesn't it depend on what jdbc driver you are using?
> 
> Dennis
> 
> ---------------------------(end of broadcast)---------------------------
> TIP 2: Don't 'kill -9' the postmaster
> 
> 
> 



^ permalink  raw  reply  [nested|flat] 12+ messages in thread


end of thread, other threads:[~2005-07-13 16:10 UTC | newest]

Thread overview: 12+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2005-07-12 06:22 General DB Tuning Brent Henry <bh_pgperf@yahoo.com>
2005-07-12 21:54 ` Tom Arthurs <tarthurs@jobflash.com>
2005-07-12 23:32   ` Brent Henry <bh_pgperf@yahoo.com>
2005-07-13 00:36     ` Tom Arthurs <tarthurs@jobflash.com>
2005-07-13 01:05       ` Dennis <dennis@works4me.com>
2005-07-13 01:17         ` Christopher Kings-Lynne <chriskl@familyhealth.com.au>
2005-07-13 01:36           ` Brent Henry <bh_pgperf@yahoo.com>
2005-07-13 01:52             ` Christopher Kings-Lynne <chriskl@familyhealth.com.au>
2005-07-13 10:07               ` Mark Rae <mrae@purplebat.com>
2005-07-13 16:10               ` Simon Riggs <simon@2ndquadrant.com>
2005-07-13 01:53             ` Tom Arthurs <tarthurs@jobflash.com>
2005-07-13 01:30         ` Tom Arthurs <tarthurs@jobflash.com>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox