sudden spurt in swap utilization (was:cpu bound postgresql setup.)

From: Rajesh Kumar Mallah <mallah(dot)rajesh(at)gmail(dot)com>
To: Kevin Grittner <Kevin(dot)Grittner(at)wicourts(dot)gov>
Cc: pgsql-performance(at)postgresql(dot)org
Subject: sudden spurt in swap utilization (was:cpu bound postgresql setup.)
Date: 2010-06-25 09:55:39
Message-ID: AANLkTinDBPQL-SjLaCr7AVgzouWbRrjwA6MAgBih_ciy@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

A scary phenomenon is being exhibited by the server , which is the server
is slurping all the swap suddenly , some of the relevant sar -r output are:

10:30:01 AM kbmemfree kbmemused %memused kbbuffers kbcached
kbswpfree kbswpused %swpused kbswpcad
10:40:01 AM 979068 31892208 97.02 10588 28194876
1781568 314872 15.02 66500
10:50:01 AM 1791536 31079740 94.55 10480 27426512
1782848 313592 14.96 43880
11:00:01 AM 4678768 28192508 85.77 9692 27213312
1784888 311552 14.86 33296
11:10:01 AM 179208 32692068 99.45 3180 27569008
1725136 371304 17.71 65444
11:20:01 AM 225604 32645672 99.31 2604 29817192
1693672 402768 19.21 78312 <-------

11:30:01 AM 520224 32351052 98.42 1780 26863576
0 2096440 100.00 1585772 <------ within 10mins
11:40:02 AM 483532 32387744 98.53 2672 27220404
0 2096440 100.00 43876
11:50:01 AM 162700 32708576 99.51 3316 27792540
0 2096440 100.00 43708
12:00:01 PM 420176 32451100 98.72 3772 28181316
0 2096440 100.00 43708
12:10:01 PM 331624 32539652 98.99 3236 27857760
0 2096440 100.00 0
12:20:01 PM 1023428 31847848 96.89 4632 27450504
0 2096440 100.00 0
12:30:01 PM 763296 32107980 97.68 4988 28270704
0 2096440 100.00 0
12:40:01 PM 770280 32100996 97.66 5260 28423292
0 2096440 100.00 0

Then i added more swap made it 4GB from 2GB

02:10:05 PM 8734144 24137132 73.43 5532 21219972
2096788 2096124 49.99 52
02:12:01 PM 5989044 26882232 81.78 6108 23606680
2096788 2096124 49.99 52
02:14:01 PM 1517724 31353552 95.38 6320 26988280
2096788 2096124 49.99 52
02:16:01 PM 316692 32554584 99.04 6516 28840264
1844856 2348056 56.00 251984
02:18:01 PM 450672 32420604 98.63 7748 27238712
0 4192912 100.00 2096840 <---- all swap gone.
02:20:01 PM 164388 32706888 99.50 7556 27118104
0 4192912 100.00 2096840
02:22:01 PM 848544 32022732 97.42 6212 26718712
0 4192912 100.00 2096840
02:24:01 PM 231332 32639944 99.30 6136 27276720
0 4192912 100.00 2096840
02:26:01 PM 639560 32231716 98.05 5608 27029372
0 4192912 100.00 2096840
02:28:01 PM 868824 32002452 97.36 4648 26253996
0 4192912 100.00 2096840
.......
03:04:01 PM 854408 32016868 97.40 4976 27182140
0 4192912 100.00 0
03:06:01 PM 1571904 31299372 95.22 5184 27513232
0 4192912 100.00 0
03:08:02 PM 304600 32566676 99.07 5420 27850780
0 4192912 100.00 0
03:10:01 PM 915352 31955924 97.22 5632 28076320
0 4192912 100.00 0
03:12:01 PM 705132 32166144 97.85 5680 28057444
0 4192912 100.00 0
03:14:01 PM 369516 32501760 98.88 6136 27684364
0 4192912 100.00 0

in vmstat the system does not seems to be swapping
vmstat 5
procs -----------memory---------- ---swap-- -----io---- --system--
-----cpu------
r b swpd free buff cache si so bi bo in cs us sy id wa st
24 2 4192912 947796 6036 27785324 1 0 451 208 0 0
50 6 39 5 0
22 3 4192912 1028956 6044 27795728 0 0 1730 555 13445
14736 67 12 17 4 0
24 0 4192912 877508 6052 27806172 0 0 1595 2292 13334 15666
67 9 19 5 0
14 8 4192912 820432 6068 27819756 0 0 2331 1351 13208 16192
66 9 14 11 0
23 1 4192912 925960 6076 27831644 0 0 1932 1584 13144 16291
71 9 14 5 0
2 3 4192912 895288 6084 27846432 0 0 2496 991 13450 16303
70 9 13 8 0
17 0 4192912 936252 6092 27859868 0 0 2122 826 13438 16233
69 9 17 5 0
8 1 4192912 906164 6100 27873640 0 0 2277 858 13440 16235
63 8 19 10 0

I reduced work_mem from 4GB to 2GB to 512MB (now). I clearly remember that this
abnormal consumption of swap was NOT there even when work_mem was 4GB.
eg during happier times swap utilisation was: http://pastebin.com/bnE1pFZ9

the question is whats making postgres slurp the swap? i am posting my
current postgresql.conf
once again.

# cat postgresql.conf | grep -v "^\s*#" | grep -v "^\s*$"
listen_addresses = '*' # what IP address(es) to listen on;
port = 5432 # (change requires restart)
max_connections = 300 # (change requires restart)
shared_buffers = 10GB # min 128kB
work_mem = 512MB # min 64kB
fsync = on # turns forced synchronization on or off
synchronous_commit = on # immediate fsync at commit
checkpoint_segments = 30 # in logfile segments, min 1, 16MB each
archive_mode = on # allows archiving to be done
archive_command = '/opt/scripts/archive_wal.sh %p %f '
archive_timeout = 600 # force a logfile segment switch after this
effective_cache_size = 18GB
constraint_exclusion = on # on, off, or partition
logging_collector = on # Enable capturing of stderr and csvlog
log_directory = '/var/log/postgresql' # directory where log
files are written,
log_filename = 'postgresql.log' # log file name pattern,
log_truncate_on_rotation = on # If on, an existing log file of the
log_rotation_age = 1d # Automatic rotation of logfiles will
log_error_verbosity = verbose # terse, default, or verbose messages
log_min_duration_statement = 5000 # -1 is disabled, 0 logs all statements
datestyle = 'iso, mdy'
lc_messages = 'en_US.UTF-8' # locale for system
error message
lc_monetary = 'en_US.UTF-8' # locale for monetary formatting
lc_numeric = 'en_US.UTF-8' # locale for number formatting
lc_time = 'en_US.UTF-8' # locale for time formatting
default_text_search_config = 'pg_catalog.english'
add_missing_from = on
custom_variable_classes = 'general' # list of custom
variable class names
general.report_level = ''
general.disable_audittrail2 = ''
general.employee=''

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Devrim GÜNDÜZ 2010-06-25 11:26:59 Re: sudden spurt in swap utilization (was:cpu bound postgresql setup.)
Previous Message Jim Montgomery 2010-06-25 04:59:33 Re: requested shared memory size overflows size_t