Re: intermittent long "log file sync" waits

From: Stefan Koehler <contact_at_soocs.de>
Date: Tue, 28 Jan 2020 21:57:39 +0100 (CET)
Message-ID: <49234795.116532.1580245059893_at_ox.hosteurope.de>


Hello Chris,
it seems like it is accounted as "MRPROF-ERROR-0004" in the Method-R report.

Can you possibly send the raw trace file as a compressed file? :)

Thanks.

Best Regards
Stefan Koehler

Independent Oracle performance consultant and researcher Website: http://www.soocs.de
Twitter: _at_OracleSK

> Chris Stephens <cstephens16_at_gmail.com> hat am 28. Januar 2020 um 21:49 geschrieben:
>
> 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'
> 'PGA memory operation'
> '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-l
Received on Tue Jan 28 2020 - 21:57:39 CET

Original text of this message