Some guidance on tuning a slow query please
Posted in 2007
We have a query that takes a long time when the system get's busy. It used to take about 20-30 seconds all the time. I added buffers and now it only takes about 3-4 seconds, until we get busy, then it goes up to 30 seconds again.
The query is ugly, and makes use of a view that is very ugly. The view joins 11 tables, the biggest of which is about 800,000 rows, and is forced to be scanned, due to the nature of the view. I don't see putting an index on it, since we need all the rows. That is the recipient table.
From the stats, I was thinking of maybe fragmenting the recipient table even though it has less than a million rows in it. But I don't know if I would get the parallel scanning unless we use pdq ( we are on version IDS10.0.FC5 ).
Also, our san is raided ( 1+0 ) and plaided, so I really don't know where the data is, as it's scattered all over the disk. I really think this has to do with buffer waits. How do I decrease those ?
At this point, I would rather check out if there is anything to do to fix this other than having to rewrite the query and the view. It seems there may be some tuning on the engine and some data management that could solve this problem. But I would appreciate any advice.
Thank You,
Floyd
The statistics are up to date, no errors in the onchecks. I've compiled some stats that I think may be pertinent, on this instance. It has only one processor.
onstat -g ppf sorted by READS in reverse ( first 3 tables.partnum lkrqs lkwts dlks touts isrd iswrt isrwt isdel bfrd bfwrt seqsc rhitratio
0x30000a 3599593208 18 0 0 3326501171 7364 85435 0 2935210660 96413 4733 100 recipient
0x200009 20606572 0 0 0 30390455 0 0 0 51594342 7208 0 100 to_order
0x600089 22357226 0 0 0 22351255 0 0 0 33531726 0 0 100 xmit_code
Huge number of lock requests, buffer reads and seq scans on the to_recipient table, which is the main table that is scanned in the view. All 3 of these highest read tables are in the query.
onstat -g ppf sorted by WRITES in reverse ( first 3 tables.partnum lkrqs lkwts dlks touts isrd iswrt isrwt isdel bfrd bfwrt seqsc rhitratio
0x60004e 9425624 0 0 0 129595 9204576 0 170 9578451 1017 13 99 sc_order_status
0x800002 1845084 0 0 0 48300 48300 0 48300 3880498 701630 0 99 email_queue
0x400009 159553 0 0 0 21592 35672 1 0 125286 37736 0 85 to_recpt_shist
The most written to table, sc_order_status, is in the to_dat dbpace, as you can see below, is the busiest dbspace, and contains many of the tables in the slow query.
Here is the output of Art's ratios.ksh It indicates a high BR.
ReadAhead Utilization (UR): 99.9976 %
Bufwaits Ratio(BR): 25.7176 %
hereiam
-n Average Buffer Turnover Rate (BTR):
5.7582/HR
Stats reset 98:23:32 ago.
onstat -g iofgfd pathname totalops dskread dskwrite io/s
17 /dev/wto_logs_c2 10 10 0 0.0
18 /dev/wto_tmp3_c1 57 51 6 0.0
16 /dev/wto_dts_c1 1006 824 182 0.0
9 /dev/wto_misc_c1 2422 2422 0 0.0
3 /dev/wto_root_c1 41190 28738 12452 0.1
14 /dev/wto_logs_c1 295379 31965 263414 0.8
5 wto_rcpnt_c1 39284 34557 4727 0.1
10 /dev/wto_jobs_c1 75034 47179 27855 0.2
6 /dev/wto_hist_c1 181041 159696 21345 0.5
4 wto_order_c1 237417 213440 23977 0.7
7 /dev/wto_pymt_c1 281422 259829 21593 0.8
13 wto_rcpnt_c2 363716 344930 18786 1.0
15 /dev/wto_tmp2_c1 663786 548090 115696 1.9
11 /dev/wto_tmp1_c1 697475 576276 121199 2.0
12 wto_order_c2 1677780 1663494 14286 4.8
8 wto_todat_c1 14496015 14459290 36725 41.3
The bolded table has the most I/O by far. Many of the tables in the scanned view are in that chunk.
onstat -g iov
AIO I/O vps:class/vp s io/s totalops dskread dskwrite dskcopy wakeups io/wup errors
kio 0 i 54.0 19063899 18381324 682575 0 35579615 0.5 0
msc 0 i 0.1 17853 0 0 0 17846 1.0 0
aio 0 i 0.1 35144 13156 20645 0 35142 1.0 0
aio 1 i 0.0 6 1 4 0 10 0.6 0
pio 0 i 0.0 0 0 0 0 1 0.0 0
lio 0 i 0.0 0 0 0 0 1 0.0 0
This reveals to me that there isn't a problem of needing another aio vp, because the amount of wakeups indicates it is idle most of the time, ( is that correct ) ?
an onstat -p
IBM Informix Dynamic Server Version 10.00.FC5 -- On-Line -- Up 4 days 02:05:28 -- 664400 KbytesProfile
dskreads pagreads bufreads %cached dskwrits pagwrits bufwrits %cached
65211041 68787288 7113803736 99.08 761824 5357382 3731764 84.94
isamtot open start read write rewrite delete commit rollbk
8714998731 7763839 82201427 5251912058 9819953 201710 61369 262414 0
gp_read gp_write gp_rewrt gp_del gp_alloc gp_free gp_curs
0 0 0 0 0 0 0
ovlock ovuserthread ovbuff usercpu syscpu numckpts flushes
0 0 0 -9944709.95 403311.80 1186 2374
bufwaits lokwaits lockreqs deadlks dltouts ckpwaits compress seqscans
18650439 288 4939055542 0 0 109 134558 218114
ixda-RA idx-RA da-RA RA-pgsused lchwaits
1823850 40 62568958 64391302 3296
Seems like a lot of buffer waits on the system. Read cache looks good but write cache seems a bit low. More buffers ??
onstat -g gloMT global info:
sessions threads vps lngspins
8 43 9 2
sched calls thread switches yield 0 yield n yield forever
total: 270748450 160558040 149888127 7285045 54695770
per sec: 0 0 0 0 0
Virtual processor summary:
class vps usercpu syscpu total
cpu 1 31080.26 754.91 31835.17
aio 2 15202761.77 62368.27 15265130.04
lio 1 15152457.52 112666.77 15265124.29
pio 1 15191607.16 73517.26 15265124.42
adm 1 15145184.20 119953.71 15265137.91
soc 2 15231541.18 34048.22 15265589.40
msc 1 4.99 3.06 8.05
total 9 75954637.08 403312.20 76357949.28
Individual virtual processors:
vp pid class usercpu syscpu total
1 78034 cpu 31080.26 754.91 31835.17
2 87032 adm 15145184.20 119953.71 15265137.91
3 192994 lio 15152457.52 112666.77 15265124.29
4 91108 pio 15191607.16 73517.26 15265124.42
5 197094 aio 15202759.97 62366.50 15265126.47
6 201192 msc 4.99 3.06 8.05
7 95210 aio 1.80 1.77 3.57
8 205292 soc 15231490.17 33896.59 15265386.76
9 99310 soc 51.01 151.63 202.64
tot 75954637.08 403312.20 76357949.28
========================
-<<Floyd Wellershaus>>-
Database Administrator
Unix Administrator
email: fwellers@yahoo.com
Home: 703-430-0805
Cell: 703-477-6045
========================
http://www.one.org/