Обсуждение: PG shutdown itself?
Greetings,
To best of my knowledge, nobody issued pg_ctl stop –m fast while
we experienced PG was trying to shutdown unsuccessfully:
*** Everything seems normal before this point ***
Mar 3 21:07:55 myhost postgres[630]: [24] LOG: recycled transaction log file 00001ABC0000006D
Mar 3 21:08:57 myhost postgres[5158]: [1] LOG: fast shutdown request
Mar 3 21:08:57 myhost postgres[5158]: [2] LOG: aborting any active transactions
Mar 3 21:08:57 myhost postgres[14292]: [1] FATAL: This connection has been terminated by the administrator.
*** A lot of “This connection has been terminated by the administrator.” taken out here ***
Mar 3 21:08:57 myhost postgres[15912]: [3] FATAL: The database system is shutting down
*** A lot the same message as last line till ***
Mar 3 22:10:39 myhost postgres[1840]: [3] FATAL: The database system is shutting down
Then I used “–m immediate”:
Mar 3 22:10:39 myhost postgres[5158]: [3] LOG: immediate shutdown request
Mar 3 22:11:07 myhost postgres[1918]: [1] LOG: database system was interrupted at 2005-03-03 21:08:53 MST
Mar 3 22:11:07 myhost postgres[1918]: [2] LOG: checkpoint record is at 1ABC/929DFCB4
Mar 3 22:11:07 myhost postgres[1918]: [3] LOG: redo record is at 1ABC/9044F3B4; undo record is at 0/0; shutdown FALSE
Mar 3 22:11:07 myhost postgres[1918]: [4] LOG: next transaction id: 1090597972; next oid: 4231750970
Mar 3 22:11:07 myhost postgres[1918]: [5] LOG: database system was not properly shut down; automatic recovery in progress
Mar 3 22:11:07 myhost postgres[1918]: [6] LOG: redo starts at 1ABC/9044F3B4
Mar 3 22:11:07 myhost postgres[1919]: [1] FATAL: The database system is starting up
*** PG was up after a lot of the above message ***
PG version is 7.3.2 on Red Hat Enterprise Linux ES release 3 (Taroon Update 4)
I know it is old, but anyone can smell why PG shutdown itself?
Thank you,
On Fri, 2005-03-04 at 11:38, Lee Wu wrote: > Greetings, > > > > To best of my knowledge, nobody issued pg_ctl stop –m fast while > > we experienced PG was trying to shutdown unsuccessfully: > > > > *** Everything seems normal before this point *** > > Mar 3 21:07:55 myhost postgres[630]: [24] LOG: recycled transaction > log file 00001ABC0000006D > > Mar 3 21:08:57 myhost postgres[5158]: [1] LOG: fast shutdown request > > Mar 3 21:08:57 myhost postgres[5158]: [2] LOG: aborting any active > transactions > > Mar 3 21:08:57 myhost postgres[14292]: [1] FATAL: This connection > has been terminated by the administrator. > > *** A lot of “This connection has been terminated by the > administrator.” taken out here *** > > Mar 3 21:08:57 myhost postgres[15912]: [3] FATAL: The database > system is shutting down > > *** A lot the same message as last line till *** > > Mar 3 22:10:39 myhost postgres[1840]: [3] FATAL: The database system > is shutting down > > > > Then I used “–m immediate”: > > Mar 3 22:10:39 myhost postgres[5158]: [3] LOG: immediate shutdown > request > > Mar 3 22:11:07 myhost postgres[1918]: [1] LOG: database system was > interrupted at 2005-03-03 21:08:53 MST > > Mar 3 22:11:07 myhost postgres[1918]: [2] LOG: checkpoint record is > at 1ABC/929DFCB4 > > Mar 3 22:11:07 myhost postgres[1918]: [3] LOG: redo record is at > 1ABC/9044F3B4; undo record is at 0/0; shutdown FALSE > > Mar 3 22:11:07 myhost postgres[1918]: [4] LOG: next transaction id: > 1090597972; next oid: 4231750970 > > Mar 3 22:11:07 myhost postgres[1918]: [5] LOG: database system was > not properly shut down; automatic recovery in progress > > Mar 3 22:11:07 myhost postgres[1918]: [6] LOG: redo starts at > 1ABC/9044F3B4 > > Mar 3 22:11:07 myhost postgres[1919]: [1] FATAL: The database system > is starting up > > *** PG was up after a lot of the above message *** > > > > PG version is 7.3.2 on Red Hat Enterprise Linux ES release 3 (Taroon > Update 4) > > I know it is old, but anyone can smell why PG shutdown itself? This sounds like postgresql ran up against the Out Of Memory killer in the linux kernel, but I thought it killed things with -9, which would result in an immediate shutdown. Maybe a ulimit issue? Those are the two most common causes of postgresql premature shutdown.
"Lee Wu" <Lwu@mxlogic.com> writes: > Mar 3 21:08:57 myhost postgres[5158]: [1] LOG: fast shutdown request *Something* sent the postmaster a SIGINT. Look around and find out what might do that. regards, tom lane
Thanks, I checked the log and could not find anything suspicious. If there was one, I'd probably have not posted for help. Here is the section around "fast shutdown request": Mar 3 21:02:41 myhost postgres[1593]: [1] LOG: recycled transaction log file 00001ABC00000059 Mar 3 21:02:41 myhost postgres[1593]: [2] LOG: recycled transaction log file 00001ABC0000005A Mar 3 21:02:41 myhost postgres[1593]: [3] LOG: recycled transaction log file 00001ABC0000005B Mar 3 21:02:41 myhost postgres[1593]: [4] LOG: recycled transaction log file 00001ABC0000005C Mar 3 21:02:41 myhost postgres[1593]: [5] LOG: recycled transaction log file 00001ABC00000046 Mar 3 21:02:41 myhost postgres[1593]: [6] LOG: recycled transaction log file 00001ABC0000005D Mar 3 21:02:41 myhost postgres[1593]: [7] LOG: recycled transaction log file 00001ABC00000047 Mar 3 21:02:41 myhost postgres[1593]: [8] LOG: recycled transaction log file 00001ABC00000048 Mar 3 21:02:41 myhost postgres[1593]: [9] LOG: recycled transaction log file 00001ABC00000049 Mar 3 21:02:41 myhost postgres[1593]: [10] LOG: recycled transaction log file 00001ABC0000004A Mar 3 21:02:41 myhost postgres[1593]: [11] LOG: recycled transaction log file 00001ABC0000004B Mar 3 21:02:41 myhost postgres[1593]: [12] LOG: recycled transaction log file 00001ABC0000004C Mar 3 21:02:41 myhost postgres[1593]: [13] LOG: recycled transaction log file 00001ABC0000004D Mar 3 21:02:41 myhost postgres[1593]: [14] LOG: recycled transaction log file 00001ABC0000004E Mar 3 21:02:41 myhost postgres[1593]: [15] LOG: recycled transaction log file 00001ABC0000004F Mar 3 21:02:41 myhost postgres[1593]: [16] LOG: recycled transaction log file 00001ABC00000050 Mar 3 21:02:41 myhost postgres[1593]: [17] LOG: recycled transaction log file 00001ABC00000051 Mar 3 21:02:41 myhost postgres[1593]: [18] LOG: recycled transaction log file 00001ABC00000052 Mar 3 21:02:41 myhost postgres[1593]: [19] LOG: recycled transaction log file 00001ABC00000053 Mar 3 21:02:41 myhost postgres[1593]: [20] LOG: recycled transaction log file 00001ABC00000054 Mar 3 21:02:41 myhost postgres[1593]: [21] LOG: recycled transaction log file 00001ABC00000055 Mar 3 21:02:42 myhost postgres[1593]: [22] LOG: recycled transaction log file 00001ABC00000056 Mar 3 21:02:42 myhost postgres[1593]: [23] LOG: recycled transaction log file 00001ABC00000057 Mar 3 21:02:42 myhost postgres[1593]: [24] LOG: recycled transaction log file 00001ABC00000058 Mar 3 21:07:54 myhost postgres[630]: [1] LOG: recycled transaction log file 00001ABC0000006E Mar 3 21:07:54 myhost postgres[630]: [2] LOG: recycled transaction log file 00001ABC0000006F Mar 3 21:07:54 myhost postgres[630]: [3] LOG: recycled transaction log file 00001ABC00000070 Mar 3 21:07:54 myhost postgres[630]: [4] LOG: recycled transaction log file 00001ABC00000071 Mar 3 21:07:54 myhost postgres[630]: [5] LOG: recycled transaction log file 00001ABC00000072 Mar 3 21:07:54 myhost postgres[630]: [6] LOG: recycled transaction log file 00001ABC00000073 Mar 3 21:07:54 myhost postgres[630]: [7] LOG: recycled transaction log file 00001ABC00000074 Mar 3 21:07:54 myhost postgres[630]: [8] LOG: recycled transaction log file 00001ABC00000075 Mar 3 21:07:54 myhost postgres[630]: [9] LOG: recycled transaction log file 00001ABC0000005E Mar 3 21:07:54 myhost postgres[630]: [10] LOG: recycled transaction log file 00001ABC0000005F Mar 3 21:07:54 myhost postgres[630]: [11] LOG: recycled transaction log file 00001ABC00000060 Mar 3 21:07:54 myhost postgres[630]: [12] LOG: recycled transaction log file 00001ABC00000061 Mar 3 21:07:54 myhost postgres[630]: [13] LOG: recycled transaction log file 00001ABC00000062 Mar 3 21:07:55 myhost postgres[630]: [14] LOG: recycled transaction log file 00001ABC00000063 Mar 3 21:07:55 myhost postgres[630]: [15] LOG: recycled transaction log file 00001ABC00000064 Mar 3 21:07:55 myhost postgres[630]: [16] LOG: recycled transaction log file 00001ABC00000065 Mar 3 21:07:55 myhost postgres[630]: [17] LOG: recycled transaction log file 00001ABC00000066 Mar 3 21:07:55 myhost postgres[630]: [18] LOG: recycled transaction log file 00001ABC00000067 Mar 3 21:07:55 myhost postgres[630]: [19] LOG: recycled transaction log file 00001ABC00000068 Mar 3 21:07:55 myhost postgres[630]: [20] LOG: recycled transaction log file 00001ABC00000069 Mar 3 21:07:55 myhost postgres[630]: [21] LOG: recycled transaction log file 00001ABC0000006A Mar 3 21:07:55 myhost postgres[630]: [22] LOG: recycled transaction log file 00001ABC0000006B Mar 3 21:07:55 myhost postgres[630]: [23] LOG: recycled transaction log file 00001ABC0000006C Mar 3 21:07:55 myhost postgres[630]: [24] LOG: recycled transaction log file 00001ABC0000006D Mar 3 21:08:57 myhost postgres[5158]: [1] LOG: fast shutdown request Mar 3 21:08:57 myhost postgres[5158]: [2] LOG: aborting any active transactions Mar 3 21:08:57 myhost postgres[14292]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14269]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14143]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14111]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14245]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14283]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14098]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14090]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14225]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14156]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14122]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[15901]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14070]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14082]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14059]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14043]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13846]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14024]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13831]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14014]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13826]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[14006]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13823]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13988]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13972]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13960]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13886]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13872]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13818]: [1] FATAL: This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[13939]: [1] FATAL: copy: line 277, This connection has been terminated by the administrator. Mar 3 21:08:57 myhost postgres[15912]: [3] FATAL: The database system is shutting down Mar 3 21:08:58 myhost postgres[15913]: [3] FATAL: The database system is shutting down Mar 3 21:08:58 myhost postgres[15914]: [3] FATAL: The database system is shutting down Mar 3 21:08:58 myhost postgres[15915]: [3] FATAL: The database system is shutting down Mar 3 21:08:58 myhost postgres[15918]: [3] FATAL: The database system is shutting down Mar 3 21:08:58 myhost postgres[15919]: [3] FATAL: The database system is shutting down Mar 3 21:08:58 myhost postgres[13939]: [2-1] LOG: statement: COPY my_table (column1, column2, column3, column4, c5, c6, c6, c7, c8, c9, Mar 3 21:08:59 myhost postgres[15920]: [3] FATAL: The database system is shutting down Mar 3 21:08:59 myhost postgres[15928]: [3] FATAL: The database system is shutting down Mar 3 21:08:59 myhost postgres[15929]: [3] FATAL: The database system is shutting down Mar 3 21:08:59 myhost postgres[15930]: [3] FATAL: The database system is shutting down Mar 3 21:08:59 myhost postgres[15931]: [3] FATAL: The database system is shutting down Mar 3 21:08:59 myhost postgres[15932]: [3] FATAL: The database system is shutting down Mar 3 21:08:59 myhost postgres[13939]: [2-2] c10, c11, c12, c13, m_c14, c15) FROM stdin Mar 3 21:08:59 myhost postgres[15940]: [3] FATAL: The database system is shutting down Mar 3 21:08:59 myhost postgres[15950]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[15958]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[15966]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[15974]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[15982]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[15990]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[15998]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16006]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16014]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16022]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16023]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16033]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16041]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16049]: [3] FATAL: The database system is shutting down Mar 3 21:09:00 myhost postgres[16057]: [3] FATAL: The database system is shutting down Mar 3 21:09:01 myhost postgres[16065]: [3] FATAL: The database system is shutting down Mar 3 21:09:01 myhost postgres[16073]: [3] FATAL: The database system is shutting down Mar 3 21:09:01 myhost postgres[16081]: [3] FATAL: The database system is shutting down -----Original Message----- From: Tom Lane [mailto:tgl@sss.pgh.pa.us] Sent: Friday, March 04, 2005 11:22 AM To: Lee Wu Cc: pgsql-admin@postgresql.org Subject: Re: [ADMIN] PG shutdown itself? "Lee Wu" <Lwu@mxlogic.com> writes: > Mar 3 21:08:57 myhost postgres[5158]: [1] LOG: fast shutdown request *Something* sent the postmaster a SIGINT. Look around and find out what might do that. regards, tom lane
Thanks, I am positive no kill -9 issued. -bash-2.05b$ ulimit -all core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited file size (blocks, -f) unlimited max locked memory (kbytes, -l) 4 max memory size (kbytes, -m) unlimited open files (-n) 1024 pipe size (512 bytes, -p) 8 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 7168 virtual memory (kbytes, -v) unlimited -bash-2.05b$ id uid=1000(postgres) gid=1000(postgres) groups=1000(postgres) -----Original Message----- From: Scott Marlowe [mailto:smarlowe@g2switchworks.com] Sent: Friday, March 04, 2005 10:51 AM To: Lee Wu Cc: pgsql-admin@postgresql.org Subject: Re: [ADMIN] PG shutdown itself? On Fri, 2005-03-04 at 11:38, Lee Wu wrote: > Greetings, > > > > To best of my knowledge, nobody issued pg_ctl stop -m fast while > > we experienced PG was trying to shutdown unsuccessfully: > > > > *** Everything seems normal before this point *** > > Mar 3 21:07:55 myhost postgres[630]: [24] LOG: recycled transaction > log file 00001ABC0000006D > > Mar 3 21:08:57 myhost postgres[5158]: [1] LOG: fast shutdown request > > Mar 3 21:08:57 myhost postgres[5158]: [2] LOG: aborting any active > transactions > > Mar 3 21:08:57 myhost postgres[14292]: [1] FATAL: This connection > has been terminated by the administrator. > > *** A lot of "This connection has been terminated by the > administrator." taken out here *** > > Mar 3 21:08:57 myhost postgres[15912]: [3] FATAL: The database > system is shutting down > > *** A lot the same message as last line till *** > > Mar 3 22:10:39 myhost postgres[1840]: [3] FATAL: The database system > is shutting down > > > > Then I used "-m immediate": > > Mar 3 22:10:39 myhost postgres[5158]: [3] LOG: immediate shutdown > request > > Mar 3 22:11:07 myhost postgres[1918]: [1] LOG: database system was > interrupted at 2005-03-03 21:08:53 MST > > Mar 3 22:11:07 myhost postgres[1918]: [2] LOG: checkpoint record is > at 1ABC/929DFCB4 > > Mar 3 22:11:07 myhost postgres[1918]: [3] LOG: redo record is at > 1ABC/9044F3B4; undo record is at 0/0; shutdown FALSE > > Mar 3 22:11:07 myhost postgres[1918]: [4] LOG: next transaction id: > 1090597972; next oid: 4231750970 > > Mar 3 22:11:07 myhost postgres[1918]: [5] LOG: database system was > not properly shut down; automatic recovery in progress > > Mar 3 22:11:07 myhost postgres[1918]: [6] LOG: redo starts at > 1ABC/9044F3B4 > > Mar 3 22:11:07 myhost postgres[1919]: [1] FATAL: The database system > is starting up > > *** PG was up after a lot of the above message *** > > > > PG version is 7.3.2 on Red Hat Enterprise Linux ES release 3 (Taroon > Update 4) > > I know it is old, but anyone can smell why PG shutdown itself? This sounds like postgresql ran up against the Out Of Memory killer in the linux kernel, but I thought it killed things with -9, which would result in an immediate shutdown. Maybe a ulimit issue? Those are the two most common causes of postgresql premature shutdown.
"Lee Wu" <Lwu@mxlogic.com> writes: > I checked the log and could not find anything suspicious. You're looking in the wrong place: that signal did not come from any part of the Postgres software. You need to be thinking of outside agents, such as kernel-enforced resource limits. The kernel logs for that time might possibly reveal something. regards, tom lane
On Fri, 2005-03-04 at 12:39, Lee Wu wrote: > Thanks, > > I checked the log and could not find anything suspicious. If there was > one, > I'd probably have not posted for help. Does your system have a dmesg command or something like it to give you the tail of the system logs?