FAQ
Hi,
We are having strange problem on production system with very slow
insert/delete commands and huge cpu and disk write activity spikes in
postgresql 7.2.4. This behavior is very reproducible and happens in
following sequence :
1. full db vacuum
2. several hundred of insert/delete commands are performed as fast as
possible(tables used by insert/delete command are indexed to speed up
queries)


At (2) postgres starts taking 90-100% cpu and performing a lot of
writing that i guess flushing dirty buffers to disk and queries are
slowed down to nearly 1-2 per second. During this time postresql logs
'recycled transaction log ...' messages.
Postgres configuration is mostly default:
max_connections=45
shared_buffers=2048
deadlock_timeout = 60000
sort_mem = 1024
log_timestamp = true
log_pid = true
debug_level = 2

What causes postgres to behave like this? Is there anything can be
done to postgres [configuration] to handle bulk queries more efficient
and reduce disk i/o and cpu consumption?

Thanks a lot and sorry for long post,

alex.

Here's top and sar outputs during this time:
7:52am up 42 days, 6:25, 1 user, load average: 2.62, 1.90, 1.22
187 processes: 182 sleeping, 4 running, 1 zombie, 0 stopped
CPU states: 0.0% user, 80.7% system, 17.7% nice, 1.5% idle
Mem: 1025852K av, 1012012K used, 13840K free, 0K shrd, 20796K buff
Swap: 1026036K av, 23292K used, 1002744K free 743360K cached

PID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND
23411 postgres 17 10 19304 18M 18696 R N 84.1 1.8 7:16 postmaster
24177 admin 16 5 1044 1044 760 R N 6.6 0.1 17:39 top
11633 admin 17 10 5888 5888 1736 R N 6.1 0.5 0:00 ctl
321 admin 9 0 0 0 0 SW 0.6 0.0 19:30 kjournald


sar :
07:02:00 tps rtps wtps bread/s bwrtn/s
07:52:00 41.38 0.34 41.04 16.84 701.34
08:02:00 42.27 0.02 42.24 0.23 696.80
08:12:00 39.42 0.05 39.37 0.76 730.63

And sample of postmaster.log :

2005-06-24 07:53:24 [23411] DEBUG: StartTransactionCommand
2005-06-24 07:53:24 [23411] DEBUG: query: insert into MONITORING_DATA_LOC_DAIL
Y (MONITORING_DATA_LOC_DAILY_ID,GEN_ID,START_TIME,END_TIME,MONITORED_OBJECT_ID,L
OCATION_ID,TIME_SPAN,GAP_MILLIS,CE_COUNT,DATA) values (1,330861,1119398400000,11
19484800000,19011,19011,4,0,1,'6#|0#0#0#|311864#311864#0#0#0#0#0#0#0#0#0#0#0#0#0
#')
2005-06-24 07:53:24 [23411] DEBUG: ProcessQuery
2005-06-24 07:53:24 [23411] DEBUG: CommitTransactionCommand
2005-06-24 07:53:24 [23411] DEBUG: StartTransactionCommand
2005-06-24 07:53:24 [23411] DEBUG: query: delete from MONITORING_DATA_LOC_HOUR
LY where MONITORED_OBJECT_ID = cast(19011 as bigint) AND END_TIME <= cast(111948
4800000 as bigint)
2005-06-24 07:53:24 [23411] DEBUG: ProcessQuery
2005-06-24 07:53:25 [23411] DEBUG: CommitTransactionCommand
2005-06-24 07:53:25 [23411] DEBUG: StartTransactionCommand
2005-06-24 07:53:25 [23411] DEBUG: query: insert into MONITORING_DATA_LOC_DAIL
Y (MONITORING_DATA_LOC_DAILY_ID,GEN_ID,START_TIME,END_TIME,MONITORED_OBJECT_ID,L
OCATION_ID,TIME_SPAN,GAP_MILLIS,CE_COUNT,DATA) values (1,330861,1119398400000,11
19484800000,15877,15877,4,0,1,'7#|0#0#0#|121435#121435#0#0#0#0#0#0#0#0#0#0#0#0#0
#')
2005-06-24 07:53:25 [23411] DEBUG: ProcessQuery
2005-06-24 07:53:25 [23411] DEBUG: CommitTransactionCommand
2005-06-24 07:53:25 [23411] DEBUG: StartTransactionCommand
2005-06-24 07:53:25 [23411] DEBUG: query: delete from MONITORING_DATA_LOC_HOUR
LY where MONITORED_OBJECT_ID = cast(15877 as bigint) AND END_TIME <= cast(111948
4800000 as bigint)
2005-06-24 07:53:25 [23411] DEBUG: ProcessQuery
2005-06-24 07:53:26 [23411] DEBUG: CommitTransactionCommand
2005-06-24 07:53:26 [23411] DEBUG: StartTransactionCommand
2005-06-24 07:53:26 [23411] DEBUG: query: insert into MONITORING_DATA_LOC_DAIL
Y (MONITORING_DATA_LOC_DAILY_ID,GEN_ID,START_TIME,END_TIME,MONITORED_OBJECT_ID,L
OCATION_ID,TIME_SPAN,GAP_MILLIS,CE_COUNT,DATA) values (1,330861,1119398400000,11
19484800000,16095,16095,4,0,1,'6#|0#0#0#|78179338#78179338#0#0#0#0#0#0#0#0#0#0#0
#0#0#')
2005-06-24 07:53:26 [23411] DEBUG: ProcessQuery
2005-06-24 07:53:26 [23411] DEBUG: CommitTransactionCommand
2005-06-24 07:53:26 [11664] DEBUG: recycled transaction log file 0000000900000
0C5
2005-06-24 07:53:26 [11664] DEBUG: proc_exit(0)

Search Discussions

  • Tom Lane at Jun 28, 2005 at 5:45 am

    Alexander Korobov writes:
    We are having strange problem on production system with very slow
    insert/delete commands and huge cpu and disk write activity spikes in
    postgresql 7.2.4.
    The first thing you should consider, if you are concerned about
    performance, is adopting a less obsolete version of Postgres.

    As a stopgap, increasing the checkpoint interval parameters might
    help some.

    regards, tom lane

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
grouppgsql-general @
categoriespostgresql
postedJun 27, '05 at 5:35p
activeJun 28, '05 at 5:45a
posts2
users2
websitepostgresql.org
irc#postgresql

2 users in discussion

Alexander Korobov: 1 post Tom Lane: 1 post

People

Translate

site design / logo © 2021 Grokbase