BUG #8392: encounter intermittent "ERROR: out of memory" on hot standby

From: pchan(at)contigo(dot)com
To: pgsql-bugs(at)postgresql(dot)org
Subject: BUG #8392: encounter intermittent "ERROR: out of memory" on hot standby
Date: 2013-08-22 23:52:15
Message-ID: E1VCefn-0002sq-1z@wrigleys.postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

The following bug has been logged on the website:

Bug reference: 8392
Logged by: Pius Chan
Email address: pchan(at)contigo(dot)com
PostgreSQL version: 9.1.9
Operating system: Linux version 2.6.32-279.14.1.el6.x86_64
Description:

In the hot standby server, we generate daily batch reports starting at 00:15
and usually it takes about 30 minutes to finish. The report server call
stored functions in database to get the data and then format the data into
pdf or word files. Intermittently batch generation process fails due to DB
ERROR: out of memory. In the database log, over 10,000 lines of memory dump
are recorded:

2013-08-21 01:04:00 PDT [DB1] [postgres] [32427]: [6286-1] 192.168.6.122
LOG: duration: 0.034 ms bind S_1: BEGIN
2013-08-21 01:04:00 PDT [DB1] [postgres] [32427]: [6287-1] 192.168.6.122
LOG: duration: 0.015 ms execute S_1: BEGIN
2013-08-21 01:04:00 PDT [DB1] [postgres] [32427]: [6288-1] 192.168.6.122
LOG: duration: 0.100 ms parse <unnamed>: select now()
2013-08-21 01:04:00 PDT [DB1] [postgres] [32427]: [6289-1] 192.168.6.122
LOG: duration: 0.029 ms bind <unnamed>: select now()
2013-08-21 01:04:00 PDT [DB1] [postgres] [32427]: [6290-1] 192.168.6.122
LOG: duration: 0.015 ms execute <unnamed>: select now()

-------------------------------------------- memory dump (14572 lines)
--------------------------------------------

TopMemoryContext: 2797744 total in 319 blocks; 331248 free (1432 chunks);
2466496 used
TopTransactionContext: 8192 total in 1 blocks; 7184 free (0 chunks); 1008
used
PL/pgSQL function context: 122880 total in 4 blocks; 25640 free (3
chunks); 97240 used
Record information cache: 24576 total in 2 blocks; 15984 free (5 chunks);
8592 used
PL/pgSQL function context: 24576 total in 2 blocks; 15976 free (2 chunks);
8600 used
PL/pgSQL function context: 57344 total in 3 blocks; 13528 free (3 chunks);
43816 used
PL/pgSQL function context: 57344 total in 3 blocks; 23792 free (4 chunks);
33552 used
PL/pgSQL function context: 122880 total in 4 blocks; 64008 free (4
chunks); 58872 used
PL/pgSQL function context: 57344 total in 3 blocks; 12264 free (2 chunks);
45080 used
PL/pgSQL function context: 57344 total in 3 blocks; 23520 free (4 chunks);
33824 used
PL/pgSQL function context: 57344 total in 3 blocks; 27176 free (3 chunks);
30168 used
PL/pgSQL function context: 57344 total in 3 blocks; 40928 free (5 chunks);
16416 used
PL/pgSQL function context: 57344 total in 3 blocks; 31304 free (4 chunks);
26040 used
PL/pgSQL function context: 24576 total in 2 blocks; 17544 free (2 chunks);
7032 used
PL/pgSQL function context: 24576 total in 2 blocks; 9608 free (2 chunks);
14968 used
PL/pgSQL function context: 253952 total in 5 blocks; 133088 free (4
chunks); 120864 used
CFuncHash: 8192 total in 1 blocks; 1680 free (0 chunks); 6512 used
Rendezvous variable hash: 8192 total in 1 blocks; 1680 free (0 chunks);
6512 used

:
:
:

pg_authid_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks); 1352
used
pg_auth_members_member_role_index: 3072 total in 2 blocks; 1704 free (4
chunks); 1368 used
pg_tablespace_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);
1352 used
pg_database_datname_index: 3072 total in 2 blocks; 1720 free (3 chunks);
1352 used
pg_auth_members_role_member_index: 3072 total in 2 blocks; 1704 free (4
chunks); 1368 used
pg_database_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);
1352 used
pg_authid_rolname_index: 3072 total in 2 blocks; 1720 free (3 chunks);
1352 used
MdSmgr: 253952 total in 5 blocks; 86080 free (0 chunks); 167872 used
LOCALLOCK hash: 516096 total in 6 blocks; 124832 free (20 chunks); 391264
used
Timezones: 83472 total in 2 blocks; 3744 free (0 chunks); 79728 used
ErrorContext: 532528 total in 2 blocks; 8048 free (2 chunks); 524480 used

----------------------------------------------------------------------------------------------------------------------------------------------------------------------------

2013-08-21 01:05:20 PDT [DB1] [postgres] [32427]: [6297-1] 192.168.6.122
ERROR: out of memory
2013-08-21 01:05:20 PDT [DB1] [postgres] [32427]: [6298-1] 192.168.6.122
DETAIL: Failed on request of size 1048576.
2013-08-21 01:05:20 PDT [DB1] [postgres] [32427]: [6299-1] 192.168.6.122
LOG: duration: 0.028 ms bind S_2: COMMIT
2013-08-21 01:05:20 PDT [DB1] [postgres] [32427]: [6300-1] 192.168.6.122
LOG: duration: 0.045 ms execute S_2: COMMIT

Not sure if this is related to bug #8279 as mentioned in this:

http://www.postgresql.org/message-id/24295.1373050026@sss.pgh.pa.us

Anyway to tell what went wrong from the memory dump?

Thanks a lot,

Pius

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message ダンミンフーン 2013-08-23 00:56:30 Re: After promote, DB can not UPDATE with SAVEPOINT (could not access status of transaction 1409172)
Previous Message Andres Freund 2013-08-22 13:30:35 Re: After promote, DB can not UPDATE with SAVEPOINT (could not access status of transaction 1409172)