Re: [HACKERS] mysterious log output

2005-03-01 Thread Robert Treat
On Tuesday 01 March 2005 12:46, Tom Lane wrote:
> Bruce Momjian  writes:
> > Tom Lane wrote:
> >> This has to be coming from exec_simple_query():
> >
> > I wonder if some statistics were turned on at postmaster start and even
> > though it was turned off and 'pg_ctl reload' was done the
> > checkpoint/bgwriter process isn't reloading for some reason.
>
> The checkpoint/bgwriter never executes exec_simple_query().  I think
> the 5-minute cycle is driven by something in Robert's application,
> rather than being tied to checkpoints.
>

Actually looking at it now, it happens every 10 minutes, so you're right in 
that it doesn't coincide with the bgwriter.  Actually I am pretty sure this 
is slony related... the output is always on the same pid, and everything else 
output on that pid is slony commands.  Is there some way I could see what 
that pid thinks the GUC variables are set to?  I have a wild theory that 
slony is preventing the modification of SUSET level variables, but haven't 
really got anything solid to back that up. 

-- 
Robert Treat
Build A Brighter Lamp :: Linux Apache {middleware} PostgreSQL

---(end of broadcast)---
TIP 2: you can get off all lists at once with the unregister command
(send "unregister YourEmailAddressHere" to [EMAIL PROTECTED])


Re: [HACKERS] mysterious log output

2005-03-01 Thread Tom Lane
Bruce Momjian  writes:
> Tom Lane wrote:
>> This has to be coming from exec_simple_query():

> I wonder if some statistics were turned on at postmaster start and even
> though it was turned off and 'pg_ctl reload' was done the
> checkpoint/bgwriter process isn't reloading for some reason.

The checkpoint/bgwriter never executes exec_simple_query().  I think
the 5-minute cycle is driven by something in Robert's application,
rather than being tied to checkpoints.

regards, tom lane

---(end of broadcast)---
TIP 5: Have you checked our extensive FAQ?

   http://www.postgresql.org/docs/faq


Re: [HACKERS] mysterious log output

2005-03-01 Thread Bruce Momjian
Tom Lane wrote:
> Robert Treat <[EMAIL PROTECTED]> writes:
> > I keep seeing the following log output around every 5 minutes:
> > 2005-02-28 23:25:05 [8646] LOG:  0: QUERY STATISTICS
> 
> This has to be coming from exec_simple_query():
> 
>   if (save_log_statement_stats)
>   ShowUsage("QUERY STATISTICS");
> 
> so *something* is turning on log_statement_stats.

I wonder if some statistics were turned on at postmaster start and even
though it was turned off and 'pg_ctl reload' was done the
checkpoint/bgwriter process isn't reloading for some reason.

-- 
  Bruce Momjian|  http://candle.pha.pa.us
  pgman@candle.pha.pa.us   |  (610) 359-1001
  +  If your life is a hard drive, |  13 Roberts Road
  +  Christ can be your backup.|  Newtown Square, Pennsylvania 19073

---(end of broadcast)---
TIP 1: subscribe and unsubscribe commands go to [EMAIL PROTECTED]


Re: [HACKERS] mysterious log output

2005-02-28 Thread Tom Lane
Robert Treat <[EMAIL PROTECTED]> writes:
> I keep seeing the following log output around every 5 minutes:
> 2005-02-28 23:25:05 [8646] LOG:  0: QUERY STATISTICS

This has to be coming from exec_simple_query():

if (save_log_statement_stats)
ShowUsage("QUERY STATISTICS");

so *something* is turning on log_statement_stats.

regards, tom lane

---(end of broadcast)---
TIP 9: the planner will ignore your desire to choose an index scan if your
  joining column's datatypes do not match


[HACKERS] mysterious log output

2005-02-28 Thread Robert Treat
I keep seeing the following log output around every 5 minutes:

2005-02-28 23:25:05 [8646] LOG:  0: QUERY STATISTICS
DETAIL:  ! system usage stats:
!   0.005023 elapsed 0.00 user 0.00 system sec
!   [537.13 user 44.86 sys total]
!   0/0 [0/0] filesystem blocks in/out
!   0/4 [848810/1849693] page faults/reclaims, 0 [0] swaps
!   0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
!   0/0 [0/0] voluntary/involuntary context switches
! buffer usage stats:
!   Shared blocks:  0 read,  0 written, buffer hit 
rate = 100.00%
!   Local  blocks:  0 read,  0 written, buffer hit 
rate = 0.00%
!   Direct blocks:  0 read,  0 written
LOCATION:  ShowUsage, postgres.c:3199


The server is postgresql 7.4, running on debian linux.  According to 
postgres.c, it should be outputting due to GUC, however I verified that all 
of the log_*_stats lines in the postgresql.conf are turned off and also 
verified those GUC's are off in the show all; output... here's the relevant 
bits.

log_connections| off
 log_duration   | off
 log_error_verbosity| verbose
 log_executor_stats | off
 log_hostname   | off
 log_min_duration_statement | 5000
 log_min_error_statement| info
 log_min_messages   | notice
 log_parser_stats   | off
 log_pid| on
 log_planner_stats  | off
 log_source_port| off
 log_statement  | off
 log_statement_stats| off
 log_timestamp  | on

the only thing real sketchy about this is that it always seems to be on the 
same pid (8646) and if I turn query logging on I see the following executed 
right before this happens:

2005-03-01 00:25:08 [8646] LOG:  0: statement: select 
"_rv".cleanupEvent();
LOCATION:  pg_parse_query, postgres.c:464

now according to the slony folks, there is nothing in slony that modifys the 
logging output... so assuming that's true, anyone have any ideas on what 
might be causing this logging? 

-- 
Robert Treat
Build A Brighter Lamp :: Linux Apache {middleware} PostgreSQL

---(end of broadcast)---
TIP 8: explain analyze is your friend