[PERFORM] Interpreting vmstat
Hello, (note best viewed in fixed-width font) I'm still trying to find where my performance bottle neck is... I have 4G ram, PG 7.3.4 shared_buffers = 75000 effective_cache_size = 75000 Run a query I've been having trouble with and watch the output of vmstat (linux): $ vmstat 1 procs memoryswap io system cpu r b w swpd free buff cache si sobibo incs us sy id 0 0 0148 8732 193652 2786668 0 0 0 0 292 151 0 2 98 2 0 2148 7040 193652 2786668 0 0 0 208 459 697 45 10 45 0 0 0148 9028 193652 2786684 0 016 644 318 613 25 4 71 1 0 0148 5092 193676 2780196 0 012 184 441 491 37 5 58 0 1 0148 5212 193684 2772512 0 0 112 9740 682 1063 45 12 43 1 0 0148 5444 193684 2771584 0 0 120 4216 464 1303 44 3 52 1 0 0148 12232 193660 2771620 0 0 244 628 340 681 43 20 38 1 0 0148 12168 193664 2771832 0 0 196 552 332 956 42 2 56 1 0 0148 12080 193664 2772248 0 0 272 204 371 201 40 1 59 1 1 0148 12024 193664 2772624 0 0 368 0 259 127 42 3 55 Thats the first 10 lines or so... the query takes 60 seconds to run. I'm confused on the bo & bi parts of the io: IO bi: Blocks sent to a block device (blocks/s). bo: Blocks received from a block device (blocks/s). yet it seems to be opposite of that... bi only increases when doing a largish query, while bo also goes up, I typically see periodic bo numbers in the low 100's, which I'd guess are log writes. I would think that my entire DB should end up cached since a raw pg_dump file is about 1G in size, yet my performance doesn't indicate that that is the case... running the same query a few minutes later, I'm not seeing a significant performance improvement. Here's a sample from iostat while the query is running: $ iostat -x -d 1 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util sda0.00 0.00 0.00 0.000.000.00 0.00 42949552.960.00 0.00 100.00 sda1 0.00 0.00 0.00 0.000.000.00 0.00 42949662.960.00 0.00 100.00 sda2 0.00 0.00 0.00 0.000.000.00 0.00 42949642.960.00 0.00 100.00 sdb0.00 428.00 0.00 116.000.00 4368.0037.66 2844.40 296.55 86.21 100.00 sdb1 0.00 428.00 0.00 116.000.00 4368.0037.66 6874.40 296.55 86.21 100.00 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util sda0.00 0.00 0.00 0.000.000.00 0.00 42949552.960.00 0.00 100.00 sda1 0.00 0.00 0.00 0.000.000.00 0.00 42949662.960.00 0.00 100.00 sda2 0.00 0.00 0.00 0.000.000.00 0.00 42949642.960.00 0.00 100.00 sdb4.00 182.00 6.00 77.00 80.00 2072.0025.93 2814.50 54.22 120.48 100.00 sdb1 4.00 182.00 6.00 77.00 80.00 2072.0025.93 6844.50 54.22 120.48 100.00 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util sda0.00 0.00 0.00 0.000.000.00 0.00 42949552.960.00 0.00 100.00 sda1 0.00 0.00 0.00 0.000.000.00 0.00 42949662.960.00 0.00 100.00 sda2 0.00 0.00 0.00 0.000.000.00 0.00 42949642.960.00 0.00 100.00 sdb0.00 43.00 0.00 11.000.00 432.0039.27 2810.40 36.36 909.09 100.00 sdb1 0.00 43.00 0.00 11.000.00 432.0039.27 6840.40 36.36 909.09 100.00 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util sda0.00 15.84 0.00 17.820.00 269.3115.11 42524309.47 44.44 561.11 100.00 sda1 0.00 15.84 0.00 17.820.00 269.3115.11 42524419.47 44.44 561.11 100.00 sda2 0.00 0.00 0.00 0.000.000.00 0.00 42524398.670.00 0.00 100.00 sdb0.99 222.77 0.99 114.85 15.84 2700.9923.45 2814.16 35.90 86.32 100.00 sdb1 0.99 222.77 0.99 114.85 15.84 2700.9923.45 6844.16 35.90 86.32 100.00 Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await svctm %util sda0.00 0.00 0.00 0.000.000.00 0.00 42949551.760.00 0.00 101.00 sda1 0.00 0.00 0.00 0.000.000.00 0.00 42949662.860.00 0.00 101.00 sda2 0.00 0.00 0.00 0.000.000.00 0.00 42949642.660.00 0.00 101.00 sdb1.00 91.00 1.00 28.00 16.00 960.0033.66 2838.40 10.34 348.28 101.00 sdb1 1.00 91.00 1.00 28.00 16.00 960.0033.66 6908.70 10.34 348.28 101.00 The DB files and logs are on sdb1. Can someone point me in the direction of some documentation on how to interpret these numbers? Also, I've tried to figure out
Re: [PERFORM] Interpreting vmstat
Well, Since I haven't seen any other responds, I'll offer a bit of advice and let others correct me. :) Your shared buffers may be too big (?). It is much larger than the guide on varlena.com recommends. All I can suggest is trying some experiments with halving/doubling the numbers to see which way performance goes. Also, if you are counting on cache to improve performance, then the db has to be loaded into cache the first time. So, are subsequent re-queries faster? Thom Dyson Director of Information Services Sybex, Inc. [EMAIL PROTECTED] wrote on 05/18/2004 11:12:14 AM: > Hello, > (note best viewed in fixed-width font) > > I'm still trying to find where my performance bottle neck is... > I have 4G ram, PG 7.3.4 > shared_buffers = 75000 > effective_cache_size = 75000 ---(end of broadcast)--- TIP 9: the planner will ignore your desire to choose an index scan if your joining column's datatypes do not match
Re: [PERFORM] Interpreting vmstat
On Tue, 2004-05-18 at 14:12, Doug Y wrote: > Run a query I've been having trouble with and watch the output of vmstat > (linux): > > $ vmstat 1 > procs memoryswap io system > cpu > r b w swpd free buff cache si sobibo incs us > sy id > 0 0 0148 8732 193652 > 2786668 0 0 0 0 292 151 0 2 98 > 2 0 2148 7040 193652 > 2786668 0 0 0 208 459 697 45 10 45 > 0 0 0148 9028 193652 > 2786684 0 016 644 318 613 25 4 71 > 1 0 0148 5092 193676 > 2780196 0 012 184 441 491 37 5 58 > 0 1 0148 5212 193684 > 2772512 0 0 112 9740 682 1063 45 12 43 > 1 0 0148 5444 193684 > 2771584 0 0 120 4216 464 1303 44 3 52 > 1 0 0148 12232 193660 > 2771620 0 0 244 628 340 681 43 20 38 > 1 0 0148 12168 193664 > 2771832 0 0 196 552 332 956 42 2 56 > 1 0 0148 12080 193664 > 2772248 0 0 272 204 371 201 40 1 59 > 1 1 0148 12024 193664 > 2772624 0 0 368 0 259 127 42 3 55 > > Thats the first 10 lines or so... the query takes 60 seconds to run. > > I'm confused on the bo & bi parts of the io: > IO > bi: Blocks sent to a block device (blocks/s). > bo: Blocks received from a block device (blocks/s). > > yet it seems to be opposite of that... bi only increases when doing a > largish query, while bo also goes up, I typically see periodic bo numbers > in the low 100's, which I'd guess are log writes. > > I would think that my entire DB should end up cached since a raw pg_dump > file is about 1G in size, yet my performance doesn't indicate that that is > the case... running the same query a few minutes later, I'm not seeing a > significant performance improvement. > Been meaning to try and address this thread since it touches on one of the areas that I think is sorely lacking in the postgresql admin knowledge base; how to use various unix commands to deduce performance information. This would seem even more important given that PostgreSQL admins are expected to use said tools to find out some information that the commercial databases provide to there users... but alas this is -performance and not -advocacy so let me get on with it eh? As you noted, bi and bo are actually reversed, and I believe if you search the kernel hackers mailing lists you'll find references to this... here's some more empirical evidence though, the following vmstat was taken from a high-write traffic monitoring type database application... procs memoryswap io system cpu r b w swpd free buff cache si sobibo incs us sy id 1 0 0 27412 593336 112036 1865936 0 1 0 11 0 1 0 0 5 1 1 27412 593336 112036 1865952 0 0 0 477 600 1346 53 7 40 4 0 0 27412 593336 112036 1865960 0 0 0 1296 731 2087 47 5 48 3 3 2 27412 594408 112052 1865972 4 0 4 2973 904 2957 32 20 48 3 1 1 26596 594544 112068 1865976 64 064 1433 770 2766 41 22 37 1 1 1 26596 594544 112072 1866004 0 0 5 959 702 1687 50 10 41 3 1 1 26596 594512 112072 1866024 0 0 0 1155 731 2209 52 12 37 2 0 0 26596 594512 112072 1866040 0 0 0 635 511 1293 48 5 46 0 1 1 26596 594472 112076 1866076 0 0 7 739 551 1248 49 8 43 1 0 0 26596 594472 112076 1866088 0 0 0 1048 598 1295 49 8 43 2 0 0 26596 594208 112084 1866696 0 0 203 1253 686 1506 42 16 41 1 0 0 26596 593920 112084 1866716 0 0 0 1184 599 1329 39 12 49 0 1 1 26596 593060 112084 1866740 0 0 3 1036 613 3442 48 8 44 0 1 2 26596 592920 112084 1866752 0 0 0 3825 836 1323 9 14 76 0 0 0 26596 593544 112084 1866788 0 0 0 1064 625 1197 9 15 76 0 1 1 26596 596300 112088 1866808 0 0 0 747 625 1558 7 13 79 0 0 1 26596 599600 112100 1866892 0 0 0 468 489 1331 6 4 91 0 0 0 26596 599600 112100 1866896 0 0 0 237 418 997 5 4 91 0 1 1 26596 599600 112104 1866896 0 0 0 1063 582 1371 7 7 86 0 0 0 26596 599612 112104 1866904 0 0 0 561 648 1556 6 4 89 notice all the bo as it continually writes data to disk. Also notice how generally speaking it has no bi since it does not have to pull data up from disk... you will notice that the couple of times it grabs information from swap space, you'll also find a corresponding pull on the io. getting back to your issue in order to determine if there is a problem in this case, you need to run explain analyze a few times repeatedly, take the relative score given by these runs, and then come back 5-10 minutes later and run explain analyze agai
