Обсуждение: 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?