seeking for suggestions - sporadic performance degradation

Hello,

I'm seeking for suggestions on diagnosing the problem. We have a
relatively complex tables structure. When running a reporting query
(60k+ in size) that includes inner/outers joins of several tables,
sub-selects and group by, I often observe postgresql ( 8.1.5) would
almost stop working on that query for several seconds (can see that by
dropped CPU and I/O activity), then several seconds later it gets back
to work. The query runs for about 3-4 minutes. Sometimes, when it's in
a good mood and it doesn't do those stops, the query would take take a
minute or so. It's a dedicated DB server and for clarity of experiment
we have excluded other queries to run at the same time and temporary
disabled autovacuum (btw, is there a way to get autovacuum activity
logged like back in old days when it was a separate package?).

The DB has autovacuum on and runs full vacuum analyze every week. It
seems to be nothing wrong with the RAID - I ran intense I/O commands
during the "stop" periods and had no visual delays or response lags to
my console commands. Server runs on FreeBSD 6.2-STABLE, Postgresql has
default configuration with increased shared memory to 1/10 of RAM and
10x increase to default FSM limits. Nothing interesting in the log.
Bellow is the output of iostat command while query was running. amrd0
hosts tables data, amrd1 - indexes.

tty amrd0 amrd1 cpu
tin tout KB/t tps MB/s KB/t tps MB/s us ni
sy in id
0 61 128.00 1 0.12 16.00 268 4.18 0 0
2 0 98
0 181 72.00 4 0.28 16.00 221 3.45 2 0
1 0 96
0 60 72.00 2 0.14 16.00 213 3.32 0 0
2 0 98
0 60 26.13 136 3.47 16.00 215 3.36 3 0
3 0 93
0 60 69.60 20 1.36 16.05 306 4.79 3 0
4 0 92
0 60 88.00 3 0.26 15.98 321 5.00 2 0
2 2 94
0 60 128.00 1 0.12 16.00 302 4.71 0 0
0 0 99
0 61 128.00 1 0.12 16.00 219 3.42 0 0
1 0 98
0 61 90.67 3 0.27 16.00 198 3.09 0 0
3 0 97
0 60 128.00 1 0.12 16.00 199 3.11 10 0
4 0 85
0 61 128.00 2 0.25 16.00 211 3.29 4 0
1 1 94
0 61 8.58 122 1.02 16.00 232 3.62 7 0
3 0 90
0 60 10.99 169 1.81 16.00 232 3.62 18 0
3 0 79
0 60 6.31 97 0.60 15.92 294 4.57 26 0
5 0 69
0 60 56.00 5 0.27 16.00 360 5.62 10 0
3 1 87
0 60 72.00 2 0.14 16.00 300 4.68 5 0
2 0 93
0 60 128.00 2 0.25 16.00 309 4.82 1 0
1 1 96
0 61 22.59 17 0.37 16.00 278 4.34 2 0
3 0 95
0 60 128.00 2 0.25 16.00 260 4.06 0 0
2 0 98
0 61 128.00 1 0.12 16.00 196 3.06 0 0
1 0 98
tty amrd0 amrd1 cpu
tin tout KB/t tps MB/s KB/t tps MB/s us ni
sy in id
0 61 128.00 1 0.12 16.00 207 3.23 1 0
1 0 98
0 181 115.33 24 2.70 16.00 201 3.14 4 0
2 1 93
0 61 127.59 270 33.61 16.00 212 3.31 11
0 8 1 80
0 61 127.59 273 33.98 16.00 195 3.04 14
0 10 1 76
0 61 127.60 277 34.48 16.00 204 3.18 10
0 5 1 84
0 61 127.61 284 35.36 16.00 186 2.90 11
0 8 1 81
0 61 125.17 277 33.83 16.96 292 4.83 14
0 6 2 77
0 61 121.29 236 27.92 16.00 199 3.11 10
0 6 1 83
0 61 124.35 275 33.45 16.00 203 3.17 15
0 7 1 77
0 61 127.61 288 35.85 16.00 210 3.28 11
0 10 1 78
0 61 127.62 293 36.48 16.00 196 3.06 13
0 10 0 77
0 61 127.60 281 34.98 16.00 193 3.01 12
0 4 1 83
0 61 123.93 275 33.25 16.00 186 2.90 8
0 8 1 83
0 61 62.16 347 21.04 16.54 207 3.34 8 0
7 1 84
0 60 42.90 458 19.17 16.00 322 5.03 5 0
8 1 86
0 60 94.28 349 32.10 16.00 613 9.58 18
0 10 1 71
0 60 102.89 339 34.03 16.00 579 9.05 11
0 7 2 79
0 61 72.71 281 19.93 16.36 267 4.26 4
0 6 0 90
0 60 57.67 172 9.68 16.00 233 3.64 1 0
4 0 94
0 60 89.53 230 20.09 16.00 369 5.76 5 0
5 1 89
tty amrd0 amrd1 cpu
tin tout KB/t tps MB/s KB/t tps MB/s us ni
sy in id
0 60 124.43 269 32.65 16.29 392 6.23 14
0 8 2 77
0 181 83.54 190 15.48 15.92 208 3.23 12
0 6 1 82
0 60 119.50 258 30.08 16.00 193 3.01 9
0 7 1 83
0 61 127.10 250 31.00 16.00 207 3.23 9
0 4 1 85
0 61 94.78 256 23.67 16.00 210 3.28 8 0
6 1 85
0 60 122.18 272 32.42 16.00 195 3.04 11
0 6 1 82
0 61 119.90 318 37.20 16.00 206 3.22 8
0 6 3 83
0 61 118.08 283 32.60 16.00 202 3.15 13
0 10 2 75
0 61 126.32 276 34.01 16.00 212 3.31 12
0 5 1 82
0 61 127.61 288 35.85 16.00 214 3.34 11
0 8 2 80
0 61 119.34 293 34.11 19.06 204 3.79 9
0 9 1 81
0 61 84.88 346 28.65 16.00 200 3.12 9 0
6 1 84
0 60 63.20 362 22.32 16.00 210 3.28 3 0
5 1 92
0 60 61.16 491 29.30 16.00 274 4.28 9 0
6 1 84
0 60 77.58 185 14.00 16.00 293 4.57 16
0 6 1 77
0 60 46.86 7 0.32 16.00 299 4.67 1 0
2 0 97
0 60 128.00 1 0.12 16.00 360 5.62 1 0
2 0 97
0 61 128.00 2 0.25 16.16 443 6.99 0 0
5 1 94
0 61 72.00 2 0.14 16.00 499 7.79 1 0
4 0 94
0 60 19.56 72 1.37 16.04 455 7.12 4 0
3 1 92
tty amrd0 amrd1 cpu
tin tout KB/t tps MB/s KB/t tps MB/s us ni
sy in id
0 60 51.10 31 1.55 17.21 435 7.30 11 0
5 1 82
0 180 119.04 275 31.94 16.25 475 7.53 22
0 11 2 65
0 61 118.89 246 28.53 16.00 452 7.06 19
0 11 2 67
0 61 73.04 315 22.45 16.00 440 6.87 5 0
8 2 85
0 60 32.98 65 2.09 16.00 376 5.87 6 0
5 0 89
0 60 28.95 61 1.72 16.00 248 3.87 7 0
6 1 86
0 60 100.00 4 0.39 16.00 228 3.56 2 0
1 0 96
0 61 128.00 1 0.12 16.00 246 3.84 0 0
1 0 98
0 61 128.00 2 0.25 16.00 255 3.98 0 0
3 0 96
0 61 128.00 2 0.25 16.00 289 4.51 0 0
1 0 98
0 61 128.00 1 0.12 16.00 282 4.40 4 0
2 0 94
0 61 34.67 6 0.20 15.98 366 5.71 4 0
4 0 92
0 60 49.67 6 0.29 16.00 314 4.90 4 0
2 0 94
0 60 128.00 1 0.12 16.00 331 5.17 0 0
3 0 97
0 61 19.28 134 2.52 16.00 356 5.56 2 0
6 0 93
0 60 17.07 434 7.23 16.00 225 3.51 0 0
3 0 96
0 60 19.59 511 9.79 16.00 246 3.84 5 0
3 2 90

--
Vlad