With such a frequent query disk i/o should not be a subject at all; it might occur with very first execution, but then never again, and the fact that it executed this many times over two hours probably only confirms this. So you don't have an i/o problem, at least not with this query, never.
Now, if one execution (or some) of this query take longer than most others, that can still happen, but likely not due to disk i/o.
Looking at this query, it is so straight forward and simple that I hardly could think of anything it might have to wait on, esp. if it is going by an index.
Any chance the data is skewed and some values for those three parameters would have to go through and return an extra large amount of data?
There also could be a remote chance of an index not cleaned properly and, maybe in certain areas only, bloated to a degree that it causes a performance problem?
How big a table are we talking about? How big is the index this query relies on (per oncheck -pt), and how fresh is the index?
Just another few cents ...
------------------------------
Andreas Legner
------------------------------
Original Message:
Sent: Fri October 14, 2022 09:35 AM
From: John Smith
Subject: IO WAIT
Hi
thanks for your reply :)
No i wanted to say Sample not example, sorry :), it is a real query, ran more than 47000 times in a 2 hours intervals, and 2 sec was the max runtime..
the execution plan is good and already using a index
the checkpoint are good
The kaio_reads/kaio_writes are fair, and not slow enough to indicate a failing device. => OK
It would be better to use onstat -g ioh to review the recent IO while running the query several times. => not available , 11.70, i know, upgrading is in the pipe :)
Also use onstat -g iov to see io/s per VP and io per wakeup.
==>
AIO I/O vps:
class/vp/id s io/s totalops dskread dskwrite dskcopy wakeups io/wup errors tempops
fifo 7 0 i 0.0 0 0 0 0 0 0.0 0 0
kio -1 0 i 762.7 15055893 14967031 88862 0 10541566 1.4 0 0
kio -1 1 i 677.2 13366528 13287533 78995 0 9308721 1.4 0 0
kio -1 2 i 633.7 12509153 12432752 76401 0 8470272 1.5 0 0
kio -1 3 i 830.6 16395165 16304576 90589 0 11533614 1.4 0 0
kio -1 4 i 649.2 12813793 12740166 73627 0 8705593 1.5 0 0
kio -1 5 i 655.5 12939753 12862025 77728 0 8756982 1.5 0 0
kio -1 6 i 515.0 10166417 10092066 74351 0 6440892 1.6 0 0
kio -1 7 i 723.8 14287930 14207722 80208 0 9894157 1.4 0 0
kio -1 8 i 497.6 9823078 9751387 71691 0 6171592 1.6 0 0
kio -1 9 i 606.0 11961931 11884235 77696 0 7913544 1.5 0 0
kio -1 10 i 544.6 10750719 10683320 67399 0 6971057 1.5 0 0
kio -1 11 i 339.3 6697720 6646076 51644 0 3854125 1.7 0 0
kio -1 12 i 396.7 7831247 7772254 58993 0 4646074 1.7 0 0
kio -1 13 i 340.3 6717816 6657758 60058 0 3943763 1.7 0 0
kio -1 14 i 553.0 10916102 10839295 76807 0 7049523 1.5 0 0
kio -1 15 i 293.1 5785159 5722695 62464 0 3253776 1.8 0 0
kio -1 16 i 436.2 8611011 8548977 62034 0 5201195 1.7 0 0
kio -1 17 i 392.6 7749044 7679118 69926 0 4581861 1.7 0 0
kio -1 18 i 537.3 10606624 10536035 70589 0 6633993 1.6 0 0
kio -1 19 i 515.6 10176536 10106638 69898 0 6267016 1.6 0 0
msc 6 0 i 4.6 91441 0 0 0 90498 1.0 0 2323503
aio 5 0 i 59.7 1178857 724749 70237 0 965543 1.2 0 9765
aio 27 1 i 12.8 253496 232102 5222 0 121332 2.1 0 732
aio 28 2 i 11.5 227851 222372 1124 0 67090 3.4 0 469
aio 29 3 i 10.3 202888 200632 601 0 56836 3.6 0 406
aio 30 4 i 10.3 203106 201597 299 0 52333 3.9 0 369
aio 31 5 i 10.2 200798 199798 151 0 49189 4.1 0 406
aio 32 6 i 9.9 195738 194887 76 0 47471 4.1 0 360
aio 33 7 i 9.6 189731 188639 278 0 46035 4.1 0 360
aio 34 8 i 9.0 178278 176784 57 0 34140 5.2 0 293
aio 35 9 i 8.8 174519 173885 33 0 30072 5.8 0 282
pio 4 0 i 0.0 0 0 0 0 0 0.0 0 0
lio 3 0 i 0.0 0 0 0 0 0 0.0 0 0
Processor Type: PowerPC_POWER8
Processor Implementation Mode: POWER 7
SMT4
------------------------------
John Smith
Original Message:
Sent: Fri October 14, 2022 08:26 AM
From: Mike Walker
Subject: IO WAIT
Is that the real query or just an example? You may not be able to review the one query in isolation, as there may be more going on to stretch out your execution time to 12 seconds. Get an explain plan and look at the query statistics at the end to see if this was using the expected index, rows returned, etc, but also the real timing. Is the 12 second runtime something that you have actually observed in the real world for this ONE query, or are you just looking at the sql trace
How are your checkpoints looking? Are you seeing a lot of long checkpoints that might indicate an IO issue?
The kaio_reads/kaio_writes are fair, and not slow enough to indicate a failing device. It would be better to use onstat -g ioh to review the recent IO while running the query several times. Also use onstat -g iov to see io/s per VP and io per wakeup. You should be looking at whether your individual cores (not overall CPU) are not running close to 100%, as there may not be enough horsepower left to perform timely IO operations. What SMT level are you using, and what CPU type?
IO Waits are a normal part of a busy system, but it's always fun to keep an eye on whether there are many threads waiting on IO overall. onstat -g ath | grep "IO"
Of course, the SAN can be an issue, and if anything else is sharing the disk, then that can give intermittent problems.
But don't just focus on IO...there may be more at play here if you really are seeing such a long runtime for a simple query that I assume doesn't return many records.
------------------------------
Mike Walker
xDB Systems, Inc
www.xdbsystems.com
Original Message:
Sent: Fri October 14, 2022 07:52 AM
From: John Smith
Subject: IO WAIT
Hello
Traced some sql statements and noticed some iowaits, i checked io on chunk (-g iof) but needed also any feedbacks about analysing io wait please
this example is useful to understand my case, runtime in 2 sec, but totaltime 12 sec, no locks, no sorts ...nothing but io waits
see also below iof output (it s about raw devices with KAIO activated on a AIX LPAR)
sql_id 0
sql_sid 1238153
sql_uid 1234
sql_runtime 2,081772664059
sql_lockreq 667
sql_lockwaits 0
sql_lockwttime 0,00
sql_logspace 0
sql_sorttotal 0
sql_sortdisk 0
sql_sortmem 0
sql_executions 47501
sql_totaltime 12,99474855827 =====================> totaltime 13 seconds
sql_numiowaits 115 ===================================> 115 iowaits
sql_avgiowaits 0,001369563858
sql_totaliowaits 0,157499843667
sql_sqlerror 0
sql_isamerror 0
sql_isollevel 7
sql_statement SELECT table.* FROM table WHERE Table.col1 = ? AND table.col2 = ? AND table.col3 = ?
sql_pdq 0
data_chk1 463028224 113044 5292032 1292 471.1
op type count avg. time
seeks 0 N/A
reads 0 N/A
writes 0 N/A
kaio_reads 6044 0.0012
kaio_writes 1059 0.0076
------------------------------
John Smith
------------------------------
#Informix