Re: Higher Read response in 19C

From: Lok P <loknath.73_at_gmail.com>
Date: Sun, 18 Sep 2022 22:05:00 +0530
Message-ID: <CAKna9Va0Vh-dGS=cGsxhtnFcS2Rfxe8_D-smYXoDGEAUbd4aaw_at_mail.gmail.com>



Below is another execution of same query for today and it is comparatively faster i.e ~7hrs vs ~12hrs before. From the details of the sql monitoring plan, It seems solely depends on temp response time.

https://gist.github.com/oracle9999/67567624aedb6e26e4796b472c66fdf6

In case of slow execution for the same plan line id- 1 i.e hash join outer its read ~780 GB with 2 million read request i.e. ~400 KB per request whereas in case of comparatively faster run i.e the one which took 7 hrs, it has read around same ~780 bytes with just ~806K requests i.e ~1MB per request. So it seems when the small reads are when the execution is severely impacted. But the question i was trying to understand is , is why just now it started doing so much higher small reads or is it that we are noticing now because the small reads response has now gone slower as compare to before 19C period?

Not sure if it will help in understanding the reason behind the slow small read response, but i am thinking, I will try to capture the details from v$sessstat during run time for this query.

On Sun, Sep 18, 2022 at 6:24 PM Lok P <loknath.73_at_gmail.com> wrote:

> Also Pap, if I see the tempfile read section between two periods 11g time
> vs 19c times as below for the same node. It's showing mainly it's the
> "small read" whose response gets degraded significantly. In the case of
> 11.2 it was ~2milli sec but in 19c it's 17ms.
>
> In our case we consider the last query for which I posted the sqlmonitor ,
> it's the step "HASH JOIN OUTER '' where significant "direct path read temp"
> samples are shown up. My understanding was "direct path" means large reads
> i.e >128KB chunks, so not sure how here it will be impacted by those "small
> read" slowness stuff of the temp file read.
>
> And again it seems to be now the majority of "small reads" component for
> "direct path read temp" is served from a hard disk as opposed to flash disk
> and thus the response time is going~17ms vs <~5ms before where it must be
> served from fully flash cache. Correct me if my understanding is wrong.
>
>
> IOStat by File Type
> 19c Requests MB Service Time
> I# Filetype Name Total IOs/s Reads/s Writes/s Total IO MB/s Read MB/s Write
> MB/s Small Read Large Read
> 2 Total 194,604,795 18,019.22 13,203.53 4,815.70 25,437,297 2,355.34
> 2,027.45 327.89 91.43us 1399.66ms
> 2 Data File 183,509,994 16,991.91 12,923.20 4,068.71 21,951,854 2,032.61
> 1,912.22 120.39 57.62us 1506.23ms
> 2 Log File 7,537,883 697.96 96.52 601.45 2,417,419 223.84 96.29 127.55
> .96ms 39.33ms
> 2 Archive Log 689,976 63.89 0 63.89 689,951 63.89 0 63.89
> 2 Temp File 1,730,049 160.19 84.93 75.26 357,563 33.11 17.14 15.97 17.23ms
> 30.10ms
> 2 Control File 1,128,445 104.49 98.09 6.4 20,479 1.9 1.8 0.1 15.32us
> 361.76us
> 2 Other 8,448 0.78 0.78 0 31 0 0 0 767.76us
>
>
> 11g
> Requests MB Service Time
> I# Filetype Name Total IOs/s Reads/s Writes/s Total IO MB/s Read MB/s Write
> MB/s Small Read Large Read
> 2 Total 130,816,242 12,131.68 9,273.38 2,858.30 20,989,589 1,946.54
> 1,709.79 236.75 404.68us 1193.65ms
> 2 Data File 110,570,510 10,254.12 8,337.68 1,916.44 17,611,625 1,633.27
> 1,555.92 77.35 294.11us 1254.38ms
> 2 Log File 7,982,178 740.25 56.74 683.51 1,548,956 143.65 56.62 87.02
> 4.38ms 65.56ms
> 2 Temp File 10,699,412 992.25 783.52 208.73 1,330,729 123.41 95.36 28.05
> 1.40ms 51.88ms
> 2 Archive Log 478,642 44.39 0.15 44.24 478,625 44.39 0.15 44.24 19.00ms
> 109.18ms
> 2 Control File 1,077,100 99.89 94.51 5.38 19,624 1.82 1.74 0.08 253.34us
> 3.07ms
> 2 Other 8,400 0.78 0.78 0 30 0 0 0 2.08ms
>
> On Sun, Sep 18, 2022 at 5:44 PM Lok P <loknath.73_at_gmail.com> wrote:
>
>> Thank You.
>>
>> I see DBA_HIST_TEMPSTATXS is blank post migration to 19C not sure why.
>> This is having the sample populated during 11.2 period snaps though.
>>
>> In below GIT link , i have put the sql monitor of the sample query which
>> is spending ~95%+of the time in the "direct path read temp" and runs for 10
>> hrs+. this used to finish in 2-3 hrs during 11.2 version. I don't have any
>> sql monitor from 11.2 period though. Note- I replaced the actual table and
>> column names by dummy names.
>>
>> https://gist.github.com/oracle9999/57438885f995c3cadde7005b989496a0
>>
>>
>>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Sun Sep 18 2022 - 18:35:00 CEST

Original text of this message