DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com;
	h=X-YMail-OSG:Received:X-Mailer:Message-ID:Date:From:Reply-To:Subject:To:MIME-Version:Content-Type:Content-Transfer-Encoding;
	b=rL7rjIt7a+uijPSILKyz9Q7cxIP51vD1g4HTa9oVIds4fpeOZWEkQf3Pj49i1RLxL5UTFgmWwoXUyAMsV5ztGgniilH7Cgv0ZErzvZYbFA8a75erdbgsPSLyFVb2Pl5jOaJOXtat8qcNSsSdJYKHdducBECOQGZhk7oWgnK7SSE=;
Message-ID: <1328640207.42210.YahooMailNeo@web46103.mail.sp1.yahoo.com>
Date: Tue, 7 Feb 2012 10:43:27 -0800 (PST)
From: Greg Williamson <gwilliamson39@yahoo.com>
Reply-To: Greg Williamson <gwilliamson39@yahoo.com>
Subject: postgres 9.0 date aberration in logs
To: "pgsql-admin@postgresql.org" <pgsql-admin@postgresql.org>
MIME-Version: 1.0
Content-Type: text/plain; charset=iso-8859-1
Content-Transfer-Encoding: quoted-printable

The server seems to have written the wrong date for the first 45 minutes or=
 so of Tuesday before switching in mid-stream:=0A<...>=0A2012-01-31 23:58:0=
5 PST [13586]: [29677-1] LOG: =A0checkpoint starting: time=0A2012-01-31 23:=
58:08 PST [13586]: [29678-1] LOG: =A0checkpoint complete: wrote 16 buffers =
(0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=3D3.0=
08 s, sync=3D=0A0.001 s, total=3D3.010 s=0A2012-02-07 00:00:41 PST [30535]:=
 [333-1] LOG: =A0checkpoint starting: time=0A2012-02-07 00:00:42 PST [30535=
]: [334-1] LOG: =A0checkpoint complete: wrote 9 buffers (0.0%); 0 transacti=
on log file(s) added, 0 removed, 0 recycled; write=3D1.603 s, sync=3D0.0=0A=
01 s, total=3D1.605 s=0A<...>=0A=0ANo editing -- honest !=0A=0AThis is what=
 the log dates look like:=0Als -ltr =A0/var/log/pg_log9.0=0Atotal 8652=0A-r=
w------- 1 postgres postgres 1729857 Feb =A01 23:59 postgresql-Wed.log=0A-r=
w------- 1 postgres postgres =A0930974 Feb =A02 23:57 postgresql-Thu.log=0A=
-rw------- 1 postgres postgres =A0441021 Feb =A03 23:57 postgresql-Fri.log=
=0A-rw------- 1 postgres postgres 1041907 Feb =A04 23:57 postgresql-Sat.log=
=0A-rw------- 1 postgres postgres 1546812 Feb =A05 23:58 postgresql-Sun.log=
=0A-rw------- 1 postgres postgres 1180910 Feb =A06 23:55 postgresql-Mon.log=
=0A-rw------- 1 postgres postgres 1943900 Feb =A07 10:40 postgresql-Tue.log=
=0A=0A=0AThis is the end of Monday's log:=0A-bash-3.2$ tail /var/log/pg_log=
9.0/postgresql-Mon.log=0A2012-02-06 23:35:41 PST [30535]: [323-1] LOG: =A0c=
heckpoint starting: time=0A2012-02-06 23:35:42 PST [30535]: [324-1] LOG: =
=A0checkpoint complete: wrote 10 buffers (0.0%); 0 transaction log file(s) =
added, 0 removed, 0 recycled; write=3D1.804 s, sync=3D0.001 s, total=3D1.80=
7 s=0A2012-02-06 23:40:41 PST [30535]: [325-1] LOG: =A0checkpoint starting:=
 time=0A2012-02-06 23:40:42 PST [30535]: [326-1] LOG: =A0checkpoint complet=
e: wrote 10 buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 r=
ecycled; write=3D1.802 s, sync=3D0.001 s, total=3D1.805 s=0A2012-02-06 23:4=
5:41 PST [30535]: [327-1] LOG: =A0checkpoint starting: time=0A2012-02-06 23=
:45:43 PST [30535]: [328-1] LOG: =A0checkpoint complete: wrote 11 buffers (=
0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=3D2.00=
2 s, sync=3D0.001 s, total=3D2.005 s=0A2012-02-06 23:50:41 PST [30535]: [32=
9-1] LOG: =A0checkpoint starting: time=0A2012-02-06 23:50:42 PST [30535]: [=
330-1] LOG: =A0checkpoint complete: wrote 6 buffers (0.0%); 0 transaction l=
og file(s) added, 0 removed, 0 recycled; write=3D1.007 s, sync=3D0.000 s, t=
otal=3D1.009 s=0A2012-02-06 23:55:41 PST [30535]: [331-1] LOG: =A0checkpoin=
t starting: time=0A2012-02-06 23:55:42 PST [30535]: [332-1] LOG: =A0checkpo=
int complete: wrote 10 buffers (0.0%); 0 transaction log file(s) added, 0 r=
emoved, 0 recycled; write=3D1.805 s, sync=3D0.001 s, total=3D1.807 s=0A=0A=
=0AAnd the start of Tuesday's:=0Ahead =A0/var/log/pg_log9.0/postgresql-Tue.=
log=A0=0A2012-01-31 00:03:53 PST [13586]: [29091-1] LOG: =A0checkpoint star=
ting: time=0A2012-01-31 00:03:54 PST [13586]: [29092-1] LOG: =A0checkpoint =
complete: wrote 9 buffers (0.0%); 0 transaction log file(s) added, 0 remove=
d, 0 recycled; write=3D1.602 s, sync=3D0.001 s, total=3D1.604 s=0A2012-01-3=
1 00:04:45 PST [6186]: [36-1] LOG: =A0duration: 1831.813 ms =A0execute fetc=
h from S_2/C_3: select<...>=0A=0A=0AThe system log doesn't show anything hi=
nky:=0Aess /var/log/messages=0A=0A<...>=0AFeb =A06 23:56:56 sf1ddb001 puppe=
t-agent[28309]: Finished catalog run in 10.51 seconds=0AFeb =A07 00:15:53 s=
f1ddb001 xinetd[6141]: START: amanda pid=3D17175 from=3D192.168.50.89=0AFeb=
 =A07 00:16:05 sf1ddb001 xinetd[6141]: EXIT: amanda status=3D0 pid=3D17175 =
duration=3D12(sec)=0AFeb =A07 00:18:37 sf1ddb001 xinetd[6141]: START: amand=
a pid=3D17507 from=3D192.168.50.89=0AFeb =A07 00:18:37 sf1ddb001 xinetd[614=
1]: EXIT: amanda status=3D0 pid=3D17507 duration=3D0(sec)=0AFeb =A07 00:18:=
55 sf1ddb001 xinetd[6141]: START: amanda pid=3D17776 from=3D192.168.50.89=
=0AFeb =A07 00:18:55 sf1ddb001 xinetd[6141]: EXIT: amanda status=3D0 pid=3D=
17776 duration=3D0(sec)=0AFeb =A07 00:19:10 sf1ddb001 xinetd[6141]: START: =
amanda pid=3D17859 from=3D192.168.50.89=0AFeb =A07 00:19:10 sf1ddb001 xinet=
d[6141]: EXIT: amanda status=3D0 pid=3D17859 duration=3D0(sec)=0AFeb =A07 0=
0:19:26 sf1ddb001 xinetd[6141]: START: amanda pid=3D17880 from=3D192.168.50=
.89=0AFeb =A07 00:19:26 sf1ddb001 xinetd[6141]: EXIT: amanda status=3D0 pid=
=3D17880 duration=3D0(sec)=0AFeb =A07 00:19:55 sf1ddb001 xinetd[6141]: STAR=
T: amanda pid=3D17922 from=3D192.168.50.89=0AFeb =A07 00:20:02 sf1ddb001 xi=
netd[6141]: EXIT: amanda status=3D0 pid=3D17922 duration=3D7(sec)=0AFeb =A0=
7 00:27:12 sf1ddb001 puppet-agent[28309]: Finished catalog run in 10.36 sec=
onds=0AFeb =A07 00:57:27 sf1ddb001 puppet-agent[28309]: Finished catalog ru=
n in 10.16 seconds=0AFeb =A07 01:27:43 sf1ddb001 puppet-agent[28309]: Finis=
hed catalog run in 10.86 seconds=0AFeb =A07 01:57:59 sf1ddb001 puppet-agent=
[28309]: Finished catalog run in 10.48 seconds=0A<...>=0A=0AHas anyone ever=
 seen anything like this ?=A0=0A=0AThanks for any suggestions, advice, etc.=
=0A=0AGreg WIlliamson=0ADBA=0APowerreviews=0A