Re: intermittent long "log file sync" waits
Date: Tue, 28 Jan 2020 21:57:39 +0100 (CET)
Message-ID: <49234795.116532.1580245059893_at_ox.hosteurope.de>
Hello Chris,
Can you possibly send the raw trace file as a compressed file? :)
Thanks.
Best Regards
Independent Oracle performance consultant and researcher
Website: http://www.soocs.de
> Chris Stephens <cstephens16_at_gmail.com> hat am 28. Januar 2020 um 21:49 geschrieben:
it seems like it is accounted as "MRPROF-ERROR-0004" in the Method-R report.
Stefan Koehler
Twitter: _at_OracleSK
>
> man, all the Heavy Weights from oracle-l! (Stefan/JL/Tim/Noveljic)
>
> I'm not exactly sure what is going on here. attached is method r report corresponding to call profile of trace file (log file sync doesn't show up prominently in report)
>
> Duration by call name
> mrskew "/Users/cs2018/no_keep/lsst2db2_ora_8486.trc"
> Run began 2020-01-28T14:44:09, lasted 3.435000 seconds
>
> input files:
> '/Users/cs2018/no_keep/lsst2db2_ora_8486.trc'
>
> where expression:
> ((1) and ($dep==$depmin)) and ($nam=~/(?^:(?i).+)/)
>
> group expression:
> $nam
>
> matched call names:
> 'CLOSE'
> 'DLM cross inst call completion'
> 'Disk file operations I/O'
> 'EXEC'
> 'FETCH'
> 'IPC group service call'
> 'KJC: Wait for msg sends to complete'
> 'PARSE'
> 'SQL*Net message from client'
> 'SQL*Net message to client'
> 'SQL*Net more data from client'
> 'XCTEND'
> 'enq: FB - contention'
> 'enq: TM - contention'
> 'enq: TS - contention'
> 'enq: TT - contention'
> 'gc current grant 2-way'
> 'gc current multi block request'
> 'ges resource directory to be unfrozen'
> 'index (re)build lock or pin object'
> 'library cache lock'
> 'library cache pin'
> 'log file sync'
> 'reliable message'
> 'row cache lock'
>
> CALL-NAME DURATION % CALLS MEAN MIN MAX
> ------------------------------ ---------- ------ ------ -------- -------- --------
> log file sync 79.291166 76.0% 150 0.528608 0.000264 2.986575
> SQL*Net message from client 22.090587 21.2% 9,886 0.002235 0.000216 7.900402
> EXEC 2.537643 2.4% 9,702 0.000262 0.000000 0.221403
> row cache lock 0.068551 0.1% 124 0.000553 0.000209 0.001036
> PARSE 0.056969 0.1% 4,778 0.000012 0.000000 0.001996
> FETCH 0.055241 0.1% 1,029 0.000054 0.000000 0.003969
> CLOSE 0.042863 0.0% 4,784 0.000009 0.000000 0.000180
> DLM cross inst call completion 0.030066 0.0% 211 0.000142 0.000005 0.000590
> library cache lock 0.024349 0.0% 61 0.000399 0.000160 0.000728
> library cache pin 0.019441 0.0% 48 0.000405 0.000157 0.000672
> 16 others 0.076164 0.1% 10,726 0.000007 0.000000 0.001792
> ------------------------------ ---------- ------ ------ -------- -------- --------
> TOTAL (26) 104.293040 100.0% 41,499 0.002513 0.000000 7.900402
>
>
> I will check on lgwr / scalable log writer mode.
-- http://www.freelists.org/webpage/oracle-lReceived on Tue Jan 28 2020 - 21:57:39 CET