Re: intermittent long "log file sync" waits

From: Cary Millsap <cary.millsap_at_method-r.com>
Date: Tue, 28 Jan 2020 15:03:50 -0600
Message-ID: <CAJOkrQbKW8k=j8AoTO9SwYPqSjuhJYW3-HPxvLdv7ZmODhJVDw_at_mail.gmail.com>



And Chris, MRPROF-ERROR-0004 is a known bug in Workbench 8.1.2.1 that is fixed in 9.0. If you'd like to send me your trace file directly, I'll be happy to profile it for you with 9.0.

Cary Millsap
Method R Corporation
Author of *Optimizing Oracle Performance <http://amzn.to/OM0q75>* and *The Method R Guide to Mastering Oracle Trace Data, 3rd edition <https://amzn.to/2IhhCG6+-+Millsap+2019.+Mastering+Oracle+Trace+Data+3ed>*

On Tue, Jan 28, 2020 at 2:59 PM Stefan Koehler <contact_at_soocs.de> wrote:

> 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
>
>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Tue Jan 28 2020 - 22:03:50 CET

Original text of this message