14 Replies Latest reply: Nov 1, 2009 11:51 AM by 706417 RSS

    Wait Events "log file parallel write" / "log file sync" during CREATE INDEX

    538022
      Hello guys,
      at my current project i am performing some performance tests for oracle data guard. The question is "How does a LGWR SYNC transfer influences the system performance?"
      To get some performance values, that i can compare i just built up a normal oracle database in the first step.

      Now i am performing different tests like creating "large" indexes, massive parallel inserts/commits, etc. to get the bench mark.

      My database is an oracle 10.2.0.4 with multiplexed redo log files on AIX.

      I am creating an index on a "normal" table .. i execute "dbms_workload_repository.create_snapshot()" before and after the CREATE INDEX to get an equivalent timeframe for the AWR report.
      After the index is built up (round about 9 GB) i perform an awrrpt.sql to get the AWR report.

      And now take a look at these values from the AWR
                                                                         Avg
                                                   %Time  Total Wait    wait     Waits
      Event                                 Waits  -outs    Time (s)    (ms)      /txn
      ---------------------------- -------------- ------ ----------- ------- ---------
      ......
      ......
      log file parallel write              10,019     .0         132      13      33.5
      log file sync                           293     .7           4      15       1.0
      ......
      ......
      How can this be possible?

      Regarding to the documentation

      -> log file sync: http://download.oracle.com/docs/cd/B19306_01/server.102/b14237/waitevents003.htm#sthref3120
      Wait Time: The wait time includes the writing of the log buffer and the post.
      -> log file parallel write: http://download.oracle.com/docs/cd/B19306_01/server.102/b14237/waitevents003.htm#sthref3104
      Wait Time: Time it takes for the I/Os to complete. Even though redo records are written in parallel, the parallel write is not complete until the last I/O is on disk.
      This was also my understanding .. the "log file sync" wait time should be higher than the "log file parallel write" wait time, because of it includes the I/O and the response time to the user session.
      I could accept it, if the values are close to each other (maybe round about 1 second in total) .. but the different between 132 seconds and 4 seconds is too noticeable.

      Is the behavior of the log file sync/write different when performing a DDL like CREATE INDEX (maybe async .. like you can influence it with the initialization parameter COMMIT_WRITE??)?
      Do you have any idea how these values come about?


      Any thoughts/ideas are welcome.

      Thanks and Regards
        • 1. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
          Fahd.Mirza
          According to my understanding, "log file parallel write " depends upon how quickly OS completes all the IO requests to the disk. In other words, the actual wait time is the time taken for all the outstanding I/O requests to complete.

          And

          "log file sync " wait occurs because when sessions wait for redo data to be written to disk.

          Both of above waits occur, because may be the disk upon which the logs are, either slow or doing other work too.

          I would also be interested in knowing about coorelation between these two wait events.

          regards
          • 2. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
            Jonathan Lewis
            oraS wrote:

            I am creating an index on a "normal" table .. i execute "dbms_workload_repository.create_snapshot()" before and after the CREATE INDEX to get an equivalent timeframe for the AWR report.
            After the index is built up (round about 9 GB) i perform an awrrpt.sql to get the AWR report.

            And now take a look at these values from the AWR
            Avg
            %Time  Total Wait    wait     Waits
            Event                                 Waits  -outs    Time (s)    (ms)      /txn
            ---------------------------- -------------- ------ ----------- ------- ---------
            ......
            ......
            log file parallel write              10,019     .0         132      13      33.5
            log file sync                           293     .7           4      15       1.0
            ......
            ......
            How can this be possible?
            The logwriter can write even when you don't issue a commit - for example when there is one MB of redo outstanding in the buffer. If you build an index of about 9GB, it is not surprising that you cause about 10,000 log file writes of about 1MB each, which get written without a log file sync being issued.

            The 293 log file syncs probably come from other (background) activity and sys-recursive activity - and thy take about 15ms because they are trailing the larger writes that are constantly streaming out from your 9GB build.

            Regards
            Jonathan Lewis
            http://jonathanlewis.wordpress.com
            http://www.jlcomp.demon.co.uk

            To post code, statspack/AWR report, execution plans or trace files, start and end the section with the tag {noformat}
            {noformat} (lowercase, curly brackets, no spaces) so that the text appears in 
            fixed format
            .
            
            "Science is more than a body of knowledge; it is a way of thinking" 
            Carl Sagan                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                    
            • 3. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
              Fahd.Mirza
              Jonathan, very lucidly explained. Thanks. and yes Carl Sagan is always right
              • 4. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                Surachart Opun
                Thank you for Nice Idea.

                In this case, How can we reduce "log file parallel write" and "log file sync" waited time?
                CREATE INDEX with NOLOGGING
                A NOLOGGING can help, can't it?
                • 5. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                  Jonathan Lewis
                  Surachart Opun (HunterX) wrote:
                  Thank you for Nice Idea.

                  In this case, How can we reduce "log file parallel write" and "log file sync" waited time?
                  CREATE INDEX with NOLOGGING
                  A NOLOGGING can help, can't it?
                  Yes - if you create index nologging then you wouldn't be generating that 10GB of redo log, so the waits would disappear.

                  Two points on nologging, though:
                  <ul>
                  it's "only" an index, so you could always rebuild it in the event of media corruption, but if you had lots of indexes created nologging this might cause an unreasonable delay before the system was usable again - so you should decide on a fallback option, such as taking a new backup of the tablespace as soon as all the nologging operatons had completed.

                  If the database, or that tablespace, is in +"force logging"+ mode, the nologging will not work.
                  </ul>

                  Don't get too alarmed by the waits, though. My guess is that the +"log file sync"+ waits are mostly from other sessions, and since there aren't many of them the other sessions are probably not seeing a performance issue. The +"log file parallel write"+ waits are caused by your create index, but they are happeninng to lgwr in the background which is running concurrently with your session - so your session is not (directly) affected by them, so may not be seeing a performance issue.

                  The other sessions are seeing relatively high sync times because their log file syncs have to wait for one of the large writes that you have triggered to complete, and then the logwriter includes their (little) writes with your next (large) write.

                  There may be a performance impact, though, from the pure volume of I/O. Apart from the I/O to write the index you have LGWR writting (N copies) of the redo for the index and ARCH is reading and writing the completed log files caused by the index build. So the 9GB of index could easily be responsible for vastly more I/O than the initial 9GB.

                  Regards
                  Jonathan Lewis
                  http://jonathanlewis.wordpress.com
                  http://www.jlcomp.demon.co.uk

                  To post code, statspack/AWR report, execution plans or trace files, start and end the section with the tag {noformat}
                  {noformat} (lowercase, curly brackets, no spaces) so that the text appears in 
                  fixed format
                  .
                  
                  
                  "Science is more than a body of knowledge; it is a way of thinking" 
                  Carl Sagan                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
                  • 6. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                    Surachart Opun
                    Thank you for your idea with NOLOGGING.
                    ;)
                    • 7. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                      Uwehesse-Oracle
                      Since the OP is trying to configure a load to benchmark for Data Guard , NOLOGGING is not an option here - it would make your standby DB useless. Therefore, the primary will run with FORCE LOGGING, ignoring all NOLOGGING clauses specified - which is a very useful and recommended thing to do for a Data Guard configuration :-)

                      Kind regards
                      Uwe

                      http://uhesse.wordpress.com
                      • 8. Re: Wait Events "log file parallel write" / "log file sync" during CREATE I
                        Surachart Opun
                        Thank you for a Data Guard configuration recommend with NOLOGGING.
                        I'll aware with nologging :)
                        • 9. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                          Jonathan Lewis
                          Uwe Hesse wrote:

                          Since the OP is trying to configure a load to benchmark for Data Guard , NOLOGGING is not an option here - it would make your standby DB useless. Therefore, the primary will run with FORCE LOGGING, ignoring all NOLOGGING clauses specified - which is a very useful and recommended thing to do for a Data Guard configuration :-)
                          Uwe,

                          You're quite right to make the potential conflict of interest clear, but I don't think Dataguard precludes the nologging option - although it may not be seen as a valid approach for the purposes of the benchmarking.

                          <ul>
                          +"so you should decide on a fallback option, such as taking a new backup of the tablespace as soon as all the nologging operatons had completed."+
                          </ul>

                          Creating the index nologging shouldn't cause the dataguard mechanisms to fail - it just means the indexes are "corrupt" in the standby until a new copy of the tablespace overwrites the old copy. As for "force logging" - the OP could isolate indexes that he wanted to rebuild with nologging and put them in a separate tablespace and apply "force logging" selectively to tablespaces rather than applying it to the database as a whole.

                          Regards
                          Jonathan Lewis
                          http://jonathanlewis.wordpress.com
                          http://www.jlcomp.demon.co.uk

                          To post code, statspack/AWR report, execution plans or trace files, start and end the section with the tag {noformat}
                          {noformat} (lowercase, curly brackets, no spaces) so that the text appears in 
                          fixed format
                          .
                          
                          "Science is more than a body of knowledge; it is a way of thinking" 
                          Carl Sagan                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                            
                          • 10. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                            706417
                            "Carl Sagan is always right"

                            Indeed he was!

                            As Sagan so wisely remarked, "The speed of light is very fast". It takes a true genius to say something so profound ... so stunning ...

                            Just a jape! I loved Cosmos and remember fighting (often physically) with my siblings to watch re-runs of the show, as they preferred Top of the Pops.


                            Regards - Don Lewis
                            • 11. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                              jgarry
                              I liked the BBC series Connections.
                              • 12. Re: Wait Events "log file parallel write" / "log file sync" during CREATE I
                                Uwehesse-Oracle
                                >
                                Thank you for a Data Guard configuration recommend with NOLOGGING.
                                I'll aware with nologging :)
                                >

                                Maybe I wasn't clear enough in the previous posting: It is recommended to run the primary database of a data guard configuration in FORCE LOGGING mode. That will cause all NOLOGGING clauses, issued at the primary database, to be ignored. It therefore makes not much sense in my view, to setup a test load for a Data Guard configuration with any NOLOGGING statements in it, because these will have no effect later in the real environment

                                Kind regards
                                Uwe

                                http://uhesse.wordpress.com
                                • 13. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                                  Uwehesse-Oracle
                                  Jonathan,
                                  you are right: It is possible to avoid FORCE LOGGING on the primary in a Data Guard configuration and to issue effective NOLOGGING statements on it then. The standby will not fail, correct. It is "useless", though, in case of a failover, because the objects, created on the primary with NOLOGGING will be unusable then on the new primary (after the failover to the standby site). That is exactly why it is recommended to run the primary with FORCE LOGGING. Your arguments are technically correct, though.

                                  I only doubt that you will often see those approaches in reality. Especially,you won't see that in a highly sensitive environment, because it would bear the risk to get an (in part) unusable database after the failover, should the emergency case on the primary occurr right after the NOLOGGING operation - before the addition of the Index-Tablespace to the standby site. That would harm the level of high availability that was the reason to implement a standby database in the first place.

                                  Kind regards
                                  Uwe

                                  http://uhesse.wordpress.com
                                  • 14. Re: Wait Events "log file parallel write" / "log file sync" during CREATE INDEX
                                    706417
                                    James Burke, right?

                                    Remember when that probe approached Halley's comet (may have been another)? He got confused and said that the data it was feeding back was realtime - a 16-year old spod in the studio had to set him right by saying there was a few minutes' delay as it was so far away!

                                    Connections was good, though.