This discussion is archived
9 Replies Latest reply: Feb 26, 2013 9:12 AM by sb92075 RSS

Buffer busy waits on UNDO data in Active Dataguard

Yasu Newbie
Currently Being Moderated
By mistake i intially posted on Dataguard category, so posting again the same content here.

Oracle Version: 11.1.0.7.0
Active Dataguard
Statspack has been configured for Active Dataguard on Primary database.
Auto undo management enabled.

We got an spike of Buffer busy waits for about 5 min in Active Dataguard, this was causing worse Application SQL's response time during this 5 min window.
Snapshot       Snap Id     Snap Time      Sessions Curs/Sess Comment
---------    ---------- ------------------ -------- --------- -------------------
Begin Snap:      18611 21-Feb-13 22:00:02      236       2.2
  End Snap:      18613 21-Feb-13 23:00:02      237       2.1
   Elapsed:               60.00 (mins)


Top 5 Timed Events                                                    Avg %Total
------------------                                                   wait   Call
Event                                            Waits    Time (s)   (ms)   Time
----------------------------------------- ------------ ----------- ------ ------
buffer busy waits                                2,359       2,133    904   76.2
reliable message                                 7,210         179     25    6.4
parallel recovery control message reply          8,831         109     12    3.9
CPU time                                                       100           3.6
latch free                                          13          85   6574    3.1
          -------------------------------------------------------------
Above is what i got from statspack report for one hour.

Since this is 11g version I was able to drill down on the segment on which buffer busy waits were occurring by using v$active_session_history on Active Dataguard.
SQL> select count(*),p1,p2,p3 from v$active_session_history where event='buffer busy waits' and sample_time between to_date('21-FEB-2013 21:55:00','DD-MON-YYYY HH24:MI:SS') and to_date('21-FEB-2013 22:09:00','DD-MON-YYYY HH24:MI:SS') group by p1,p2

  COUNT(*)         P1         P2
---------- ---------- ----------
      2136          3      99405
        17          3       7293

SQL> select owner,segment_name,segment_type from dba_extents where file_id = 3 and 99405 between block_id AND block_id + blocks - 1 
OWNER                          SEGMENT_NAME              SEGMENT_TYPE
------------------------------ ------------------------- --------------------
SYS                            _SYSSMU14_1303827994$     TYPE2 UNDO

SQL> select owner,segment_name,segment_type from dba_extents where file_id = 3 and 7293 between block_id AND block_id + blocks - 1;
OWNER                          SEGMENT_NAME              SEGMENT_TYPE
------------------------------ ------------------------- --------------------
SYS                            _SYSSMU11_1303827994$     TYPE2 UNDO
Thought to check the SQL_ID which were waiting on this buffer busy waits.
SQL> select count(*),sql_id,session_state from v$active_session_history where event='buffer busy waits' and sample_time between to_date('21-FEB-2013 21:55:00','DD-MON-YYYY HH24:MI:SS') and to_date('21-FEB-2013 22:09:00','DD-MON-YYYY HH24:MI:SS') group by sql_id,session_state order by 1;

  COUNT(*) SQL_ID        SESSION_STATE
---------- ------------- ----------------------------
         1 cvypjyh0mm56x WAITING
         1 02dtz82as4y42 WAITING
         1 80gz2r4hx1wrj WAITING
         2 6tfk1t4mwt7hu WAITING
         9 0q63qhsbqmpf0 WAITING
        12 0jgnx96ur0bmb WAITING
        12 7pguapqcc6372 WAITING
        14 4t6hqk5r2zbqs WAITING
        18 1qwt0qkd59xj3 WAITING
        23 5phgg8btvhh6p WAITING
        23 banp2v6yttym7 WAITING
        30 a1kdmb1x084yh WAITING
        30 8hxuagk22f8jz WAITING
        30 9r0nysyp360hn WAITING
        31 cackx62yu477k WAITING
        32 40zxqg1qrdvuh WAITING
        32 0jqrd56ds1rbm WAITING
        32 7009zmuhvac54 WAITING
        38 1jb37ryn1c871 WAITING
        60 aum74caa623rs WAITING
        63 cr8mv0wawhak9 WAITING
        63 3xgk3vsh3nm08 WAITING
        86 3k9cq3jv0c3rg WAITING
        95 0sy9vjuutgwqu WAITING
       122 bhn2kk76wpg12 WAITING
       134 4pkfqgyt7rh34 WAITING
       139 1sbzsw7y88c7t WAITING
       146 92y0ha2nqd6zj WAITING
       163 djjqcp1sg2twb WAITING
       173 arxq6au12zazw WAITING
       256 fa0gzxmgyyxj2 WAITING
       282 2f17qywcgu751 WAITING
So top 10 sql_id's were on tables TAB1 and TAB2 under schemas SCHEMA1 to SCHEMA8.

Checked DML's occurred on Primary using dba_tab_modifications view since last stats job ran on these was about 10 hours ago from when the issue occurred on Active Dataguard.
SQL> select TABLE_OWNER,TABLE_NAME,INSERTS,UPDATES,DELETES from dba_tab_modifications where TABLE_NAME='TAB1' order by 3;

TABLE_OWNER               TABLE_NAME              INSERTS    UPDATES    DELETES 
------------------------------ --------------------- ---------- ---------- ---------- 
SCHEMA1                    TAB1                     4448          0       3728 
SCHEMA2                    TAB1                     4547          0       4022 
SCHEMA3                    TAB1                     4612          0       4152 
SCHEMA4                    TAB1                     4628          0       3940 
SCHEMA5                    TAB1                     4719          0       4258 
SCHEMA6                    TAB1                     4809          0       4292 
SCHEMA7                    TAB1                     4853          0       4356 
SCHEMA8                    TAB1                     5049          0       4536 


SQL> select TABLE_OWNER,TABLE_NAME,INSERTS,UPDATES,DELETES from dba_tab_modifications where TABLE_NAME='TAB2' order by 3;

TABLE_OWNER               TABLE_NAME                  INSERTS    UPDATES    DELETES 
--------------------- ------------------------- ---------- ---------- ---------- 
SCHEMA1                    TAB2                        25546          0      26360 
SCHEMA2                    TAB2                        26728          0      27565 
SCHEMA3                    TAB2                        27403          0      27763 
SCHEMA4                    TAB2                        27500          0      28149 
SCHEMA5                    TAB2                        28408          0      30440 
SCHEMA6                    TAB2                        30453          0      31906 
SCHEMA7                    TAB2                        31469          0      31988 
SCHEMA8                    TAB2                        32875          0      34670 
But confused about Why there could sudden spike of demand on UNDO data in Active Data Guard ? Could any one please shed some lights on finding the reason for this issue ?
  • 1. Re: Buffer busy waits on UNDO data in Active Dataguard
    SalmanQureshi Expert
    Currently Being Moderated
    Hi,
    First of all, why are not you using AWR report? I belive you have diagnostic pack license (because you are using v$active_session_history).
    What is size of undo tablespace? Probably you should try adding space to your undo tablespace. Oracle tries to allocate a single undo segment to each transaction, but, if tablespace size is small, mulitple transactions start to share same undo segment and this may rize buffer busy waits for undo tablespace.

    Salman
  • 2. Re: Buffer busy waits on UNDO data in Active Dataguard
    Yasu Newbie
    Currently Being Moderated
    We do have Diagnostic pack license but in this situation how can i generate AWR report for Standby(Active Dataguard) ? Hence we have scheduled Statspack in Cronjob on Primary which connects to Standby and take snapshots.

    I have used ASH on Standby(Active Dataguard) since it resides in Standby memory. At the same time i cannot take ASH report for standby since it fetches it from AWR ASH(DBA_HIST_ACTIVE_SESS_HISTORY) of Primary.
    SQL> select tablespace_name,file_name,bytes/1024/1024 MB from dba_data_files where tablespace_name like 'UNDOTBS%';
    
    TABLESPACE_NAME                FILE_NAME                                                            MB
    ------------------------------ ------------------------------------------------------------ ----------
    UNDOTBS1                       /s01/p15/p15_undotbs101.dbf                          10240
    UNDOTBS2                       /s01/p15/p15_undotbs201.dbf                          10240
    Please let me know if you need any more information.
  • 3. Re: Buffer busy waits on UNDO data in Active Dataguard
    Rob_J Journeyer
    Currently Being Moderated
    Hi,

    Just thinking out loud, but questions I have would be:

    1. Is it the 22:00-23:00 logs from the primary which are being applied to th DG DB at this time? I.e. is there any lag? If so, when are the logs from which are being applied to the standby DB?

    2. At that time, what is happening on the DB? Was something being rolled back? Do you use flashback queries to create other content, etc? Anything that could be using UNDO?

    3. How large is your buffer cache on the standby compared to the primary?

    4. Does this problem happen at the same time each day, week, month, etc, or is it a one off issue? Is it intermittent or consistent?

    Rob
  • 4. Re: Buffer busy waits on UNDO data in Active Dataguard
    Yasu Newbie
    Currently Being Moderated
    1. Is it the 22:00-23:00 logs from the primary which are being applied to th DG DB at this time? I.e. is there any lag? If so, when are the logs from which are being applied to the standby DB?
    Its through MRP process which keeps DG DB in sync. No lag.
    2. At that time, what is happening on the DB? Was something being rolled back? Do you use flashback queries to create other content, etc? Anything that could be using UNDO?
    Inserts and Deletes was happening on Primary. No flashback queries. Nothing was rolled back.
    3. How large is your buffer cache on the standby compared to the primary?
    Buffer sizing is same on both primary and standby. Size is 11 GB
    4. Does this problem happen at the same time each day, week, month, etc, or is it a one off issue? Is it intermittent or consistent?
    Its one-off issue, but need to find the reason as preventive measure.
  • 5. Re: Buffer busy waits on UNDO data in Active Dataguard
    Rob_J Journeyer
    Currently Being Moderated
    Hi,

    Ok, well nothing obvious to go on there. Maybe the deletes/inserts were also UNDO heavy on the primary DB at the same time but you have a better I/O response time on your primary? Or the applications which were using active data guard were running very resource intensive queries which caused contention across the disk system and therefore slowed response times down?

    Could be a number of reasons. What level of control do you have over what is run against the active data guard DB? Can people run anything they like whenever they like?

    Ideally you would need to look back at what else was running at the same time and see if there is something there of interest. If it's a complete one-off, and users have access to run anything on data guard, it's difficult to diagnose now. If it was happening regularly it would be easier to investigate.

    Maybe you can monitor more closely so that when/if it happens again you are alerted and can look at it in more detail?

    Rob
  • 6. Re: Buffer busy waits on UNDO data in Active Dataguard
    Yasu Newbie
    Currently Being Moderated
    Thanks for the guidance !!

    I will have a close watch for this DB and check for nature of application.

    By the way, do you know any better and accurate way to capture DML's occurred and amount of redo generated on particular table by mining history information from V$ASH or DBA_HIST_ACTIVE_SESS_HISTORY ?

    Thanks.
  • 7. Re: Buffer busy waits on UNDO data in Active Dataguard
    sb92075 Guru
    Currently Being Moderated
    Yasu wrote:
    Thanks for the guidance !!

    I will have a close watch for this DB and check for nature of application.

    By the way, do you know any better and accurate way to capture DML's occurred and amount of redo generated on particular table by mining history information from V$ASH or DBA_HIST_ACTIVE_SESS_HISTORY ?

    Thanks.
    DBMS_LOGMNR
  • 8. Re: Buffer busy waits on UNDO data in Active Dataguard
    Yasu Newbie
    Currently Being Moderated
    Thanks, so if i capture the details of DML's performed on primary db can we conclude hypthetically for this buffer busy waits on UNDO in Active Dataguard.

    Can it be due to 'Delayed block cleanout' on primary affecting Active Dataguard? How can i check for this ?
  • 9. Re: Buffer busy waits on UNDO data in Active Dataguard
    sb92075 Guru
    Currently Being Moderated
    Yasu wrote:
    Thanks, so if i capture the details of DML's performed on primary db can we conclude hypthetically for this buffer busy waits on UNDO in Active Dataguard.

    Can it be due to 'Delayed block cleanout' on primary affecting Active Dataguard? How can i check for this ?
    Do you see same activity on Primary?
    If not, why not?

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points