Re: System in Recovery Mode

On Mon, Feb 25, 2008 at 9:42 AM, Simon Riggs <simon@2ndquadrant.com> wrote:

On Mon, 2008-02-25 at 08:11 -0600, Aaron Bono wrote:

> Our database was going along just fine this morning when, out of the
> blue, we started getting the following errors:
>
> FATAL:  the database system is in recovery mode
>
> We are using PostgreSQL 8.1.3 on CentOS.  I was the only person on the
> machine and had recently started a small batch that had just finished
> querying and updating the database.  This batch runs constantly and
> has not been changed in months.

Your database has crashed and is recovering. You should look at the
server log to find out when and why this happened, then either correct
the problem or report the bug.

Here is what I am seeing:

<2008-02-25 07:15:24 CST username 127.0.0.1>ERROR:  unrecognized node type: 4260493
<2008-02-25 07:15:25 CST [unknown] >LOG:  connection received: host=127.0.0.1 port=51295
<2008-02-25 07:15:25 CST username 127.0.0.1>LOG:  connection authorized: user=username database=my_db
<2008-02-25 07:15:25 CST username 127.0.0.1>LOG:  disconnection: session time: 0:00:00.04 user=username database=my_db host=127.0.0.1 port=51295
<2008-02-25 07:15:25 CST [unknown] >LOG:  connection received: host=127.0.0.1 port=51296
<2008-02-25 07:15:25 CST username 127.0.0.1>LOG:  connection authorized: user=username database=clockwork_db_prod
<2008-02-25 07:15:38 CST username 127.0.0.1>ERROR:  unrecognized node type: 4260493
<2008-02-25 07:15:49 CST  >LOG:  server process (PID 10876) was terminated by signal 11
<2008-02-25 07:15:49 CST  >LOG:  terminating any other active server processes
<2008-02-25 07:15:49 CST username 127.0.0.1>WARNING:  terminating connection because of crash of another server process
<2008-02-25 07:15:49 CST username 127.0.0.1>DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
<2008-02-25 07:15:49 CST username 127.0.0.1>HINT:  In a moment you should be able to reconnect to the database and repeat your command.
<2008-02-25 07:15:49 CST username 127.0.0.1>WARNING:  terminating connection because of crash of another server process

and it continues like this as it terminated all connections followed by:

<2008-02-25 07:15:49 CST username 127.0.0.1>CONTEXT:  PL/pgSQL function "get_branch_for_zip" line 61 at fetch
<2008-02-25 07:15:50 CST  >LOG:  all server processes terminated; reinitializing
<2008-02-25 07:15:50 CST  >LOG:  database system was interrupted at 2008-02-25 07:11:10 CST
<2008-02-25 07:15:50 CST  >LOG:  checkpoint record is at 14/9F015F54
<2008-02-25 07:15:50 CST  >LOG:  redo record is at 14/9F015F54; undo record is at 0/0; shutdown FALSE
<2008-02-25 07:15:50 CST  >LOG:  next transaction ID: 911288200; next OID: 90133045
<2008-02-25 07:15:50 CST  >LOG:  next MultiXactId: 27095; next MultiXactOffset: 66130
<2008-02-25 07:15:50 CST  >LOG:  database system was not properly shut down; automatic recovery in progress
<2008-02-25 07:15:50 CST  >LOG:  redo starts at 14/9F015F98
<2008-02-25 07:15:50 CST  >LOG:  record with zero length at 14/9F08C23C
<2008-02-25 07:15:50 CST  >LOG:  redo done at 14/9F08C214
<2008-02-25 07:15:50 CST  >LOG:  could not truncate directory "pg_multixact/members": apparent wraparound
<2008-02-25 07:15:50 CST  >LOG:  database system is ready
<2008-02-25 07:15:50 CST  >LOG:  transaction ID wrap limit is 1576224515, limited by database "another_db"
<2008-02-25 07:15:56 CST [unknown] >LOG:  connection received: host=127.0.0.1 port=51987
<2008-02-25 07:15:56 CST username 127.0.0.1>LOG:  connection authorized: user=onehour database=my_db
<2008-02-25 07:15:56 CST  >LOG:  server process (PID 14433) was terminated by signal 11
<2008-02-25 07:15:56 CST  >LOG:  terminating any other active server processes
<2008-02-25 07:15:56 CST  >LOG:  all server processes terminated; reinitializing
<2008-02-25 07:15:56 CST  >LOG:  database system was interrupted at 2008-02-25 07:15:50 CST
<2008-02-25 07:15:56 CST  >LOG:  checkpoint record is at 14/9F08C23C
<2008-02-25 07:15:56 CST  >LOG:  redo record is at 14/9F08C23C; undo record is at 0/0; shutdown TRUE
<2008-02-25 07:15:56 CST  >LOG:  next transaction ID: 911293548; next OID: 90133045
<2008-02-25 07:15:56 CST  >LOG:  next MultiXactId: 27095; next MultiXactOffset: 66130
<2008-02-25 07:15:56 CST  >LOG:  database system was not properly shut down; automatic recovery in progress
<2008-02-25 07:15:56 CST  >LOG:  record with zero length at 14/9F08C280
<2008-02-25 07:15:56 CST  >LOG:  redo is not required
<2008-02-25 07:15:56 CST  >LOG:  could not truncate directory "pg_multixact/members": apparent wraparound
<2008-02-25 07:15:56 CST  >LOG:  database system is ready
<2008-02-25 07:15:56 CST  >LOG:  transaction ID wrap limit is 1576224515, limited by database "another_db"

and it then continues with this.