Received: from maia.hub.org (maia-2.hub.org [200.46.204.251]) by mail.postgresql.org (Postfix) with ESMTP id 6A1361337B5D for ; Mon, 29 Nov 2010 19:46:55 -0400 (AST) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.251]) (amavisd-maia, port 10024) with ESMTP id 94408-08 for ; Mon, 29 Nov 2010 23:46:48 +0000 (UTC) X-Greylist: delayed 00:05:15.898978 by SQLgrey-1.7.6 Received: from na3sys009aog101.obsmtp.com (na3sys009aog101.obsmtp.com [74.125.149.67]) by mail.postgresql.org (Postfix) with SMTP id 2E33F1337B50 for ; Mon, 29 Nov 2010 19:46:47 -0400 (AST) Received: from source ([209.85.214.172]) by na3sys009aob101.postini.com ([74.125.148.12]) with SMTP ID DSNKTPQ7ZkfdAcR+LCNZjV1Fz63PuVmbmIjJ@postini.com; Mon, 29 Nov 2010 15:46:48 PST Received: by mail-iw0-f172.google.com with SMTP id 40so6339535iwn.3 for ; Mon, 29 Nov 2010 15:46:46 -0800 (PST) Received: by 10.231.157.146 with SMTP id b18mr1448565ibx.33.1291074088940; Mon, 29 Nov 2010 15:41:28 -0800 (PST) From: Michael Holt MIME-Version: 1.0 X-Mailer: Microsoft Office Outlook 12.0 Thread-Index: AcuQHvFGnC5lq5PNQlmiJ3ee8qOozg== Date: Mon, 29 Nov 2010 15:41:28 -0800 Message-ID: <8a0b69864ef0bd962213ad553c113a44@mail.gmail.com> Subject: Diagnosing Postgres Segfault To: pgsql-admin@postgresql.org Content-Type: multipart/alternative; boundary=001636d3402273377a0496399c61 X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-4.199 tagged_above=-10 required=5 tests=BAYES_00=-1.9, HTML_MESSAGE=0.001, RCVD_IN_DNSWL_MED=-2.3 X-Spam-Level: X-Archive-Number: 201011/241 X-Sequence-Number: 36207 --001636d3402273377a0496399c61 Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: quoted-printable Early this morning one of our databases suffered a segfault. The only note on this in /var/log/messages was: Nov 29 03:34:07 servername kernel: postmaster[18265]: segfault at 0000000017b82000 rip 0000003c45e7c266 rsp 00007fff2ca1b7d8 error 4 (replaced actual server name with servername) The postgres log has a bit more information: 2010-11-29 03:34:07 PST LOG: server process (PID 18265) was terminated by signal 11 2010-11-29 03:34:07 PST LOG: terminating any other active server processe= s 2010-11-29 03:34:07 PST 10.2.0.18 WARNING: terminating connection because of crash of another server process 2010-11-29 03:34:07 PST 10.2.0.18 DETAIL: The postmaster has commanded thi= s server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 2010-11-29 03:34:07 PST 10.2.0.18 HINT: In a moment you should be able to reconnect to the database and repeat your command. 2010-11-29 03:34:07 PST 10.2.0.18 WARNING: terminating connection because of crash of another server process 2010-11-29 03:34:07 PST 10.2.0.18 DETAIL: The postmaster has commanded thi= s server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 2010-11-29 03:34:07 PST 10.2.0.18 HINT: In a moment you should be able to reconnect to the database and repeat your command. 2010-11-29 03:34:07 PST 10.2.0.18 WARNING: terminating connection because of crash of another server process 2010-11-29 03:34:07 PST 10.2.0.18 DETAIL: The postmaster has commanded thi= s server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 2010-11-29 03:34:07 PST 10.2.0.18 HINT: In a moment you should be able to reconnect to the database and repeat your command. 2010-11-29 03:34:07 PST 10.2.0.18 FATAL: the database system is in recover= y mode 2010-11-29 03:34:07 PST LOG: all server processes terminated; reinitializing 2010-11-29 03:34:10 PST 10.2.0.17 FATAL: the database system is starting u= p 2010-11-29 03:34:10 PST 10.2.0.17 FATAL: the database system is starting u= p 2010-11-29 03:34:10 PST 127.0.0.1 FATAL: the database system is starting u= p 2010-11-29 03:34:10 PST 10.2.0.17 FATAL: the database system is starting u= p 2010-11-29 03:34:10 PST 10.2.0.18 FATAL: the database system is starting u= p 2010-11-29 03:34:10 PST 10.2.0.18 FATAL: the database system is starting u= p 2010-11-29 03:34:10 PST LOG: database system was interrupted at 2010-11-2= 9 03:30:26 PST 2010-11-29 03:34:10 PST LOG: checkpoint record is at 41F/723A1648 2010-11-29 03:34:10 PST LOG: redo record is at 41F/723A1648; undo record is at 0/0; shutdown FALSE 2010-11-29 03:34:10 PST LOG: next transaction ID: 0/1144655884; next OID: 630827 2010-11-29 03:34:10 PST LOG: next MultiXactId: 1; next MultiXactOffset: 0 2010-11-29 03:34:10 PST LOG: database system was not properly shut down; automatic recovery in progress 2010-11-29 03:34:10 PST LOG: record with zero length at 41F/723A1698 2010-11-29 03:34:10 PST LOG: redo is not required 2010-11-29 03:34:10 PST 10.2.0.17 FATAL: the database system is starting u= p 2010-11-29 03:34:10 PST LOG: database system is ready I=92m trying to figure out what might have caused this, partly because I wa= nt to replicate the segfault to see if it is the cause of another system randomly freezing on us. Is there any way to figure out exactly what query being run at the time of the crash was doing? Could the xlog files help me in anyway? --001636d3402273377a0496399c61 Content-Type: text/html; charset=windows-1252 Content-Transfer-Encoding: quoted-printable

Early this morning one of our= databases suffered a segfault. The only note on this in /var/log/messages = was:

=A0

Nov 29 03:34:07 server= name kernel: postmaster[18265]: segfault at 0000000017b82000 rip 0000003c45= e7c266 rsp 00007fff2ca1b7d8 error 4

(replaced act= ual server name with servername)

=A0

The postgres log has a= bit more information:

=A0

2010-11-29 03:34:07 PST=A0 LOG:=A0 server process (PID 18265) was termi= nated by signal 11

2010-11-29 03:34:07 PST=A0 LOG:=A0 terminating any o= ther active server processes

2010-11-29 03:34:07 = PST 10.2.0.18 WARNING:=A0 terminating connection because of crash of anothe= r server process

2010-11-29 03:34:07 PST 10.2.0.18 DETAIL:=A0 The pos= tmaster has commanded this server process to roll back the current transact= ion and exit, because another server process exited abnormally and possibly= corrupted shared memory.

2010-11-29 03:34:07 PST 10.2.0.18 HINT:=A0 In a mome= nt you should be able to reconnect to the database and repeat your command.=

2010-11-29 03:34:07 PST 10.2.0.18 WARNING:=A0 te= rminating connection because of crash of another server process

2010-11-29 03:34:07 PST 10.2.0.18 DETAIL:=A0 The pos= tmaster has commanded this server process to roll back the current transact= ion and exit, because another server process exited abnormally and possibly= corrupted shared memory.

2010-11-29 03:34:07 PST 10.2.0.18 HINT:=A0 In a mome= nt you should be able to reconnect to the database and repeat your command.=

2010-11-29 03:34:07 PST 10.2.0.18 WARNING:=A0 te= rminating connection because of crash of another server process

2010-11-29 03:34:07 PST 10.2.0.18 DETAIL:=A0 The pos= tmaster has commanded this server process to roll back the current transact= ion and exit, because another server process exited abnormally and possibly= corrupted shared memory.

2010-11-29 03:34:07 PST 10.2.0.18 HINT:=A0 In a mome= nt you should be able to reconnect to the database and repeat your command.=

2010-11-29 03:34:07 PST 10.2.0.18 FATAL:=A0 the = database system is in recovery mode

2010-11-29 03:34:07 PST=A0 LOG:=A0 all server proces= ses terminated; reinitializing

2010-11-29 03:34:1= 0 PST 10.2.0.17 FATAL:=A0 the database system is starting up

2010-11-29 03:34:10 PST 10.2.0.17 FATAL:=A0 the database system is starting= up

2010-11-29 03:34:10 PST 127.0.0.1 FATAL:=A0 t= he database system is starting up

2010-11-29 03:3= 4:10 PST 10.2.0.17 FATAL:=A0 the database system is starting up

2010-11-29 03:34:10 PST 10.2.0.18 FATAL:=A0 the data= base system is starting up

2010-11-29 03:34:10 PS= T 10.2.0.18 FATAL:=A0 the database system is starting up

2010-11-29 03:34:10 PST=A0 LOG:=A0 database system was interrupted at 2010-= 11-29 03:30:26 PST

2010-11-29 03:34:10 PST=A0 LOG= :=A0 checkpoint record is at 41F/723A1648

2010-11= -29 03:34:10 PST=A0 LOG:=A0 redo record is at 41F/723A1648; undo record is = at 0/0; shutdown FALSE

2010-11-29 03:34:10 PST=A0 LOG:=A0 next transaction = ID: 0/1144655884; next OID: 630827

2010-11-29 03:= 34:10 PST=A0 LOG:=A0 next MultiXactId: 1; next MultiXactOffset: 0

2010-11-29 03:34:10 PST=A0 LOG:=A0 database system was not properly shut do= wn; automatic recovery in progress

2010-11-29 03:= 34:10 PST=A0 LOG:=A0 record with zero length at 41F/723A1698

2010-11-29 03:34:10 PST=A0 LOG:=A0 redo is not required

2010-11-29 03:34:10 PST 10.2.0.17 FATAL:=A0 the database system is s= tarting up

2010-11-29 03:34:10 PST=A0 LOG:=A0 dat= abase system is ready

=A0

I=92m trying to figure= out what might have caused this, partly because I want to replicate the se= gfault to see if it is the cause of another system randomly freezing on us.= Is there any way to figure out exactly what query being run at the time of= the crash was doing? Could the xlog files help me in anyway?

--001636d3402273377a0496399c61--