Thank you Tanel. I tried using devent_hist script for those two different
~15minutes durations (i.e. slow vs fast) without putting any filter on the
event and attached the output. I see in the slow period a lot of
back related waits though and also if I see "cell multiblock physical
read"around ~60% of the time it was showing the response time >60milli sec.
So it does show that in that slow period "cell multiblock physical read"
was impacted. Db file parallel write was also shooting till ~512milli
milliseconds.
Now as it seems quite appealing that backup caused the pressure on storage
and thus decrease in response time of the IO requests. And also Mladen
pointed out some backup which may not be the regular DB incremental backup
though because I don't see(from v$rmana_backup_job_details) that DB RMAN
incremental running during that point in time. And that backup is something
related to the ASM file system related backup, so where can i confirm that
exact backup was started and thus we impacted? And i have not heard of Veam
backup in the past though, So is that Veam is filesystem backup but not DB
backup?
Regards
Pap
On Fri, Apr 2, 2021 at 10:24 PM Tanel Poder <tanel@xxxxxxxxxxxxxx> wrote:
If you see the time waited for IOs go up, but you're not trying to do more
I/O (same amount of data & workload and exec plans haven't changed), you
can report the individual I/O latencies to see if your I/O is just slower
this time (due to other activity in the storage subsystem).
You can even estimate wait event counts in different latency buckets using
ASH data (more granularity and flexibility compared to AWR).
https://github.com/tanelpoder/tpt-oracle/blob/master/ash/devent_hist.sql
SQL> @ash/*devent_hist* db.file.*read 1=1 "TIMESTAMP'2020-12-10
00:00:00'" "TIMESTAMP'2020-12-10 23:00:00'"
Wait time Num ASH Estimated
Estimated % Event Estimated
Wait Event bucket ms+ Samples Total Waits
Total Sec Time Time Graph
---------------------------- --------------- ---------- -----------
------------ ---------- ------------
db file parallel read < 1 7 31592.4
315.9 8.1 |# |
< 2 6 4044.5
80.9 2.1 | |
< 4 5 1878.6
75.1 1.9 | |
< 8 9 1407.2
112.6 2.9 | |
< 16 19 1572.1
251.5 6.5 |# |
< 32 36 1607.3
514.3 13.2 |# |
< 64 35 809.8
518.3 13.3 |# |
< 128 52 530.8
679.5 17.5 |## |
< 256 44 284.6
728.7 18.7 |## |
< 512 28 88
450.7 11.6 |# |
< 1024 2 3.7
38.1 1 | |
< 4096 1 1
41.0 1.1 | |
< 8192 1 1
81.9 2.1 | |
db file scattered read < 1 4 17209.3
172.1 71.1 |####### |
< 2 1 935.5
18.7 7.7 |# |
< 4 3 1021
40.8 16.9 |## |
< 8 1 131.7
10.5 4.3 | |
db file sequential read < 1 276 1354178.7
13,541.8 7.7 |# |
< 2 221 150962.7
3,019.3 1.7 | |
< 4 515 174345.3
6,973.8 4 | |
< 8 1453 250309.8
20,024.8 11.4 |# |
< 16 1974 181327.4
29,012.4 16.6 |## |
< 32 2302 101718.4
32,549.9 18.6 |## |
< 64 2122 49502.4
31,681.5 18.1 |## |
< 128 1068 12998.8
16,638.4 9.5 |# |
< 256 312 1855.9
4,751.1 2.7 | |
< 512 260 763.7
3,909.9 2.2 | |
< 1024 13 24.7
253.2 .1 | |
< 4096 59 59
2,416.6 1.4 | |
< 8192 127 127
10,403.8 5.9 |# |
This way, any potential latency outliers won't get hidden in averages.
--
Tanel Poder
#vConf2021: Troubleshooting Very Complex Oracle Performance Problems
https://tanelpoder.com/conference/
On Fri, Apr 2, 2021 at 2:28 AM Pap <oracle.developer35@xxxxxxxxx> wrote:
Thank you.
Attached is the DASH output for both the period.I do see more activity
during slow periods. But is this confirming that , because of some other
factor impacting overall database read activity during slow periods, how to
get that?
Actually in the sql monitor(which i posted in the initial thread) it
shows the fast execution period was able to perform ~67GB bytes read in
~10minutes whereas during slow execution period, the same ~67GB took
~30minutes. So wanted to understand how can i find the root cause of the
slowness here?
Regards
Pap
On Thu, Apr 1, 2021 at 11:26 PM Laurentiu Oprea <
laurentiu.oprea06@xxxxxxxxx> wrote:
Indeed looks like it is all related with storage response time.
Just to have some fun you can post the ash numbers:
sql> @dashtop program2,event2 1=1 "TIMESTAMP'2021-03-30 22:16:57'"
"TIMESTAMP'2021-03-30 22:30:07'"
sql> @dashtop program2,event2 1=1 "TIMESTAMP'2021-03-31 22:16:57'"
"TIMESTAMP'2021-03-31 22:30:07'"
https://github.com/tanelpoder/tpt-oracle/blob/master/ash/dashtop.sql
Attachment:
Devent_hist_output.xlsx
Description: application/vnd.openxmlformats-officedocument.spreadsheetml.sheet
