Thread: postgre restarts in short period

Hi,

Our client has began to complain for a few days that the application can
not connect to the database more times.
I looked into the logs and as far as I can see, postgresql restarts more
times a day. I made a vacuum (full, freeze, analyze) on the database and
reindexed everything, but it looks, nothing has changed.

Server data:
Windows Standard Server 2007 SP2 64 bit
Intel Xeon 3GHz
4MB ram

Postgresql 8.2 32 bit

The application is writen in php.


I paste here the logs for one day:

postgresql-2013-08-05_044313.log:
2013-08-05 04:43:13 FATAL:  the database system is starting up
2013-08-05 04:43:13 LOG:  database system was interrupted at 2013-08-04
21:17:08
2013-08-05 04:43:13 LOG:  checkpoint record is at A/C07BA3D0
2013-08-05 04:43:13 LOG:  redo record is at A/C07BA3D0; undo record is
at 0/0; shutdown TRUE
2013-08-05 04:43:13 LOG:  next transaction ID: 0/86886248; next OID:
28623177
2013-08-05 04:43:13 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 04:43:13 LOG:  database system was not properly shut down;
automatic recovery in progress
2013-08-05 04:43:14 LOG:  record with zero length at A/C07BA420
2013-08-05 04:43:14 LOG:  redo is not required
2013-08-05 04:43:14 FATAL:  the database system is starting up
2013-08-05 04:43:14 LOG:  database system is ready
2013-08-05 04:43:24 LOG:  could not receive data from client: Unknown
winsock error 10061
2013-08-05 04:43:24 LOG:  unexpected EOF on client connection

postgresql-2013-08-05_063316.log:
2013-08-05 06:33:17 FATAL:  the database system is starting up
2013-08-05 06:33:17 LOG:  database system was interrupted at 2013-08-05
04:43:14
2013-08-05 06:33:17 LOG:  checkpoint record is at A/C07BA420
2013-08-05 06:33:17 LOG:  redo record is at A/C07BA420; undo record is
at 0/0; shutdown TRUE
2013-08-05 06:33:17 LOG:  next transaction ID: 0/86886248; next OID:
28623177
2013-08-05 06:33:17 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 06:33:17 LOG:  database system was not properly shut down;
automatic recovery in progress
2013-08-05 06:33:17 LOG:  record with zero length at A/C07BA470
2013-08-05 06:33:17 LOG:  redo is not required
2013-08-05 06:33:18 FATAL:  the database system is starting up
2013-08-05 06:33:18 LOG:  database system is ready
2013-08-05 06:33:19 FATAL:  the database system is starting up

postgresql-2013-08-05_084852.log:
2013-08-05 08:48:53 LOG:  database system was interrupted at 2013-08-05
08:43:19
2013-08-05 08:48:53 FATAL:  the database system is starting up
2013-08-05 08:48:53 LOG:  checkpoint record is at A/C0940F58
2013-08-05 08:48:53 LOG:  redo record is at A/C0940F58; undo record is
at 0/0; shutdown FALSE
2013-08-05 08:48:53 LOG:  next transaction ID: 0/86889158; next OID:
28631369
2013-08-05 08:48:53 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 08:48:53 LOG:  database system was not properly shut down;
automatic recovery in progress
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:54 LOG:  redo starts at A/C0940FA8
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:55 FATAL:  the database system is starting up
2013-08-05 08:48:56 FATAL:  the database system is starting up
2013-08-05 08:48:57 FATAL:  the database system is starting up
2013-08-05 08:48:59 FATAL:  the database system is starting up
2013-08-05 08:49:00 FATAL:  the database system is starting up
2013-08-05 08:49:01 FATAL:  the database system is starting up
2013-08-05 08:49:02 FATAL:  the database system is starting up
2013-08-05 08:49:03 FATAL:  the database system is starting up
2013-08-05 08:49:04 FATAL:  the database system is starting up
2013-08-05 08:49:05 FATAL:  the database system is starting up
2013-08-05 08:49:06 FATAL:  the database system is starting up
2013-08-05 08:49:07 FATAL:  the database system is starting up
2013-08-05 08:49:08 FATAL:  the database system is starting up
2013-08-05 08:49:09 FATAL:  the database system is starting up
2013-08-05 08:49:11 FATAL:  the database system is starting up
2013-08-05 08:49:11 LOG:  record with zero length at A/C096B8B0
2013-08-05 08:49:11 LOG:  redo done at A/C096B880
2013-08-05 08:49:12 FATAL:  the database system is starting up
2013-08-05 08:49:13 FATAL:  the database system is starting up
2013-08-05 08:49:14 FATAL:  the database system is starting up
2013-08-05 08:49:15 FATAL:  the database system is starting up
2013-08-05 08:49:16 FATAL:  the database system is starting up
2013-08-05 08:49:16 LOG:  database system is ready
2013-08-05 08:49:18 FATAL:  the database system is starting up
2013-08-05 10:18:01 ERROR:  syntax error at or near "and" at character 195
2013-08-05 10:18:01 STATEMENT:  select distinct count(*) as rownum from
minta as m  join partner as p on ( m.partnerid = p.partnerid )  join
mintajelleg as mj on ( mj.mintajellegid = m.mintajellegid )   where
m.status IN   and m.mintajellegid =   and m.partnerid =

postgresql-2013-08-05_155425.log:
2013-08-05 15:54:26 FATAL:  the database system is starting up
2013-08-05 15:54:26 LOG:  database system was interrupted at 2013-08-05
15:49:18
2013-08-05 15:54:26 LOG:  checkpoint record is at A/C352B138
2013-08-05 15:54:26 LOG:  redo record is at A/C352B138; undo record is
at 0/0; shutdown FALSE
2013-08-05 15:54:26 LOG:  next transaction ID: 0/86971106; next OID:
28647753
2013-08-05 15:54:26 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 15:54:26 LOG:  database system was not properly shut down;
automatic recovery in progress
2013-08-05 15:54:27 LOG:  redo starts at A/C352B188
2013-08-05 15:54:27 FATAL:  the database system is starting up
2013-08-05 15:54:28 LOG:  record with zero length at A/C3538F90
2013-08-05 15:54:28 LOG:  redo done at A/C3538F60
2013-08-05 15:54:28 FATAL:  the database system is starting up
2013-08-05 15:54:29 FATAL:  the database system is starting up
2013-08-05 15:54:30 LOG:  database system is ready
2013-08-05 15:54:30 FATAL:  the database system is starting up
2013-08-05 15:54:38 LOG:  unexpected EOF on client connection

I hope somebody has an idea how I can correct it.
Thanks for the help!

fenor

On 08/06/2013 06:56 AM, edlef wrote:
> Hi,
>
> Our client has began to complain for a few days that the application can
> not connect to the database more times.
> I looked into the logs and as far as I can see, postgresql restarts more
> times a day. I made a vacuum (full, freeze, analyze) on the database and
> reindexed everything, but it looks, nothing has changed.
>
> Server data:
> Windows Standard Server 2007 SP2 64 bit
> Intel Xeon 3GHz
> 4MB ram
>
> Postgresql 8.2 32 bit
>
> The application is writen in php.
>
>

>
> I hope somebody has an idea how I can correct it.
> Thanks for the help!

Best guess there is an external program causing problems. The timestamps
are interesting and somewhat regular:

database system was interrupted at 2013-08-04 21:17:08
                                                         ~7 hrs
database system was interrupted at 2013-08-05 04:43:14
                                                          4 hrs
database system was interrupted at 2013-08-05 08:43:19
                                                         ~7 hrs
database system was interrupted at 2013-08-05 15:49:18


Given that this is Windows have you investigated the possibility of
interference from Anti-virus software.

>
> fenor
>
>
>


--
Adrian Klaver
adrian.klaver@gmail.com

well, in your statement, the parameters are missing.

2013-08-05 10:18:01 STATEMENT:  select distinct count(*) as rownum from  minta as m  join partner as p on ( m.partnerid = p.partnerid )  join mintajelleg as mj on ( mj.mintajellegid = m.mintajellegid )   where   m.status IN   and m.mintajellegid =   and m.partnerid =

there should be 'm.mintajellegid = ???? and m.partnerid = ????'

but this should not be the cause of the rather heavy database system crash

On Tue, Aug 6, 2013 at 3:56 PM, edlef <edlef@freemail.hu> wrote:

Hi,

Our client has began to complain for a few days that the application can not connect to the database more times.
I looked into the logs and as far as I can see, postgresql restarts more times a day. I made a vacuum (full, freeze, analyze) on the database and reindexed everything, but it looks, nothing has changed.

Server data:
Windows Standard Server 2007 SP2 64 bit
Intel Xeon 3GHz
4MB ram

Postgresql 8.2 32 bit

The application is writen in php.


I paste here the logs for one day:

postgresql-2013-08-05_044313.log:
2013-08-05 04:43:13 FATAL:  the database system is starting up
2013-08-05 04:43:13 LOG:  database system was interrupted at 2013-08-04 21:17:08
2013-08-05 04:43:13 LOG:  checkpoint record is at A/C07BA3D0
2013-08-05 04:43:13 LOG:  redo record is at A/C07BA3D0; undo record is at 0/0; shutdown TRUE
2013-08-05 04:43:13 LOG:  next transaction ID: 0/86886248; next OID: 28623177
2013-08-05 04:43:13 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 04:43:13 LOG:  database system was not properly shut down; automatic recovery in progress
2013-08-05 04:43:14 LOG:  record with zero length at A/C07BA420
2013-08-05 04:43:14 LOG:  redo is not required
2013-08-05 04:43:14 FATAL:  the database system is starting up
2013-08-05 04:43:14 LOG:  database system is ready
2013-08-05 04:43:24 LOG:  could not receive data from client: Unknown winsock error 10061
2013-08-05 04:43:24 LOG:  unexpected EOF on client connection

postgresql-2013-08-05_063316.log:
2013-08-05 06:33:17 FATAL:  the database system is starting up
2013-08-05 06:33:17 LOG:  database system was interrupted at 2013-08-05 04:43:14
2013-08-05 06:33:17 LOG:  checkpoint record is at A/C07BA420
2013-08-05 06:33:17 LOG:  redo record is at A/C07BA420; undo record is at 0/0; shutdown TRUE
2013-08-05 06:33:17 LOG:  next transaction ID: 0/86886248; next OID: 28623177
2013-08-05 06:33:17 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 06:33:17 LOG:  database system was not properly shut down; automatic recovery in progress
2013-08-05 06:33:17 LOG:  record with zero length at A/C07BA470
2013-08-05 06:33:17 LOG:  redo is not required
2013-08-05 06:33:18 FATAL:  the database system is starting up
2013-08-05 06:33:18 LOG:  database system is ready
2013-08-05 06:33:19 FATAL:  the database system is starting up

postgresql-2013-08-05_084852.log:
2013-08-05 08:48:53 LOG:  database system was interrupted at 2013-08-05 08:43:19
2013-08-05 08:48:53 FATAL:  the database system is starting up
2013-08-05 08:48:53 LOG:  checkpoint record is at A/C0940F58
2013-08-05 08:48:53 LOG:  redo record is at A/C0940F58; undo record is at 0/0; shutdown FALSE
2013-08-05 08:48:53 LOG:  next transaction ID: 0/86889158; next OID: 28631369
2013-08-05 08:48:53 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 08:48:53 LOG:  database system was not properly shut down; automatic recovery in progress
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:54 LOG:  redo starts at A/C0940FA8
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:54 FATAL:  the database system is starting up
2013-08-05 08:48:55 FATAL:  the database system is starting up
2013-08-05 08:48:56 FATAL:  the database system is starting up
2013-08-05 08:48:57 FATAL:  the database system is starting up
2013-08-05 08:48:59 FATAL:  the database system is starting up
2013-08-05 08:49:00 FATAL:  the database system is starting up
2013-08-05 08:49:01 FATAL:  the database system is starting up
2013-08-05 08:49:02 FATAL:  the database system is starting up
2013-08-05 08:49:03 FATAL:  the database system is starting up
2013-08-05 08:49:04 FATAL:  the database system is starting up
2013-08-05 08:49:05 FATAL:  the database system is starting up
2013-08-05 08:49:06 FATAL:  the database system is starting up
2013-08-05 08:49:07 FATAL:  the database system is starting up
2013-08-05 08:49:08 FATAL:  the database system is starting up
2013-08-05 08:49:09 FATAL:  the database system is starting up
2013-08-05 08:49:11 FATAL:  the database system is starting up
2013-08-05 08:49:11 LOG:  record with zero length at A/C096B8B0
2013-08-05 08:49:11 LOG:  redo done at A/C096B880
2013-08-05 08:49:12 FATAL:  the database system is starting up
2013-08-05 08:49:13 FATAL:  the database system is starting up
2013-08-05 08:49:14 FATAL:  the database system is starting up
2013-08-05 08:49:15 FATAL:  the database system is starting up
2013-08-05 08:49:16 FATAL:  the database system is starting up
2013-08-05 08:49:16 LOG:  database system is ready
2013-08-05 08:49:18 FATAL:  the database system is starting up
2013-08-05 10:18:01 ERROR:  syntax error at or near "and" at character 195
2013-08-05 10:18:01 STATEMENT:  select distinct count(*) as rownum from  minta as m  join partner as p on ( m.partnerid = p.partnerid )  join mintajelleg as mj on ( mj.mintajellegid = m.mintajellegid )   where   m.status IN   and m.mintajellegid =   and m.partnerid =

postgresql-2013-08-05_155425.log:
2013-08-05 15:54:26 FATAL:  the database system is starting up
2013-08-05 15:54:26 LOG:  database system was interrupted at 2013-08-05 15:49:18
2013-08-05 15:54:26 LOG:  checkpoint record is at A/C352B138
2013-08-05 15:54:26 LOG:  redo record is at A/C352B138; undo record is at 0/0; shutdown FALSE
2013-08-05 15:54:26 LOG:  next transaction ID: 0/86971106; next OID: 28647753
2013-08-05 15:54:26 LOG:  next MultiXactId: 88; next MultiXactOffset: 175
2013-08-05 15:54:26 LOG:  database system was not properly shut down; automatic recovery in progress
2013-08-05 15:54:27 LOG:  redo starts at A/C352B188
2013-08-05 15:54:27 FATAL:  the database system is starting up
2013-08-05 15:54:28 LOG:  record with zero length at A/C3538F90
2013-08-05 15:54:28 LOG:  redo done at A/C3538F60
2013-08-05 15:54:28 FATAL:  the database system is starting up
2013-08-05 15:54:29 FATAL:  the database system is starting up
2013-08-05 15:54:30 LOG:  database system is ready
2013-08-05 15:54:30 FATAL:  the database system is starting up
2013-08-05 15:54:38 LOG:  unexpected EOF on client connection

I hope somebody has an idea how I can correct it.
Thanks for the help!

fenor



--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

On 08/06/2013 06:56 AM, edlef wrote:
> Hi,
>
> Our client has began to complain for a few days that the application can
> not connect to the database more times.
> I looked into the logs and as far as I can see, postgresql restarts more
> times a day. I made a vacuum (full, freeze, analyze) on the database and
> reindexed everything, but it looks, nothing has changed.
>
> Server data:
> Windows Standard Server 2007 SP2 64 bit
> Intel Xeon 3GHz
> 4MB ram
>
> Postgresql 8.2 32 bit
>
> The application is writen in php.
>
>

>
> I hope somebody has an idea how I can correct it.
> Thanks for the help!

In addition to my previous comments, it would be nice to see the tail
end of the logs previous to the ones shown. In other words those logs
that show the database shutting down or at least what was happening just
before it shut down.

>
> fenor
>
>
>


--
Adrian Klaver
adrian.klaver@gmail.com

On Tue, Aug 6, 2013 at 7:56 AM, edlef <edlef@freemail.hu> wrote:
> Hi,
>
> Our client has began to complain for a few days that the application can not
> connect to the database more times.
> I looked into the logs and as far as I can see, postgresql restarts more
> times a day. I made a vacuum (full, freeze, analyze) on the database and
> reindexed everything, but it looks, nothing has changed.
>
> Server data:
> Windows Standard Server 2007 SP2 64 bit
> Intel Xeon 3GHz
> 4MB ram
>
> Postgresql 8.2 32 bit
>
> The application is writen in php.
>
>
> I paste here the logs for one day:
>
> postgresql-2013-08-05_044313.log:
> 2013-08-05 04:43:13 FATAL:  the database system is starting up
> 2013-08-05 04:43:13 LOG:  database system was interrupted at 2013-08-04
> 21:17:08
> 2013-08-05 04:43:13 LOG:  checkpoint record is at A/C07BA3D0
> 2013-08-05 04:43:13 LOG:  redo record is at A/C07BA3D0; undo record is at

SNIP

> I hope somebody has an idea how I can correct it.
> Thanks for the help!

We need to see what happens BEFORE the database was starting back up.
I.e. what caused it to shut down / restart / crash etc. The fact that
it's starting back up after a crash doesn't tell us much.

Hi,

I looked into other log files, but there is no regularity. I found
intervals when it restarted 2-3 time in a hour.
What I pasted was a full days log entrys, they were not snipets. There
are no entries about the shot down.
I try to find when it all began.

fenor

2013.08.06. 16:32 keltezéssel, Adrian Klaver írta:
> On 08/06/2013 06:56 AM, edlef wrote:
>> Hi,
>>
>> Our client has began to complain for a few days that the application can
>> not connect to the database more times.
>> I looked into the logs and as far as I can see, postgresql restarts more
>> times a day. I made a vacuum (full, freeze, analyze) on the database and
>> reindexed everything, but it looks, nothing has changed.
>>
>> Server data:
>> Windows Standard Server 2007 SP2 64 bit
>> Intel Xeon 3GHz
>> 4MB ram
>>
>> Postgresql 8.2 32 bit
>>
>> The application is writen in php.
>>
>>
>
>>
>> I hope somebody has an idea how I can correct it.
>> Thanks for the help!
>
> In addition to my previous comments, it would be nice to see the tail
> end of the logs previous to the ones shown. In other words those logs
> that show the database shutting down or at least what was happening
> just before it shut down.
>
>>
>> fenor
>>
>>
>>
>
>

On Tue, Aug 6, 2013 at 8:45 AM, edlef <edlef@freemail.hu> wrote:
> Hi,
>
> I looked into other log files, but there is no regularity. I found intervals
> when it restarted 2-3 time in a hour.
> What I pasted was a full days log entrys, they were not snipets. There are
> no entries about the shot down.
> I try to find when it all began.

OK then you're gonna need to trawl through system level logs for
anything you can find. Without and hints on why pg is crashing /
shutting down we've got nowhere to go.

On 08/06/2013 07:45 AM, edlef wrote:
> Hi,
>
> I looked into other log files, but there is no regularity. I found
> intervals when it restarted 2-3 time in a hour.
> What I pasted was a full days log entrys, they were not snipets. There
> are no entries about the shot down.
> I try to find when it all began.

Well for instance, the first log you show is:

postgresql-2013-08-05_044313.log

What would be interesting are the last entries in the log file before
the above.

>
> fenor



--
Adrian Klaver
adrian.klaver@gmail.com