[20130904]等待事件wait for a undo record.txt

生产系统出现严重的等待事件，出现问题时我不在现场，这个事后的分析。

检查慢的时段的awr报表，可以发现出现了wait for a undo record等待事件，这个问题以前没有遇到。

Top 5 Timed Events                                         Avg %Total

~~~~~~~~~~~~~~~~~~                                        wait   Call

Event                                 Waits    Time (s)   (ms)   Time Wait Class

------------------------------ ------------ ----------- ------ ------ ----------

db file sequential read           1,651,116      24,802     15   48.4   User I/O

CPU time                                         11,499          22.4           

wait for a undo record              191,327      11,153     58   21.7      Other

buffer busy waits                 2,637,172       6,101      2   11.9 Concurrenc

log buffer space                      3,931       3,551    903    6.9 Configurat

          -------------------------------------------------------------       

google发现相关链接：http://www.itpub.net/thread-1328358-1-1.html

SQL> select * from V$FAST_START_TRANSACTIONS;

 USN  SLT        SEQ STATE      UNDOBLOCKSDONE UNDOBLOCKSTOTAL     PID    CPUTIME  PARENTUSN  PARENTSLT  PARENTSEQ XID              PXID  RCVSERVERS

---- ---- ---------- ---------- -------------- --------------- ------- ---------- ---------- ---------- ---------- ---------------- ----- ----------

  35    6      87390 RECOVERED           29379           29379                184                                  230006005E550100               48

  92   39       6748 RECOVERED           14749           14749                241                                  5C0027005C1A0000                1

  49   38      70834 RECOVERED           36979           36979                173                                  31002600B2140100               48

  20   43     141597 RECOVERED            3444            3444                 45                                  14002B001D290200               48

select * from v$event_name where name like 'wait for a undo record';

    EVENT#   EVENT_ID NAME                   PARAMETER1  PARAMETER2  PARAMETER3  WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS

---------- ---------- ---------------------- ----------- ----------- ----------- ------------- ----------- ----------

       587 3020078888 wait for a undo record                                        1893977003           0 Other

--没有参数的说明。

从XID='230006005E550100'来找线索。

SQL> select * from FLASHBACK_TRANSACTION_QUERY where xid=hextoraw('230006005E550100');

XID               START_SCN START_TIMESTAMP     COMMIT_SCN COMMIT_TIMESTAMP    LOGON_USER  UNDO_CHANGE# OPERATION  TABLE_NAME TABLE_OWNER  ROW_ID   UNDO_SQL

---------------- ---------- ------------------- ---------- ------------------- ----------- ------------ ---------- ---------- ------------ ------  ---------

230006005E550100 9932260717 2013-09-03 16:54:08 9933165192 2013-09-03 17:08:58 XXXXXXXXXX              1 BEGIN

--说明：这个视图查看有一定时间，也许时间久了在这里看不到，也许使用IMU的原因，看不到UNDO_SQL语句。时间2013-09-03 16:54:08到2013-09-03 17:08:58。

SQL> select * from V$ACTIVE_SESSION_HISTORY where xid=hextoraw('230006005E550100');

--输出太多，忽略。从里面可以知道sql_id.
--说明：这个视图查看有一定时间，也许时间久了在这里看不到.可以使用DBA_HIST_ACTIVE_SESS_HISTORY代替。

SQL> select * from DBA_HIST_ACTIVE_SESS_HISTORY where xid=hextoraw('230006005E550100')

SQL> select distinct sql_id from V$ACTIVE_SESSION_HISTORY where xid=hextoraw('230006005E550100');

SQL_ID

-------------

ftm564rm196my

SQL> select * from v$sql where sql_id='ftm564rm196my';

no rows selected

--已经不在shared pool。

SQL> select * from DBA_HIST_SQLTEXT where sql_id='ftm564rm196my';

      DBID SQL_ID        SQL_TEXT                                                                         COMMAND_TYPE

---------- ------------- -------------------------------------------------------------------------------- ------------

 168324986 ftm564rm196my update ZY_FYMX SET YJRQ =:1 WHERE ZY_FYMX.JFRQ < :2 AND ZY_FYMX.YJRQ IS NULL                6

SQL> select * from DBA_HIST_SQLBIND where sql_id='ftm564rm196my';
no rows selected
--无法获得绑定变量的值。

SQL> select * from DBA_HIST_SQL_PLAN where sql_id='ftm564rm196my';
no rows selected
--执行计划也无法获得？why？查询awr报表也没有记录。有点奇怪!

直接看sql语句。
update ZY_FYMX SET YJRQ =:1 WHERE ZY_FYMX.JFRQ < :2 AND ZY_FYMX.YJRQ IS NULL;

-- 表ZY_FYMX的大小2.3G。
-- 猜测一下 YJRQ 表示月结日期 JFRQ表示什么日期呢？直接输入汉语拼音开头jf，好像表示计费，问一下开发确实这样。
-- [ 补充：我个人非常讨厌这种字段的命名方式，更加要命的是一些开发根本没有文档说明,或者根本不全]。
-- 这样就很明显，正好是月头，财务做扎帐处理，表仅仅在JFRQ字段上有索引。ZY_FYMX.JFRQ < :2的区间范围一定很大应该不会使用这个索引。
-- 而查询ZY_FYMX.YJRQ 的条件是ZY_FYMX.YJRQ IS NULL，很明显即使存在yjrq的索引也没有用。因为查询条件是NULL。
-- 正常如果每个月都做月结，YJRQ is NULL的信息应该会很少,建立一个函数索引也许能解决这个问题。

-- 执行计划应该是全部扫描,操作人员一定觉得慢，没有等待结束就退出，导致大量事务rollback，出现wait for a undo record的情况。

SELECT distinct xid,session_id,sql_id

  FROM DBA_HIST_ACTIVE_SESS_HISTORY

 WHERE xid IN

          (HEXTORAW ('14002B001D290200'),

           HEXTORAW ('31002600B2140100'),

           HEXTORAW ('5C0027005C1A0000'),

           HEXTORAW ('230006005E550100'))

order by xid;

XID              SESSION_ID SQL_ID

---------------- ---------- -------------

14002B001D290200       2274 9a4dwk6bdus8m

14002B001D290200       2274 b5nzc0t42sjut

14002B001D290200       2274 ftm564rm196my

230006005E550100        466 ftm564rm196my

31002600B2140100       2393 b5nzc0t42sjut

31002600B2140100       2393 ftm564rm196my

5C0027005C1A0000       1052 ftm564rm196my

5C0027005C1A0000       1052

8 rows selected.

--xid相同涉及到sql_id还有9a4dwk6bdus8m，b5nzc0t42sjut，很奇怪这两个sql_id事后无法查询到对应的sql语句。不过基本可以确定问题。