| From: | "George Pavlov" <gpavlov(at)mynewplace(dot)com> | 
|---|---|
| To: | <pgsql-general(at)postgresql(dot)org> | 
| Subject: | negative duration times in query logs | 
| Date: | 2008-01-03 22:14:12 | 
| Message-ID: | 8C5B026B51B6854CBE88121DBF097A86018F88B4@ehost010-33.exch010.intermedia.net | 
| Views: | Whole Thread | Raw Message | Download mbox | Resend email | 
| Thread: | |
| Lists: | pgsql-general | 
I started seeing some negative durations in my production query logs --
a "-" sign preceding the duration number, e.g.:
% grep 'duration: -' postgresql-Wed-*
postgresql-Wed-09.log:2008-01-02 08:56:33 PST [11705]: [538-1] LOG:
duration: -268280.421 ms
postgresql-Wed-15.log:2008-01-02 15:01:01 PST [30072]: [18-1] LOG:
duration: -1005.500 ms
postgresql-Wed-15.log:2008-01-02 15:01:01 PST [30066]: [14-1] LOG:
duration: -265.634 ms
These follow fairly standard queries that are issued hundreds if not
thousands times a day and ordinarily produce "normal" (positive)
durations. 
Has anyone seen this before? Any special meaning to the minus sign
(maybe it does not mean negative, but something else?)
I am running:
PostgreSQL 8.1.10 on x86_64-redhat-linux-gnu, compiled by GCC gcc (GCC)
3.4.6 20060404 (Red Hat 3.4.6-3)
My logging setup is:
 log_connections                 | on              
 log_destination                 | stderr          
 log_disconnections              | on              
 log_duration                    | on              
 log_error_verbosity             | default         
 log_executor_stats              | off             
 log_hostname                    | off             
 log_line_prefix                 | %t [%p]: [%l-1] 
 log_min_duration_statement      | -1              
 log_min_error_statement         | panic           
 log_min_messages                | notice          
 log_parser_stats                | off             
 log_planner_stats               | off             
 log_rotation_age                | 60              
 log_rotation_size               | 0               
 log_statement                   | all             
 log_statement_stats             | off             
 log_truncate_on_rotation        | on              
 redirect_stderr                 | on              
George
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Geoffrey | 2008-01-04 00:17:00 | Re: [OT] Slony (initial) Replication - Slow | 
| Previous Message | James B. Byrne | 2008-01-03 21:57:33 | CentOS-5 PostgreSQL 8.1.9 server instrumentation |