A simple update query, over roughly 17 million rows, populating a newly added
column in a table, resulted in an out of memory error when the process memory
usage reached 2GB. Could this be due to a poor choice of some configuration
parameter, or is there a limit on how many rows I can update in a single
statement?
Log:
...
2008-01-25 09:42:08.119 NZDT [3432]: [1-1] LOG: checkpoint starting: time
2008-01-25 09:42:08.697 NZDT [3432]: [2-1] LOG: checkpoint complete: wrote 2
buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled;
write=0.218 s, sync=0.047 s, total=0.578 s
...
2008-01-25 10:44:49.011 NZDT [3824]: [1-1] LOG: connection received:
host=(removed) port=3207
2008-01-25 10:44:49.042 NZDT [3824]: [2-1] LOG: connection authorized:
user=postgres database=(removed)
2008-01-25 10:52:08.204 NZDT [3432]: [3-1] LOG: checkpoint starting: time
2008-01-25 10:52:39.673 NZDT [3432]: [4-1] LOG: checkpoint complete: wrote 275
buffers (6.7%); 1 transaction log file(s) added, 0 removed, 0 recycled;
write=27.078 s, sync=1.485 s, total=31.407 s
2008-01-25 11:02:08.055 NZDT [3432]: [5-1] LOG: checkpoint starting: time
2008-01-25 11:02:32.759 NZDT [3432]: [6-1] LOG: checkpoint complete: wrote 222
buffers (5.4%); 0 transaction log file(s) added, 0 removed, 69 recycled;
write=22.766 s, sync=0.968 s, total=24.704 s
2008-01-25 11:12:08.344 NZDT [3432]: [7-1] LOG: checkpoint starting: time
2008-01-25 11:12:38.423 NZDT [3432]: [8-1] LOG: checkpoint complete: wrote 268
buffers (6.5%); 0 transaction log file(s) added, 0 removed, 77 recycled;
write=27.875 s, sync=1.312 s, total=30.094 s
2008-01-25 11:22:08.088 NZDT [3432]: [9-1] LOG: checkpoint starting: time
2008-01-25 11:22:29.526 NZDT [3432]: [10-1] LOG: checkpoint complete: wrote
188 buffers (4.6%); 0 transaction log file(s) added, 0 removed, 48 recycled;
write=18.155 s, sync=1.391 s, total=21.312 s
2008-01-25 11:32:08.362 NZDT [3432]: [11-1] LOG: checkpoint starting: time
2008-01-25 11:33:21.706 NZDT [3432]: [12-1] LOG: checkpoint complete: wrote
672 buffers (16.4%); 0 transaction log file(s) added, 0 removed, 59 recycled;
write=70.423 s, sync=1.562 s, total=73.375 s
2008-01-25 11:42:08.244 NZDT [3432]: [13-1] LOG: checkpoint starting: time
2008-01-25 11:42:27.010 NZDT [3432]: [14-1] LOG: checkpoint complete: wrote
175 buffers (4.3%); 0 transaction log file(s) added, 0 removed, 51 recycled;
write=17.077 s, sync=1.204 s, total=18.813 s
2008-01-25 11:52:08.299 NZDT [3432]: [15-1] LOG: checkpoint starting: time
2008-01-25 11:52:33.627 NZDT [3432]: [16-1] LOG: checkpoint complete: wrote
233 buffers (5.7%); 0 transaction log file(s) added, 0 removed, 64 recycled;
write=23.328 s, sync=1.468 s, total=25.391 s
TopMemoryContext: 49816 total in 6 blocks; 5656 free (6 chunks); 44160 used
RI compare cache: 8192 total in 1 blocks; 1800 free (0 chunks); 6392 used
RI query cache: 8192 total in 1 blocks; 5968 free (0 chunks); 2224 used
TopTransactionContext: 8192 total in 1 blocks; 7792 free (0 chunks); 400 used
Operator class cache: 8192 total in 1 blocks; 3848 free (0 chunks); 4344 used
Operator lookup cache: 24576 total in 2 blocks; 14072 free (6 chunks); 10504
used
MessageContext: 40960 total in 3 blocks; 19960 free (5 chunks); 21000 used
smgr relation table: 8192 total in 1 blocks; 2808 free (0 chunks); 5384 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: 8192 total in 1 blocks; 8040 free (0 chunks); 152 used
PortalHeapMemory: 1024 total in 1 blocks; 760 free (0 chunks); 264 used
ExecutorState: 2044715008 total in 270 blocks; 21056 free (262 chunks);
2044693952 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used
Relcache by OID: 8192 total in 1 blocks; 3376 free (0 chunks); 4816 used
CacheMemoryContext: 667472 total in 20 blocks; 182800 free (1 chunks); 484672
used
location_ix: 1024 total in 1 blocks; 304 free (0 chunks); 720 used
... [Cut 58 indexes with very similar lines to the above, to save space]
MdSmgr: 8192 total in 1 blocks; 7240 free (0 chunks); 952 used
LOCALLOCK hash: 8192 total in 1 blocks; 3912 free (0 chunks); 4280 used
Timezones: 49432 total in 2 blocks; 5968 free (0 chunks); 43464 used
ErrorContext: 8192 total in 1 blocks; 8176 free (3 chunks); 16 used
2008-01-25 11:53:10.315 NZDT [3824]: [3-1] ERROR: out of memory
2008-01-25 11:53:10.362 NZDT [3824]: [4-1] DETAIL: Failed on request of size
28.
2008-01-25 11:53:10.362 NZDT [3824]: [5-1] STATEMENT: UPDATE document_file SET
document_type_id = (SELECT document_type_id FROM document d where d.id =
document_id);
2008-01-25 12:00:53.571 NZDT [3604]: [1-1] LOG: connection received:
host=(removed) port=3399
2008-01-25 12:00:54.274 NZDT [3604]: [2-1] LOG: connection authorized:
user=postgres database=(removed)
2008-01-25 12:00:55.727 NZDT [3604]: [3-1] LOG: duration: 1264.999 ms
statement: SET DateStyle=ISO;SELECT oid, pg_encoding_to_char(encoding) AS
encoding, datlastsysoid
FROM pg_database WHERE oid = 16466
2008-01-25 12:02:08.322 NZDT [3432]: [17-1] LOG: checkpoint starting: time
2008-01-25 12:07:03.591 NZDT [3432]: [18-1] LOG: checkpoint complete: wrote
2784 buffers (68.0%); 0 transaction log file(s) added, 0 removed, 92 recycled;
write=292.488 s, sync=1.515 s, total=295.473 s
2008-01-25 12:10:07.031 NZDT [3604]: [4-1] LOG: duration: 539646.999 ms
statement: select count(*) from document_file;
2008-01-25 12:12:08.048 NZDT [3432]: [19-1] LOG: checkpoint starting: time
2008-01-25 12:15:22.176 NZDT [3432]: [20-1] LOG: checkpoint complete: wrote
949 buffers (23.2%); 0 transaction log file(s) added, 0 removed, 8 recycled;
write=193.097 s, sync=0.936 s, total=194.127 s
Environment:
OS: Windows XP
PostgreSQL: 8.3RC1
Non default Resource and WAL configuration settings:
shared_buffers = 32MB
max_fsm_pages = 204800
checkpoint_segments = 300
checkpoint_timeout = 10min
The previous query (not logged due to log_min_duration_statement = 500) had
been:
ALTER TABLE document_file ADD document_type_id integer;
The query plan:
Seq Scan on document_file (cost=0.00..280337907.00 rows=27619541 width=617)
SubPlan
-> Index Scan using pk_document_id on document d (cost=0.00..10.12 rows=1
width=4)
Index Cond: (id = $0)
Stephen Denne
Disclaimer:
At the Datamail Group we value team commitment, respect, achievement, customer
focus, and courage. This email with any attachments is confidential and may be
subject to legal privilege. If it is not intended for you please advise by
reply immediately, destroy it and do not copy, disclose or use it in any way.
__________________________________________________________________
This email has been scanned by the DMZGlobal Business Quality
Electronic Messaging Suite.
Please see http://www.dmzglobal.com/services/bqem.htm for details.
__________________________________________________________________
---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match
