Oracle数据库数据恢复、性能优化

找回密码
注册
搜索
热搜: 活动 交友 discuz
Oracle数据库数据恢复、性能优化»论坛 › Oracle › Oracle数据库管理 › 在死锁检测之前 oracle会等 enqueue lock多久？ ...
发新帖
Maclean Liu(刘相兵

2135

积分

502

好友

184

主题

在死锁检测之前 oracle会等 enqueue lock多久？

1#
发表于 2012-6-12 11:36:59 | 查看: 12463| 回复: 7
在死锁检测之前 oracle会等 enqueue lock多久？    欢迎大家踊跃讨论！
下载专业ORACLE数据库恢复工具PRM-DUL  For Oracle http://www.parnassusdata.com/zh-hans/emergency-services

如果自己搞不定可以找诗檀软件专业ORACLE数据库修复团队成员帮您恢复!

诗檀软件专业数据库修复团队

服务热线 ： 13764045638  QQ: 47079569   
2#
发表于 2012-6-12 13:08:42
在11.2.0.2.0上做了实验，步骤如下
会话1，PID=66

  2. [oracle@GG-rac1 ~]$ export ORACLE_SID=sbdb1
  3. [oracle@GG-rac1 ~]$ sqlplus / as sysdba
  4. SQL*Plus: Release 11.2.0.2.0 Production on Tue Jun 12 12:36:30 2012
  5. Copyright (c) 1982, 2010, Oracle.  All rights reserved.

  7. Connected to:
  8. Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
  9. With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
  10. Data Mining and Real Application Testing options
  11. SQL> select pid from v$process where addr=(select paddr from v$session where sid=userenv('SID'));
  12.        PID
  13. ----------
  14.         66
  15. SQL> alter system set "_trace_events"='10000-10999:255:66,67';
  16. System altered.
  17. SQL> update t_clevernby set id=11 where id=1;
  18. 1 row updated.
  19. SQL> update t_clevernby set id=22 where id=2;
  20. update t_clevernby set id=22 where id=2
  21. *
  22. ERROR at line 1:
  23. ORA-00060: deadlock detected while waiting for resource

  25. SQL> commit;
  26. Commit complete.
  27. SQL> oradebug setmypid
  28. Statement processed.
  29. SQL> oradebug dump errorstack 4
  30. Statement processed.
复制代码


会话2，PID=67

  2. [root@GG-rac1 ~]# su - oracle
  3. [oracle@GG-rac1 ~]$ export ORACLE_SID=sbdb1
  4. [oracle@GG-rac1 ~]$ sqlplus / as sysdba
  5. SQL*Plus: Release 11.2.0.2.0 Production on Tue Jun 12 12:36:43 2012
  6. Copyright (c) 1982, 2010, Oracle.  All rights reserved.

  8. Connected to:
  9. Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
  10. With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP,
  11. Data Mining and Real Application Testing options
  12. SQL> select pid from v$process where addr=(select paddr from v$session where sid=userenv('SID'));
  13.        PID
  14. ----------
  15.         67
  16. SQL> update t_clevernby set id=222 where id=2;
  17. 1 row updated.
  18. SQL> update t_clevernby set id=111 where id=1;
  19. 0 rows updated.
  20. SQL> commit;
  21. Commit complete.
  22. SQL> oradebug setmypid
  23. Statement processed.
  24. SQL> oradebug dump errorstack 4
  25. Statement processed.
复制代码


KSTTrace.rar (842.08 KB, 下载次数: 1638)

在66.trc中可以看到

  2. 2012-06-12 12:38:48.672238 :8766BA98:db_trace:ksq.c@7632:ksqgtlctx(): [10704:66:93] ksqgtl: acquire TX-00060021-0000121e mode=X flags=GLOBAL|LONG why="row lock contention"
  3. 2012-06-12 12:38:48.672331 :8766BA99:db_trace:kju.c@1224:kjuef(): [10425:66:93] kjuef: [0x60021][0x121e],[TX][ext 0x7fff,0x0]
  4. 2012-06-12 12:38:48.672433 :8766BA9A:db_trace:ksl2.c@2542:kslwtbctx(): [10005:66:93] KSL WAIT BEG [enq: TX - row lock contention] 1415053318/0x54580006 393249/0x60021 4638/0x121e wait_id=52 seq_num=59 snap_id=1
  5. 2012-06-12 12:38:49.173483 :8766BB0B:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  6. 2012-06-12 12:38:49.674485 :8766BB56:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  7. 2012-06-12 12:38:50.175483 :8766BBA8:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  8. 2012-06-12 12:38:50.175483*:8766BBA9:sql_mon_query:keswx.c@6154:keswxCurPushMonitoring(begin): xsc=0x2adbd5a24b50 monCtx=(nil) estart=1339475928 eid=16777218 ctx=0xff403460 cwh=0x2adbd5a209b8 cpu=0 buffg=9 interb=0 r=0 rb=0 w=0 wb=0
  9. 2012-06-12 12:38:50.175483*:8766BBAA:sql_mon_query:keswx.c@2845:keswxCurPrepare(): Allocate monitor context: xsc=0x2adbd5a24b50 curCtx=0x2adbd5a245a0 pubTabIdxCnt=0
  10. 2012-06-12 12:38:50.175483*:8766BBAB:sql_mon_query:keswx.c@6200:keswxCurPushMonitoring(): clear monitoring flag for xsc=0x2adbd5a24b50
  11. 2012-06-12 12:38:50.175483*:8766BBAC:sql_mon_query:keswx.c@6332:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x2adbd5a24b50
  12. 2012-06-12 12:38:50.676480 :8766BC29:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  13. 2012-06-12 12:38:51.177480 :8766BCB4:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  14. 2012-06-12 12:38:51.678480 :8766BD13:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  15. 2012-06-12 12:38:52.179484 :8766BD74:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  16. 2012-06-12 12:38:52.179484*:8766BD75:sql_mon_query:keswx.c@6154:keswxCurPushMonitoring(begin): xsc=0x2adbd5a24b50 monCtx=0x2adbd5a245a0 estart=1339475928 eid=16777218 ctx=0xff403460 cwh=0x2adbd5a209b8 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0
  17. 2012-06-12 12:38:52.179484*:8766BD76:sql_mon_query:keswx.c@6332:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x2adbd5a24b50
  18. 2012-06-12 12:38:52.680480 :8766BDBA:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  19. 2012-06-12 12:38:53.181481 :8766BE17:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  20. 2012-06-12 12:38:53.682478 :8766BEF7:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  21. 2012-06-12 12:38:54.183479 :8766BFB3:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  22. 2012-06-12 12:38:54.183479*:8766BFB4:sql_mon_query:keswx.c@6154:keswxCurPushMonitoring(begin): xsc=0x2adbd5a24b50 monCtx=0x2adbd5a245a0 estart=1339475928 eid=16777218 ctx=0xff403460 cwh=0x2adbd5a209b8 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0
  23. 2012-06-12 12:38:54.183479*:8766BFB5:sql_mon_query:keswx.c@6332:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x2adbd5a24b50
  24. 2012-06-12 12:38:54.684474 :8766C03B:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  25. 2012-06-12 12:38:55.185477 :8766C0B6:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  26. 2012-06-12 12:38:55.686473 :8766C0FE:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  27. 2012-06-12 12:38:56.187476 :8766C140:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  28. 2012-06-12 12:38:56.187476*:8766C141:sql_mon_query:keswx.c@6154:keswxCurPushMonitoring(begin): xsc=0x2adbd5a24b50 monCtx=0x2adbd5a245a0 estart=1339475928 eid=16777218 ctx=0xff403460 cwh=0x2adbd5a209b8 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0
  29. 2012-06-12 12:38:56.187476*:8766C142:sql_mon_query:keswx.c@6332:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x2adbd5a24b50
  30. 2012-06-12 12:38:56.688470 :8766C1E3:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  31. 2012-06-12 12:38:57.189536 :8766C289:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  32. 2012-06-12 12:38:57.690468 :8766C2F4:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  33. 2012-06-12 12:38:58.191470 :8766C378:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  34. 2012-06-12 12:38:58.191470*:8766C379:sql_mon_query:keswx.c@6154:keswxCurPushMonitoring(begin): xsc=0x2adbd5a24b50 monCtx=0x2adbd5a245a0 estart=1339475928 eid=16777218 ctx=0xff403460 cwh=0x2adbd5a209b8 cpu=0 buffg=0 interb=0 r=0 rb=0 w=0 wb=0
  35. 2012-06-12 12:38:58.191470*:8766C37A:sql_mon_query:keswx.c@6332:keswxCurPushMonitoring(end): full monitoring not yet started for xsc=0x2adbd5a24b50
  36. 2012-06-12 12:38:58.692488 :8766C3C8:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=50
  37. 2012-06-12 12:38:58.799543 :8766C3CD:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=10
  38. 2012-06-12 12:38:58.799546 :8766C3CE:db_trace:ksl2.c@13718:ksliwat(): [10005:66:93] KSL POST RCVD poster=43 num=3338 loc='ksv2.h LINE:1673 ID:ksvpst: workdone' id1=0 id2=0 name=   type=0 fac#=3 posted=0x1 may_be_posted=1
  39. 2012-06-12 12:38:59.021847 :8766C3F4:db_trace:kju.c@1224:kjuef(): [10425:66:93] kjuef: [0x60021][0x121e],[TX][ext 0x7fff,0x0]
  40. 2012-06-12 12:38:59.021852 :8766C3F5:db_trace:ksl2.c@13590:ksliwat(): [10005:66:93] KSL FACILITY WAIT fac#=3 time_waited_csecs=22
  41. 2012-06-12 12:38:59.021854 :8766C3F6:db_trace:ksl2.c@13718:ksliwat(): [10005:66:93] KSL POST RCVD poster=13 num=270089 loc='kji.h LINE:3275 ID:kjata: wake up enqueue owner' id1=0 id2=0 name=   type=0 fac#=3 posted=0x3 may_be_posted=1
  42. 2012-06-12 12:38:59.021861 :8766C3F7:db_trace:ksl2.c@2676:kslwtectx(): [10005:66:93] KSL WAIT END [enq: TX - row lock contention] 1415053318/0x54580006 393249/0x60021 4638/0x121e wait_id=52 seq_num=59 snap_id=1
  43. 2012-06-12 12:38:59.021863 :8766C3F8:db_trace:ksl2.c@2684:kslwtectx(): [10005:66:93] KSL WAIT END wait times (usecs) - snap=10349422, exc=10349422, tot=10349422
  44. 2012-06-12 12:38:59.021863*:RAC_ENQ:kju.c@2847:kjusuc(): convert request failed with status=[0xF].
  45. 2012-06-12 12:38:59.021888 :8766C3F9:db_trace:ksq.c@8142:ksqgtlctx(): [10704:66:93] ksqgtl: FAILURE: DEADLOCK
复制代码

会话1请求TX-00060021-0000121e未果后进入KSL WAIT，10s后出现ksqgtl: FAILURE: DEADLOCK

请刘大过目，不过有个问题

PID=67的KST Trace不知为何只有12:39:15之后的数据，因此感觉实验结果可能有误

回复 只看该作者 道具 举报

3#
发表于 2012-6-12 23:41:49
clevernby 同学用KST  TRACE做了一个很有意思的实验， 值得大家鼓励，  本贴加精。

我个人对于Enqueue Deadlock Detection的一点看法，发表在 http://www.oracledatabase12g.com ... lock-detection.html

回复 只看该作者 道具 举报

4#
发表于 2012-6-13 09:30:04
刚才拜读了您的文章感触颇深，但对我的实验结果为10s确有些不解，于是进一步分析了我的KST Trace，发现以下细节，请刘大过目
在process 66的trc中

  2. 2012-06-12 12:38:59.021854 :8766C3F6:db_trace:ksl2.c@13718:ksliwat(): [10005:66:93] KSL POST RCVD poster=13 num=270089 loc='kji.h LINE:3275 ID:kjata: wake up enqueue owner' id1=0 id2=0 name=   type=0 fac#=3 posted=0x3 may_be_posted=1
复制代码

唤醒它的是process 13，这个进程经查是RAC LMD0进程，该进程除了管理全局enqueue、资源访问之外，也负责检测全局enqueue死锁。
查询涉及LMD进程的隐含参数后发现_lm_dd_interval参数为默认的10s.

最后在单实例的11.2.0.2.0数据库上测试，结果果然是3s。

回复 只看该作者 道具 举报

5#
发表于 2012-6-13 11:03:45

回复 4# 的帖子

很不错 我支持你的观点， http://www.oracledatabase12g.com ... lock-detection.html 这里补充了关于RAC的死锁检测

回复 只看该作者 道具 举报

fsm
6#
发表于 2012-6-13 11:15:02
两位高人，能否给个KST Trace的使用说明？没用过这东西呢。

回复 只看该作者 道具 举报

7#
发表于 2012-6-13 16:04:41
原帖由 fsm 于 2012-6-13 11:15 发表
两位高人，能否给个KST Trace的使用说明？没用过这东西呢。

KST Trace可参考DSI408第19章
刘大在博客中提到的UTS Trace可参考1402625.1，其中还有介绍event++ syntax.

回复 只看该作者 道具 举报

fsm
8#
发表于 2012-6-14 07:13:49
原帖由 clevernby 于 2012-6-13 16:04 发表

KST Trace可参考DSI408第19章
刘大在博客中提到的UTS Trace可参考1402625.1，其中还有介绍event++ syntax.

多谢！

回复 只看该作者 道具 举报

返回列表
高级模式
B Color Image Link Quote Code Smilies
您需要登录后才可以回帖 登录 | 注册

QQ|手机版|Archiver|Oracle数据库数据恢复、性能优化

GMT+8, 2024-4-20 13:10 , Processed in 0.056056 second(s), 24 queries .

Powered by Discuz! X2.5

© 2001-2012 Comsenz Inc.

回顶部
TEL/電話+86 13764045638
Email service@parnassusdata.com
QQ 47079569