X-Original-To: pgsql-performance-postgresql.org@postgresql.org Received: from localhost (unknown [200.46.208.251]) by postgresql.org (Postfix) with ESMTP id AF79A9FA61D for ; Wed, 30 Aug 2006 10:13:57 -0300 (ADT) Received: from postgresql.org ([200.46.204.71]) by localhost (mx1.hub.org [200.46.208.251]) (amavisd-new, port 10024) with ESMTP id 28463-03-3 for ; Wed, 30 Aug 2006 10:13:32 -0300 (ADT) X-Greylist: delayed 02:52:48.673501 by SQLgrey- Received: from smtp01.isdsl.net (smtp01.isdsl.net [196.26.208.190]) by postgresql.org (Postfix) with ESMTP id 9CA999FB2FC for ; Wed, 30 Aug 2006 10:12:54 -0300 (ADT) Received: from server.svo.co.za (c1-52-10.rrba.isadsl.co.za [196.209.57.52]) by smtp01.isdsl.net (Postfix) with ESMTP id EC7802F13B for ; Wed, 30 Aug 2006 15:12:48 +0200 (SAST) Received: from [192.168.0.11] ([192.168.0.11]) by server.svo.co.za with Microsoft SMTPSVC(6.0.3790.1830); Wed, 30 Aug 2006 15:17:13 +0200 Message-ID: <44F58EC9.9090703@studentvillage.co.za> Date: Wed, 30 Aug 2006 15:12:41 +0200 From: Willo van der Merwe User-Agent: Thunderbird 1.5.0.5 (Windows/20060719) MIME-Version: 1.0 To: Dave Cramer Cc: Luke Lonergan , Merlin Moncure , pgsql-performance@postgresql.org Subject: Re: PostgreSQL performance issues References: <3E37B936B592014B978C4415F90D662D04392D1A@MI8NYCMAIL06.Mi8.com> <44F577F8.5070307@studentvillage.co.za> In-Reply-To: Content-Type: multipart/alternative; boundary="------------010008040400090901050000" X-OriginalArrivalTime: 30 Aug 2006 13:17:13.0546 (UTC) FILETIME=[9B7AE2A0:01C6CC36] X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=0.444 tagged_above=0 required=5 tests=AWL, FORGED_RCVD_HELO, HTML_50_60, HTML_MESSAGE X-Spam-Level: X-Archive-Number: 200608/475 X-Sequence-Number: 20660 This is a multi-part message in MIME format. --------------010008040400090901050000 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Dave Cramer wrote: > > On 30-Aug-06, at 7:35 AM, Willo van der Merwe wrote: > >> Luke Lonergan wrote: >>>> Currently the load looks like this: >>>> Cpu0 : 96.8% us, 1.9% sy, 0.0% ni, 0.3% id, 0.0% wa, 0.0% >>>> hi, 1.0% si >>>> Cpu1 : 97.8% us, 1.6% sy, 0.0% ni, 0.3% id, 0.0% wa, 0.0% >>>> hi, 0.3% si >>>> Cpu2 : 96.8% us, 2.6% sy, 0.0% ni, 0.3% id, 0.0% wa, 0.0% >>>> hi, 0.3% si >>>> Cpu3 : 96.2% us, 3.2% sy, 0.0% ni, 0.3% id, 0.0% wa, 0.0% >>>> hi, 0.3% si >>>> >>> >>> All four CPUs are hammered busy - check "top" and look for runaway >>> processes. >>> >>> - Luke >>> >>> >>> >> Yes, the first 463 process are all postgres. In the meanwhile I've done: >> Dropped max_connections from 500 to 250 and >> Upped shared_buffers = 50000 > > With 4G of memory you can push shared buffers to double that. > effective_cache should be 3/4 of available memory. > > Can you also check vmstat 1 for high context switches during this > query, high being over 100k > > Dave >> >> Without any apparent effect. >> >> ---------------------------(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 >> > > Hi Dave, Ok, I've upped shared_buffers = 150000 and effective_cache_size = 100000 and restarted the service top now reads: top - 15:08:28 up 20:12, 1 user, load average: 19.55, 22.48, 26.59 Tasks: 132 total, 24 running, 108 sleeping, 0 stopped, 0 zombie Cpu0 : 97.0% us, 1.0% sy, 0.0% ni, 0.3% id, 0.0% wa, 0.3% hi, 1.3% si Cpu1 : 98.3% us, 1.7% sy, 0.0% ni, 0.0% id, 0.0% wa, 0.0% hi, 0.0% si Cpu2 : 98.0% us, 1.7% sy, 0.0% ni, 0.0% id, 0.0% wa, 0.0% hi, 0.3% si Cpu3 : 96.7% us, 3.3% sy, 0.0% ni, 0.0% id, 0.0% wa, 0.0% hi, 0.0% si Mem: 4060084k total, 2661772k used, 1398312k free, 108152k buffers Swap: 4192956k total, 0k used, 4192956k free, 2340936k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 11446 postgres 17 0 1280m 97m 95m R 28.9 2.5 0:03.63 postmaster 11435 postgres 16 0 1279m 120m 117m R 26.9 3.0 0:05.18 postmaster 11438 postgres 16 0 1279m 31m 30m R 24.6 0.8 0:04.43 postmaster 11163 postgres 16 0 1279m 120m 118m R 23.2 3.0 0:42.61 postmaster 11167 postgres 16 0 1279m 120m 118m R 23.2 3.0 0:41.04 postmaster 11415 postgres 15 0 1279m 299m 297m R 22.2 7.5 0:07.07 postmaster 11428 postgres 15 0 1279m 34m 32m R 21.9 0.9 0:05.53 postmaster 11225 postgres 16 0 1279m 31m 30m R 21.6 0.8 0:34.95 postmaster 11298 postgres 16 0 1279m 118m 117m R 21.6 3.0 0:23.82 postmaster 11401 postgres 15 0 1279m 31m 30m R 21.6 0.8 0:08.18 postmaster 11377 postgres 15 0 1279m 122m 120m R 20.9 3.1 0:09.54 postmaster 11357 postgres 17 0 1280m 126m 123m R 19.9 3.2 0:13.98 postmaster 11415 postgres 16 0 1279m 299m 297m R 17.1 7.5 0:06.40 postmaster 11461 postgres 17 0 1279m 81m 78m R 17.1 2.0 0:00.77 postmaster 11357 postgres 15 0 1279m 120m 118m S 16.8 3.0 0:13.38 postmaster 11458 postgres 16 0 1279m 31m 30m R 15.8 0.8 0:00.97 postmaster 11446 postgres 15 0 1279m 31m 30m S 15.5 0.8 0:02.76 postmaster 11428 postgres 15 0 1279m 34m 32m S 15.2 0.9 0:04.87 postmaster 11435 postgres 16 0 1279m 120m 117m R 14.2 3.0 0:04.37 postmaster 11466 postgres 16 0 1279m 33m 32m S 7.9 0.9 0:00.24 postmaster load avg is climbing... vmstat 1 I don't see any cs > 100k procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu---- r b swpd free buff cache si so bi bo in cs us sy id wa 33 0 0 1352128 108248 2352604 0 0 7 33 147 26 65 2 33 0 19 0 0 1348360 108264 2352656 0 0 0 348 3588 1408 98 2 0 0 26 0 0 1346024 108264 2352996 0 0 0 80 3461 1154 98 2 0 0 27 0 0 1349496 108264 2352996 0 0 0 100 3611 1199 98 2 0 0 31 0 0 1353872 108264 2353064 0 0 0 348 3329 1227 97 2 0 0 21 0 0 1352528 108264 2353064 0 0 0 80 3201 1437 97 2 0 0 28 0 0 1352096 108280 2353184 0 0 0 64 3579 1073 98 2 0 0 29 0 0 1352096 108284 2353180 0 0 0 0 3538 1293 98 2 0 0 28 0 0 1351776 108288 2353244 0 0 0 36 3339 1313 99 1 0 0 22 0 0 1366392 108288 2353244 0 0 0 588 3663 1303 99 1 0 0 27 0 0 1366392 108288 2353312 0 0 0 84 3276 1028 99 1 0 0 28 0 0 1365504 108296 2353372 0 0 0 140 3500 1164 98 2 0 0 26 0 0 1368272 108296 2353372 0 0 0 68 3268 1082 98 2 0 0 25 0 0 1372232 108296 2353508 0 0 0 260 3261 1278 97 3 0 0 26 0 0 1366056 108296 2353644 0 0 0 0 3268 1178 98 2 0 0 24 1 0 1368704 108296 2353780 0 0 0 1788 3548 1614 97 3 0 0 29 0 0 1367728 108296 2353304 0 0 0 60 3637 1105 99 1 0 0 21 0 0 1365224 108300 2353640 0 0 0 12 3257 918 99 1 0 0 27 0 0 1363944 108300 2354116 0 0 0 72 3052 1365 98 2 0 0 25 0 0 1366968 108300 2354184 0 0 0 212 3314 1696 99 1 0 0 30 0 0 1363552 108300 2354184 0 0 0 72 3147 1420 97 2 0 0 27 0 0 1367792 108300 2354184 0 0 0 184 3245 1310 97 2 0 0 21 0 0 1369088 108308 2354380 0 0 0 140 3306 987 98 2 0 0 11 1 0 1366056 108308 2354448 0 0 0 88 3210 1183 98 1 0 0 27 0 0 1361104 108308 2354516 0 0 0 0 3598 1015 98 2 0 0 28 0 0 1356808 108308 2354584 0 0 0 64 2835 1326 98 2 0 0 3 0 0 1352888 108308 2354856 0 0 0 88 2829 1111 97 3 0 0 29 0 0 1351408 108316 2354848 0 0 0 180 2916 939 97 3 0 0 30 0 0 1352568 108316 2354848 0 0 0 112 2962 1122 98 2 0 0 29 0 0 1356936 108316 2355052 0 0 0 176 2987 976 98 2 0 0 27 0 0 1363816 108316 2355188 0 0 0 220 2990 1809 98 2 0 0 24 0 0 1361944 108316 2355256 0 0 0 0 3043 1213 98 2 0 0 24 0 0 1368808 108324 2355248 0 0 0 112 3168 1464 98 2 0 0 24 0 0 1370120 108324 2355248 0 0 0 112 3179 997 99 1 0 0 12 0 0 1370752 108324 2355248 0 0 0 16 3255 1081 97 3 0 0 26 0 0 1372752 108324 2355248 0 0 0 112 3416 1169 98 2 0 0 27 0 0 1369088 108324 2355248 0 0 0 0 3011 828 98 2 0 0 20 0 0 1366848 108324 2355316 0 0 0 64 3062 959 98 2 0 0 26 0 0 1368064 108328 2355312 0 0 0 264 3069 1064 97 3 0 0 24 0 0 1365624 108328 2355448 0 0 0 152 2940 1344 98 2 0 0 26 0 0 1363880 108328 2355584 0 0 0 128 3294 1122 98 2 0 0 26 0 0 1370048 108328 2355652 0 0 0 152 3198 1340 97 3 0 0 procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu---- r b swpd free buff cache si so bi bo in cs us sy id wa 12 0 0 1369344 108328 2355720 0 0 0 184 2994 1030 98 2 0 0 --------------010008040400090901050000 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Dave Cramer wrote:

On 30-Aug-06, at 7:35 AM, Willo van der Merwe wrote:

Luke Lonergan wrote:
Currently the load looks like this:
Cpu0  : 96.8% us,  1.9% sy,  0.0% ni,  0.3% id,  0.0% wa,  0.0% hi,  1.0% si
Cpu1  : 97.8% us,  1.6% sy,  0.0% ni,  0.3% id,  0.0% wa,  0.0% hi,  0.3% si
Cpu2  : 96.8% us,  2.6% sy,  0.0% ni,  0.3% id,  0.0% wa,  0.0% hi,  0.3% si
Cpu3  : 96.2% us,  3.2% sy,  0.0% ni,  0.3% id,  0.0% wa,  0.0% hi,  0.3% si


All four CPUs are hammered busy - check "top" and look for runaway
processes.

- Luke



Yes, the first 463 process are all postgres. In the meanwhile I've done:
Dropped max_connections from 500 to 250 and
Upped shared_buffers = 50000

With 4G of memory you can push shared buffers to double that.
effective_cache should be 3/4 of available memory.

Can you also check vmstat 1 for high context switches during this query, high being over 100k

Dave

Without any apparent effect.

---------------------------(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



Hi Dave,

Ok, I've upped shared_buffers = 150000
and effective_cache_size = 100000

and restarted the service
top now reads:

top - 15:08:28 up 20:12,  1 user,  load average: 19.55, 22.48, 26.59
Tasks: 132 total,  24 running, 108 sleeping,   0 stopped,   0 zombie
Cpu0  : 97.0% us,  1.0% sy,  0.0% ni,  0.3% id,  0.0% wa,  0.3% hi,  1.3% si
Cpu1  : 98.3% us,  1.7% sy,  0.0% ni,  0.0% id,  0.0% wa,  0.0% hi,  0.0% si
Cpu2  : 98.0% us,  1.7% sy,  0.0% ni,  0.0% id,  0.0% wa,  0.0% hi,  0.3% si
Cpu3  : 96.7% us,  3.3% sy,  0.0% ni,  0.0% id,  0.0% wa,  0.0% hi,  0.0% si
Mem:   4060084k total,  2661772k used,  1398312k free,   108152k buffers
Swap:  4192956k total,        0k used,  4192956k free,  2340936k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
11446 postgres  17   0 1280m  97m  95m R 28.9  2.5   0:03.63 postmaster
11435 postgres  16   0 1279m 120m 117m R 26.9  3.0   0:05.18 postmaster
11438 postgres  16   0 1279m  31m  30m R 24.6  0.8   0:04.43 postmaster
11163 postgres  16   0 1279m 120m 118m R 23.2  3.0   0:42.61 postmaster
11167 postgres  16   0 1279m 120m 118m R 23.2  3.0   0:41.04 postmaster
11415 postgres  15   0 1279m 299m 297m R 22.2  7.5   0:07.07 postmaster
11428 postgres  15   0 1279m  34m  32m R 21.9  0.9   0:05.53 postmaster
11225 postgres  16   0 1279m  31m  30m R 21.6  0.8   0:34.95 postmaster
11298 postgres  16   0 1279m 118m 117m R 21.6  3.0   0:23.82 postmaster
11401 postgres  15   0 1279m  31m  30m R 21.6  0.8   0:08.18 postmaster
11377 postgres  15   0 1279m 122m 120m R 20.9  3.1   0:09.54 postmaster
11357 postgres  17   0 1280m 126m 123m R 19.9  3.2   0:13.98 postmaster
11415 postgres  16   0 1279m 299m 297m R 17.1  7.5   0:06.40 postmaster
11461 postgres  17   0 1279m  81m  78m R 17.1  2.0   0:00.77 postmaster
11357 postgres  15   0 1279m 120m 118m S 16.8  3.0   0:13.38 postmaster
11458 postgres  16   0 1279m  31m  30m R 15.8  0.8   0:00.97 postmaster
11446 postgres  15   0 1279m  31m  30m S 15.5  0.8   0:02.76 postmaster
11428 postgres  15   0 1279m  34m  32m S 15.2  0.9   0:04.87 postmaster
11435 postgres  16   0 1279m 120m 117m R 14.2  3.0   0:04.37 postmaster
11466 postgres  16   0 1279m  33m  32m S  7.9  0.9   0:00.24 postmaster

load avg is climbing...

vmstat 1

I don't see any cs > 100k

procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
33  0      0 1352128 108248 2352604    0    0     7    33  147    26 65  2 33  0
19  0      0 1348360 108264 2352656    0    0     0   348 3588  1408 98  2  0  0
26  0      0 1346024 108264 2352996    0    0     0    80 3461  1154 98  2  0  0
27  0      0 1349496 108264 2352996    0    0     0   100 3611  1199 98  2  0  0
31  0      0 1353872 108264 2353064    0    0     0   348 3329  1227 97  2  0  0
21  0      0 1352528 108264 2353064    0    0     0    80 3201  1437 97  2  0  0
28  0      0 1352096 108280 2353184    0    0     0    64 3579  1073 98  2  0  0
29  0      0 1352096 108284 2353180    0    0     0     0 3538  1293 98  2  0  0
28  0      0 1351776 108288 2353244    0    0     0    36 3339  1313 99  1  0  0
22  0      0 1366392 108288 2353244    0    0     0   588 3663  1303 99  1  0  0
27  0      0 1366392 108288 2353312    0    0     0    84 3276  1028 99  1  0  0
28  0      0 1365504 108296 2353372    0    0     0   140 3500  1164 98  2  0  0
26  0      0 1368272 108296 2353372    0    0     0    68 3268  1082 98  2  0  0
25  0      0 1372232 108296 2353508    0    0     0   260 3261  1278 97  3  0  0
26  0      0 1366056 108296 2353644    0    0     0     0 3268  1178 98  2  0  0
24  1      0 1368704 108296 2353780    0    0     0  1788 3548  1614 97  3  0  0
29  0      0 1367728 108296 2353304    0    0     0    60 3637  1105 99  1  0  0
21  0      0 1365224 108300 2353640    0    0     0    12 3257   918 99  1  0  0
27  0      0 1363944 108300 2354116    0    0     0    72 3052  1365 98  2  0  0
25  0      0 1366968 108300 2354184    0    0     0   212 3314  1696 99  1  0  0
30  0      0 1363552 108300 2354184    0    0     0    72 3147  1420 97  2  0  0
27  0      0 1367792 108300 2354184    0    0     0   184 3245  1310 97  2  0  0
21  0      0 1369088 108308 2354380    0    0     0   140 3306   987 98  2  0  0
11  1      0 1366056 108308 2354448    0    0     0    88 3210  1183 98  1  0  0
27  0      0 1361104 108308 2354516    0    0     0     0 3598  1015 98  2  0  0
28  0      0 1356808 108308 2354584    0    0     0    64 2835  1326 98  2  0  0
 3  0      0 1352888 108308 2354856    0    0     0    88 2829  1111 97  3  0  0
29  0      0 1351408 108316 2354848    0    0     0   180 2916   939 97  3  0  0
30  0      0 1352568 108316 2354848    0    0     0   112 2962  1122 98  2  0  0
29  0      0 1356936 108316 2355052    0    0     0   176 2987   976 98  2  0  0
27  0      0 1363816 108316 2355188    0    0     0   220 2990  1809 98  2  0  0
24  0      0 1361944 108316 2355256    0    0     0     0 3043  1213 98  2  0  0
24  0      0 1368808 108324 2355248    0    0     0   112 3168  1464 98  2  0  0
24  0      0 1370120 108324 2355248    0    0     0   112 3179   997 99  1  0  0
12  0      0 1370752 108324 2355248    0    0     0    16 3255  1081 97  3  0  0
26  0      0 1372752 108324 2355248    0    0     0   112 3416  1169 98  2  0  0
27  0      0 1369088 108324 2355248    0    0     0     0 3011   828 98  2  0  0
20  0      0 1366848 108324 2355316    0    0     0    64 3062   959 98  2  0  0
26  0      0 1368064 108328 2355312    0    0     0   264 3069  1064 97  3  0  0
24  0      0 1365624 108328 2355448    0    0     0   152 2940  1344 98  2  0  0
26  0      0 1363880 108328 2355584    0    0     0   128 3294  1122 98  2  0  0
26  0      0 1370048 108328 2355652    0    0     0   152 3198  1340 97  3  0  0
procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
12  0      0 1369344 108328 2355720    0    0     0   184 2994  1030 98  2  0  0


--------------010008040400090901050000--