Re: SIGUSR1 pingpong between master na autovacum launcher causes crash

Tom Lane píše v pá 21. 08. 2009 v 18:06 -0400:

> Maybe, but I think we need to understand exactly what happened first.

I try to mine more data from the system to reconstruct what happen.
Unfortunately, default postgresql log configuration does not have
timestamp. The postgresql had no load, system was under load which could
cause some slow system response. ... and ... bingo I'm able to reproduce
it.

I will look on it deeply with dtrace on Monday (I'm leaving now for a
weekend).

There are most important records from yesterdays issues.
Messages:
---------
Aug 20 11:14:54 genunix: [ID 470503 kern.warning] WARNING: Sorry, no swap space to grow stack for pid 507 (postgres)

svc log:
--------
[ Aug 20 10:53:27 Stopping because service disabled. ]
[ Aug 20 10:53:27 Executing stop method ("/lib/svc/method/postgres_84 stop"). ]
waiting for server to shut down..... done
server stopped
[ Aug 20 10:53:31 Method "stop" exited with status 0. ]
[ Aug 20 10:54:17 Executing start method ("/lib/svc/method/postgres_84 start"). ]
server starting
[ Aug 20 10:54:19 Method "start" exited with status 0. ]
[ Aug 20 11:14:58 Stopping because process dumped core. ]
[ Aug 20 11:16:05 Executing stop method ("/lib/svc/method/postgres_84 stop"). ]
pg_ctl: could not send stop signal (PID: 507): No such process
[ Aug 20 11:16:12 Method "stop" exited with status 0. ]
[ Aug 20 11:17:17 Executing start method ("/lib/svc/method/postgres_84 start"). ]
ld.so.1: sh: fatal: mmap anon failed: Resource temporarily unavailable
[ Aug 20 11:17:28 Method "start" failed due to signal KILL. ]
[ Aug 20 11:18:39 Executing start method ("/lib/svc/method/postgres_84 start"). ]
ld.so.1: sh: fatal: mmap anon failed: Resource temporarily unavailable
[ Aug 20 11:18:50 Method "start" failed due to signal KILL. ]
[ Aug 20 11:19:58 Executing start method ("/lib/svc/method/postgres_84 start"). ]
ld.so.1: sh: fatal: mmap anon failed: Resource temporarily unavailable

postgresql.log:
---------------
LOG: received smart shutdown request
LOG: autovacuum launcher shutting down
LOG: shutting down
LOG: database system is shut down
LOG: database system was shut down at 2009-08-20 10:53:30 CEST
LOG: database system is ready to accept connections
LOG: autovacuum launcher started
LOG: could not fork autovacuum worker process: Not enough space
...
TopMemoryContext: 31192 total in 4 blocks; 6056 free (4 chunks); 25136 used
TopTransactionContext: 8192 total in 1 blocks; 7792 free (1 chunks); 400 used
TransactionAbortContext: 32768 total in 1 blocks; 32752 free (0 chunks); 16 used
Portal hash: 8192 total in 1 blocks; 3912 free (0 chunks); 4280 used
PortalMemory: 0 total in 0 blocks; 0 free (0 chunks); 0 used
Relcache by OID: 8192 total in 1 blocks; 4936 free (0 chunks); 3256 used
CacheMemoryContext: 274480 total in 18 blocks; 17072 free (2 chunks); 257408 used
<snip rest of memory context dump>
ERROR: out of memory
DETAIL: Failed on request of size 8.
LOG: could not fork autovacuum worker process: Not enough space
...
LOG: could not fork autovacuum worker process: Not enough space
WARNING: worker took too long to start; cancelled
LOG: could not fork autovacuum worker process: Not enough space
...
LOG: could not fork autovacuum worker process: Not enough space
WARNING: worker took too long to start; cancelled
2009-08-21 13:30:48.701 CEST 416 LOG: database system was interrupted; last known up at 2009-08-20 10:54:21 CEST
2009-08-21 13:30:48.963 CEST 416 LOG: database system was not properly shut down; automatic recovery in progress