Re: intermittent long "log file sync" waits

  • From: Stefan Koehler <contact@xxxxxxxx>
  • To: Chris Stephens <cstephens16@xxxxxxxxx>
  • Date: Tue, 28 Jan 2020 21:57:39 +0100 (CET)

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: @OracleSK

Chris Stephens <cstephens16@xxxxxxxxx> 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.
--
//www.freelists.org/webpage/oracle-l


Other related posts: