Received: from makus.postgresql.org (makus.postgresql.org [98.129.198.125]) by mail.postgresql.org (Postfix) with ESMTP id 0669D1648184 for ; Fri, 30 Mar 2012 13:20:55 -0300 (ADT) Received: from server316.com ([216.35.196.86]) by makus.postgresql.org with esmtp (Exim 4.72) (envelope-from ) id 1SDeZI-0003lk-KR for pgsql-admin@postgresql.org; Fri, 30 Mar 2012 16:20:55 +0000 Received: (qmail 7372 invoked by uid 503); 30 Mar 2012 16:20:39 -0000 Received: from unknown (HELO EricPC) (70.252.139.147) by server316.com with ESMTPS (AES128-SHA encrypted); 30 Mar 2012 16:20:39 -0000 From: "Eric Simon" To: Subject: Warnings in Standby Logs Date: Fri, 30 Mar 2012 11:20:44 -0500 Message-ID: <003501cd0e91$0eee7dd0$2ccb7970$@theiqgroup.com> MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_NextPart_000_0036_01CD0E67.261ABFC0" X-Mailer: Microsoft Outlook 14.0 Thread-Index: Ac0OkQ19N6qSQZHiQX61eUNk5Ec6sQ== Content-Language: en-us X-Pg-Spam-Score: -1.9 (-) X-Archive-Number: 201203/141 X-Sequence-Number: 39329 This is a multipart message in MIME format. ------=_NextPart_000_0036_01CD0E67.261ABFC0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Hi, I'm on 9.1.2 and occasionally get what are probably harmless warning messages in my logs, but because I have the responsibility of ensuring we haven't lost a bit of data between our master and standby, I feel I should know exactly what they mean. I occasionally see "invalid record length" and "record with zero length" in my logs, and they almost only occur during reboots (the "consistent recovery state reached" message gives me the warm-fuzzy, but then when they're followed by either of those two, it leaves me wondering). For example, I had to reboot my hot standby twice this month: 2012-03-16 10:23:28 CDT LOG: received smart shutdown request 2012-03-16 10:23:28 CDT FATAL: terminating walreceiver process due to administrator command 2012-03-16 10:27:33 CDT LOG: database system was interrupted while in recovery at log time 2012-03-16 10:14:15 CDT 2012-03-16 10:27:33 CDT HINT: If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target. 2012-03-16 10:27:33 CDT LOG: entering standby mode 2012-03-16 10:27:34 CDT LOG: redo starts at 9/B98D6968 2012-03-16 10:27:34 CDT LOG: consistent recovery state reached at 9/B9F171B0 2012-03-16 10:27:34 CDT LOG: database system is ready to accept read only connections 2012-03-16 10:27:34 CDT LOG: invalid record length at 9/B9F85E78 2012-03-16 10:27:34 CDT LOG: streaming replication successfully connected to primary 2012-03-16 10:28:07 CDT LOG: received smart shutdown request 2012-03-16 10:28:07 CDT FATAL: terminating walreceiver process due to administrator command 2012-03-16 10:28:07 CDT LOG: shutting down 2012-03-16 10:47:00 CDT LOG: database system was interrupted while in recovery at log time 2012-03-16 10:14:15 CDT 2012-03-16 10:47:00 CDT HINT: If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target. 2012-03-16 10:47:00 CDT LOG: entering standby mode 2012-03-16 10:47:01 CDT LOG: redo starts at 9/B98D6968 2012-03-16 10:47:02 CDT LOG: consistent recovery state reached at 9/BA2D3490 2012-03-16 10:47:02 CDT LOG: database system is ready to accept read only connections 2012-03-16 10:47:02 CDT LOG: invalid record length at 9/BA2D3490 2012-03-16 10:47:02 CDT LOG: streaming replication successfully connected to primary Is this something I should be concerned about (and even if not, where can I read about what these mean in detail)? Also, is there a more elegant shutdown command I can use so that when it starts up again, I don't get these "invalid record length" type messages? P.S. I have searched the forums and the docs several times, so I apologize if I missed the answer/tutorial on this somewhere. Thanks, Eric Simon ------=_NextPart_000_0036_01CD0E67.261ABFC0 Content-Type: text/html; charset="us-ascii" Content-Transfer-Encoding: quoted-printable

Hi,

I'm on 9.1.2 and occasionally = get what are probably harmless warning messages in my logs, but because = I have the responsibility of ensuring we haven't lost a bit of data = between our master and standby, I feel I should know exactly what they = mean. I occasionally see "invalid record length" and = "record with zero length" in my logs, and they almost only = occur during reboots (the "consistent recovery state reached" = message gives me the warm-fuzzy, but then when they're followed by = either of those two, it leaves me wondering). For example, I had to = reboot my hot standby twice this month:

2012-03-16 10:23:28 = CDT LOG:  received smart shutdown request
2012-03-16 10:23:28 = CDT FATAL:  terminating walreceiver process due to administrator = command
2012-03-16 10:27:33 CDT LOG:  database system was = interrupted while in recovery at log time 2012-03-16 10:14:15 = CDT
2012-03-16 10:27:33 CDT HINT:  If this has occurred more = than once some data might be corrupted and you might need to choose an = earlier recovery target.
2012-03-16 10:27:33 CDT LOG:  entering = standby mode
2012-03-16 10:27:34 CDT LOG:  redo starts at = 9/B98D6968
2012-03-16 10:27:34 CDT LOG:  consistent recovery = state reached at 9/B9F171B0
2012-03-16 10:27:34 CDT LOG:  = database system is ready to accept read only connections
2012-03-16 = 10:27:34 CDT LOG:  invalid record length at = 9/B9F85E78
2012-03-16 10:27:34 CDT LOG:  streaming replication = successfully connected to primary
2012-03-16 10:28:07 CDT LOG:  = received smart shutdown request
2012-03-16 10:28:07 CDT FATAL:  = terminating walreceiver process due to administrator = command
2012-03-16 10:28:07 CDT LOG:  shutting = down
2012-03-16 10:47:00 CDT LOG:  database system was = interrupted while in recovery at log time 2012-03-16 10:14:15 = CDT
2012-03-16 10:47:00 CDT HINT:  If this has occurred more = than once some data might be corrupted and you might need to choose an = earlier recovery target.
2012-03-16 10:47:00 CDT LOG:  entering = standby mode
2012-03-16 10:47:01 CDT LOG:  redo starts at = 9/B98D6968
2012-03-16 10:47:02 CDT LOG:  consistent recovery = state reached at 9/BA2D3490
2012-03-16 10:47:02 CDT LOG:  = database system is ready to accept read only connections
2012-03-16 = 10:47:02 CDT LOG:  invalid record length at = 9/BA2D3490
2012-03-16 10:47:02 CDT LOG:  streaming replication = successfully connected to primary

Is this something I = should be concerned about (and even if not, where can I read about what = these mean in detail)?

Also, is there a more elegant shutdown = command I can use so that when it starts up again, I don’t get = these “invalid record length” type messages?

P.S. I = have searched the forums and the docs several times, so I apologize if I = missed the answer/tutorial on this somewhere.

Thanks,

Eric = Simon

------=_NextPart_000_0036_01CD0E67.261ABFC0--