Re: Slow running Delete query for same data volume

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_at_tanelpoder.com> 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> _at_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_at_gmail.com> 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_at_gmail.com> wrote:
>>
>>> Indeed looks like it is all related with storage response time.
>>>
>>> Just to have some fun you can post the ash numbers:
>>>
>>> sql> _at_dashtop program2,event2 1=1 "TIMESTAMP'2021-03-30 22:16:57'"
>>> "TIMESTAMP'2021-03-30 22:30:07'"
>>> sql> _at_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
>>>
>>>
>>>>

--
http://www.freelists.org/webpage/oracle-l





application/vnd.openxmlformats-officedocument.spreadsheetml.sheet attachment: Devent_hist_output.xlsx