Mohamed Houri’s Oracle Notes

November 12, 2013

Log file sync and user commits

Filed under: Oracle — hourim @ 10:50 am

This is a brief note to demonstrate from where a difference between the number of log file sync wait event and user commits might come. Very recently I have been pointed out in an otn thread that my AWR report contains inconsistent numbers of log file sync and user commits as shown below:

Top 5 Timed Foreground Events

Event Waits Time(s) Avg wait (ms) % DB time Wait Class
db file sequential read 1,234,292 6,736 5 44.97 User I/O
DB CPU 5,251 35.05
log file sync 83,846 1,594 19 10.64 Commit
log file switch completion 1,256 372 296 2.48 Configuration
enq: TX – index contention 19,327 310 16 2.07 Concurrency

In this 60 minutes AWR report I have 83,846 log file sync waits suggesting 23 commits per second (83,846/3600)

Instance Activity Stats

Statistic Total per Second per Trans
user commits 701,112 193.72 0.8

But why the Instance Activity Stats part of the same report is showing 193 user commits per second? From where this discrepancy is coming from?

Well, I have been given a clue also in the same otn thread which I have tested and which I am reporting here in this article

SQL> create table t (n1 number);

SQL> start c:\commits#

NAME                        VALUE
--------------------------- -----
user commits                 5

SQL> start c:\events#

EVENT                      TOTAL_WAITS
-------------------------- -----------
log file sync               5

In the next simple PL/SQL anonymous block I am inserting into a for loop and committing outside the loop only one time

 SQL>  BEGIN
          FOR j in 1..10 LOOP
             insert into t values(j);
          END LOOP;
        commit;
      END;
     /

 PL/SQL procedure successfully completed.
 

If I check now the log file sync and user commits numbers I will see that the figures have been both incremented once and hence are in perfect synchronisation

SQL> start c:\commits#

NAME                VALUE
------------------- ------
user commits        6

SQL> start c:\events#

EVENT                TOTAL_WAITS
-------------------- -----------
log file sync        6

However, if I commit inside the loop (you shouldn’t commit across fetch by the way, this is not a recommended PL/SQL habit) the figures start their deviation.

 SQL> BEGIN
      FOR j in 1..10 LOOP
       INSERT INTO T VALUES(J);
       commit;
      END LOOP;
 END;
 /

PL/SQL procedure successfully completed.

 

SQL> start c:\commits#

NAME                    VALUE
----------------------- ----------
user commits             16   --> old value was 6

SQL> start c:\events#

EVENT                    TOTAL_WAITS
------------------------ -----------
log file sync             7  --> old value was 6

And here where the discrepancy starts. I have an extra 10 user commits while my log file sync wait event underwent a single wait increment. This is a PL/SQL feature which seems to increment the log file sync per PL/SQL block call and not per user commit call.

Bottom line: you have better to worry about your log file sync figures instead of your user commits value when these two values do not match

In case you want to play with this example then I’ve attached here below the commits# and events# sql files respectively

select b.name, a.value
from
v$mystat a,v$statname b
where
a.statistic# = b.statistic#
and b.name = 'user commits';

--

select a.event, a.total_waits
from
 v$session_event a
,v$event_name b
where
a.event = b.name
and  b.name = 'log file sync'
and  a.sid = 578 -- adapt with your sid
;

5 Comments »

  1. Hi Mohamed!

    I was investigating a log file sync event in my DB, and it’s being hard to find the root cause of it.

    At first, I was looking for sessions with high commits numbers… but, after reading this post, I’m not sure if that’s the correct strategy for getting into what’s causing the issue.

    For example, there’s a SID with 269.259 commits within 7 minutes, and only 54 log file sync waits for that sid.
    On the other hand, I can see a SID with 122049 commits and 122049 log file sync waits.

    My problem is: how to say which session / program is responsible for the increase of log file sync waits? I mean, should the session with most log file sync waits be responsable for it, or this is a consequence from another session?

    In other words: when you have a lots of sessions suffering from log file sync waits, how can you say which session(s) is causing the problem, and which session is suffering the consequences of it?

    tks!

    Fabricio

    Comment by fabriciouerj — December 4, 2015 @ 6:32 pm | Reply

    • Hello Fabricio

      I am sorry for this delay, I read your comment in my smartphone and then forget to answer you when being at work

      As per regards to your log file sync issue I would strongly recommend using ASH. Something like this

      SQL> select session_id, count(1)
        2  from gv$active_session_history
        3  where sample_time between to_date('01122015 18:00:00', 'ddmmyyyy hh24:mi:ss')
        4                     and    to_date('12122015 19:00:00', 'ddmmyyyy hh24:mi:ss')
        5  and event in ('log file sync', 'log file parallel write')
        6  group by  session_id
        7  order by 2 desc;
      
      SESSION_ID   COUNT(1)
      ---------- ----------
             121         20
             358         17
             240          6
             130          1
             124          1
             366          1
             123          1
             249          1
      

      And then analyse the TOP sessions. Generally a commit action has a NULL SQL_ID in ASH but try to see the TOP_LEVEL_SQL_ID which is fairly likely going to be NULL in this case as well But I would definitely investigate this problem using ASH.

      A high number of commits is one of the reasons that might introduce a log file sync wait events. But sometimes it is the LGWR which when posted to flush the redo into the disk (following a commit) starts waiting on the log file parallel write which is the event that write the redo into the disk

      Best regards
      Mohamed

      Comment by hourim — December 12, 2015 @ 6:42 pm | Reply

      • Hi Mohamed, thanks for replying.
        Best Regards,
        Fabricio

        Comment by fabriciouerj — January 18, 2016 @ 11:11 pm

  2. What will be the solutions when the commits are high?

    Comment by venky — December 9, 2015 @ 10:59 am | Reply

    • Venky,

      Generally you should commit only when necessary and never across fetch (inside the loop). So if possible then reduce the commit frequency.If not, look carefully to the size and number of the on line redo log files so that you will not be confronted to a high number of redo log switches as well.I don’t know exactly what to recommend you rather then reducing the frequency of commit if your application is committing very often

      Best regards

      Comment by hourim — December 12, 2015 @ 6:49 pm | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Create a free website or blog at WordPress.com.

Tony's Oracle Tips

Tony Hasler's light hearted approach to learning about Oracle

Richard Foote's Oracle Blog

Focusing Specifically On Oracle Indexes, Database Administration and Some Great Music

Hatem Mahmoud Oracle's blog

Just another Oracle blog : Database topics and techniques

Mohamed Houri’s Oracle Notes

Qui se conçoit bien s’énonce clairement

Oracle Diagnostician

Performance troubleshooting as exact science

Raheel's Blog

Things I have learnt as Oracle DBA

Coskan's Approach to Oracle

What I learned about Oracle

So Many Oracle Manuals, So Little Time

“Books to the ceiling, Books to the sky, My pile of books is a mile high. How I love them! How I need them! I'll have a long beard by the time I read them”—Lobel, Arnold. Whiskers and Rhymes. William Morrow & Co, 1988.

EU Careers info

Your career in the European Union

Carlos Sierra's Tools and Tips

Tools and Tips for Oracle Performance and SQL Tuning

Oracle Scratchpad

Just another Oracle weblog

OraStory

Dominic Brooks on Oracle Performance, Tuning, Data Quality & Sensible Design ... (Now with added Sets Appeal)

%d bloggers like this: