shutdown immediate hangs诊断求助

clevernby

数据库版本 11.2.0.2.0 linux x86-64
集群件版本 11.2.0.2.0 linux x86-64
这是一个2节点RAC数据库
上周五下午17:06对实例一执行shutdown immediate操作，但直到17:22分仍然不能正常关闭。
当时的DBA在17:16对执行shutdown命令的进程做了processstate（详见附件）
17:22分DBA对数据库执行shutdown abort并重新启动，一切恢复正常(很快)。
烦请刘大帮忙诊断一下，由于当时DBA只做了processstate，不知借此是否可分析出问题，再此先谢过了。
附上hang住时的alert日志

1. Fri Jun 01 17:06:37 2012
   
2. Shutting down instance (immediate)
   
3. Stopping background process SMCO
   
4. Shutting down instance: further logons disabled
   
5. Fri Jun 01 17:06:38 2012
   
6. Stopping background process CJQ0
   
7. Stopping background process QMNC
   
8. Stopping background process MMNL
   
9. Stopping background process MMON
   
10. License high water mark = 220
    
11. All dispatchers and shared servers shutdown
    
12. ALTER DATABASE CLOSE NORMAL
    
13. Fri Jun 01 17:06:44 2012
    
14. SMON: disabling tx recovery
    
15. Stopping background process RCBG
    
16. SMON: disabling cache recovery
    
17. Fri Jun 01 17:06:49 2012
    
18. NOTE: Deferred communication with ASM instance
    
19. Fri Jun 01 17:06:49 2012
    
20. NOTE: Deferred communication with ASM instance
    
21. NOTE: deferred map free for map id 25041
    
22. NOTE: deferred map free for map id 25043
    
23. Fri Jun 01 17:06:49 2012
    
24. NOTE: Deferred communication with ASM instance
    
25. Fri Jun 01 17:06:50 2012
    
26. Shutting down archive processes
    
27. Archiving is disabled
    
28. Fri Jun 01 17:06:50 2012
    
29. ARCH shutting down
    
30. Fri Jun 01 17:06:50 2012
    
31. ARCH shutting down
    
32. Fri Jun 01 17:06:50 2012
    
33. ARCH shutting down
    
34. Fri Jun 01 17:06:50 2012
    
35. ARCH shutting down
    
36. ARC3: Archival stopped
    
37. ARC1: Archival stopped
    
38. ARC0: Archival stopped
    
39. ARC2: Archival stopped
    
40. Thread 1 closed at log sequence 6680
    
41. Successful close of redo thread 1
    
42. Fri Jun 01 17:06:51 2012
    
43. NOTE: Deferred communication with ASM instance
    
44. NOTE: deferred map free for map id 4
    
45. Fri Jun 01 17:22:08 2012
    
46. License high water mark = 220
    
47. USER (ospid: 17823): terminating the instance
    
48. Instance terminated by USER, pid = 17823

复制代码

precessstate.rar (374.88 KB, 下载次数: 959)

2012-6-4 14:14 上传

点击文件名下载附件

[ 本帖最后由 clevernby 于 2012-6-4 14:19 编辑 ]

Maclean Liu(刘相兵

ODM DATA:
Stopping background process SMCO

*** 2012-06-01 17:06:38.202
ksimdel: READY status 5

*** 2012-06-01 17:06:38.298
Stopping background process QMNC

*** 2012-06-01 17:06:39.317
Stopping background process MMNL

*** 2012-06-01 17:06:40.329
Stopping background process MMON

*** 2012-06-01 17:06:41.437
ksukia: Starting kill, flags = 1
ksukia: Attempt 1 to kill process oracle@tbdb01_zj, OS id=18387

ksukia: killed 143 out of 143 processes.

*** 2012-06-01 17:06:43.131
ksukia: Starting kill, flags = 1
ksukia: killed 0 out of 0 processes.

*** 2012-06-01 17:06:44.206
* Set mstr_rdy 0, lmon_pnpchk 0

*** 2012-06-01 17:06:44.290
Stopping background process RCBG

在stop RCBG 时hang住  


RCBG 负责管理result cache ， 建议上传该段时间rcbg的TRACE

  SO: 0xc987576e8, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
   proc=0xc987576e8, name=process, file=ksu.h LINE:12451, pg=0
  (process) Oracle pid:94, ser:20, calls cur/top: 0xc0ad8dc80/0xc0ad8dc80
            flags : (0x0) -
            flags2: (0x0),  flags3: (0x0)
            intr error: 0, call error: 0, sess error: 0, txn error 1089
            intr queue: empty
    ksudlp FALSE at location: 0
  (post info) last post received: 0 0 27
              last post received-location: ksa2.h LINE:286 ID:ksasnr
              last process to post me: c8074b178 1 6
              last post sent: 0 0 26
              last post sent-location: ksa2.h LINE:282 ID:ksasnd
              last process posted by me: c8074b178 1 6
    (latch info) wait_event=0 bits=80
      holding    (efd=9) 601097d8 Child shared pool level=7 child#=3
        Location from where latch is held: kgh.h LINE:6407 ID:kghfre: Chunk Header
        Context saved from call: 49454235520
        state=busy [holder orapid=94] wlstate=free [value=0]


pid:94 的进程hold hild shared pool level=7 child#=3   by kghfre: Chunk Header

在等Disk file operations I/O


   SO: 0xc888362c8, type: 4, owner: 0xc987576e8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
     proc=0xc987576e8, name=session, file=ksu.h LINE:12459, pg=0
    (session) sid: 455 ser: 60839 trans: 0xc75af15f0, creator: 0xc987576e8
              flags: (0x100041) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x48008) -/DDLT2
              DID: , short-term DID:
              txn branch: (nil)
              oct: 35, prv: 0, sql: 0x9eb32f4c8, psql: 0xcd4417108, user: 0/SYS
    ksuxds FALSE at location: 0
    service name: SYS$USERS
    client details:
      O/S info: user: oracle, term: pts/3, ospid: 7396
      machine: tbdb01_zj program: sqlplus@tbdb01_zj (TNS V1-V3)
      application name: sqlplus@tbdb01_zj (TNS V1-V3), hash value=1997861317
    Current Wait Stack:
      Not in wait; last wait ended 9 min 19 sec ago
    Wait State:
      fixed_waits=0 flags=0x28 boundary=(nil)/-1
    Session Wait History:
        elapsed time of 9 min 19 sec since last wait
     0: waited for 'Disk file operations I/O'
        FileOperation=0x5, fileno=0x1, filetype=0x1
        wait_id=27177 seq_num=27184 snap_id=1
        wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec
        wait times: max=infinite
        wait counts: calls=0 os=0
        occurred after 0.000001 sec of elapsed time
     1: waited for 'Disk file operations I/O'
        FileOperation=0x5, fileno=0x0, filetype=0x1
        wait_id=27176 seq_num=27183 snap_id=1
        wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec
        wait times: max=infinite
        wait counts: calls=0 os=0
        occurred after 0.000010 sec of elapsed time


      SO: 0xa71e5e438, type: 77, owner: 0xc888362c8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
       proc=0xc987576e8, name=LIBRARY OBJECT LOCK, file=kgl.h LINE:8476, pg=0

      LibraryObjectLock:  Address=0xa71e5e438 Handle=0x9eb32f4c8 Mode=N CanBeBrokenCount=1 Incarnation=1 ExecutionCount=1         
        
        User=0xc888362c8 Session=0xc888362c8 ReferenceCount=1 Flags=CNB/[0001] SavepointNum=4fc88623
      LibraryHandle:  Address=0x9eb32f4c8 Hash=65cb1a12 LockMode=N PinMode=0 LoadLockMode=0 Status=VALD
        ObjectName:  Name=ALTER DATABASE CLOSE NORMAL


执行的语句是  ALTER DATABASE CLOSE NORMAL


没有更多其它的可用信息

clevernby

附上该时段的RCBG进程trc，该文件的最后修改时间为17:06:46，从内容来看RCBG正常退出无挂起现象。
tbdb1_rcbg_13681.zip (695 Bytes, 下载次数: 885)

2012-6-5 10:13 上传

点击文件名下载附件

尚存的一些疑惑
(1) Disk file operations I/O等待

1. 
   
2. SO: 0xc888362c8, type: 4, owner: 0xc987576e8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
   
3.      proc=0xc987576e8, name=session, file=ksu.h LINE:12459, pg=0
   
4.     (session) sid: 455 ser: 60839 trans: 0xc75af15f0, creator: 0xc987576e8
   
5.               flags: (0x100041) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
   
6.               flags2: (0x48008) -/DDLT2
   
7.               DID: , short-term DID:
   
8.               txn branch: (nil)
   
9.               oct: 35, prv: 0, sql: 0x9eb32f4c8, psql: 0xcd4417108, user: 0/SYS
   
10.     ksuxds FALSE at location: 0
    
11.     service name: SYS$USERS
    
12.     client details:
    
13.       O/S info: user: oracle, term: pts/3, ospid: 7396
    
14.       machine: tbdb01_zj program: sqlplus@tbdb01_zj (TNS V1-V3)
    
15.       application name: sqlplus@tbdb01_zj (TNS V1-V3), hash value=1997861317
    
16.     Current Wait Stack:
    
17.       Not in wait; last wait ended 9 min 19 sec ago
    
18.     Wait State:
    
19.       fixed_waits=0 flags=0x28 boundary=(nil)/-1
    
20.     Session Wait History:
    
21.         elapsed time of 9 min 19 sec since last wait
    
22.      0: waited for 'Disk file operations I/O'
    
23.         FileOperation=0x5, fileno=0x1, filetype=0x1
    
24.         wait_id=27177 seq_num=27184 snap_id=1
    
25.         wait times: snap=0.000001 sec, exc=0.000001 sec, total=0.000001 sec
    
26.         wait times: max=infinite
    
27.         wait counts: calls=0 os=0
    
28.         occurred after 0.000001 sec of elapsed time
    

复制代码

其中

1. 
   
2.     Current Wait Stack:
   
3.       Not in wait; last wait ended 9 min 19 sec ago
   

复制代码

最后一次等待发生在9分19秒之前，时间大致应该是17:07:07，自此之后并无等待发生。我觉得它导致hang的可能性不高。

(2) ASM map operations

1. 
   
2. Fri Jun 01 17:06:51 2012
   
3. NOTE: Deferred communication with ASM instance
   
4. NOTE: deferred map free for map id 4
   

复制代码

这是alert日志中最后输出的内容
然后是ASM map operation的SO

1. 
   
2. SO: 0xbf8c8e070, type: 123, owner: 0xc987576e8, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
   
3.      proc=0xc987576e8, name=ASM map operations, file=kffm2.h LINE:380, pg=0
   
4.     transistion:0x(nil)
   
5.     busylist:[bf8c8e0d8,bf8c8e0d8]
   
6.     freelist:[cbfaa0f00,cbfaa0f78]
   
7.       KFFMOP: hash link:[cbfaa0ef0,cbfaa0ef0] sobj link:[cbfaa0e88,bf8c8e0c8]
   
8.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
   
9.         group:[2,-2016913365] file:[265,753976451] extent:0
   
10.         flags:0x0000 disk:3 au:390 lock:0 proc:0x0xc987576e8
    
11.       KFFMOP: hash link:[cbfaa0e78,cbfaa0e78] sobj link:[cbfaa0e10,cbfaa0f00]
    
12.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
    
13.         group:[2,-2016913365] file:[265,753976451] extent:7
    
14.         flags:0x0000 disk:2 au:393 lock:0 proc:0x0xc987576e8
    
15.       KFFMOP: hash link:[cbfaa0e00,cbfaa0e00] sobj link:[cbfaa0c30,cbfaa0e88]
    
16.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
    
17.         group:[2,-2016913365] file:[265,753976451] extent:6
    
18.         flags:0x0000 disk:0 au:427 lock:0 proc:0x0xc987576e8
    
19.       KFFMOP: hash link:[cbfaa0c20,cbfaa0c20] sobj link:[cbfaa0bb8,cbfaa0e10]
    
20.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
    
21.         group:[2,-2016913365] file:[265,753976451] extent:5
    
22.         flags:0x0000 disk:1 au:392 lock:0 proc:0x0xc987576e8
    
23.       ......略
    
24.       KFFMOP: hash link:[cbfaa1238,cbfaa1238] sobj link:[cbfaa10e0,cbfaa12c0]
    
25.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
    
26.         group:[2,-2016913365] file:[265,753976451] extent:0
    
27.         flags:0x0000 disk:3 au:390 lock:0 proc:0x0xc987576e8
    
28.       KFFMOP: hash link:[cbfaa10d0,cbfaa10d0] sobj link:[cbfaa1068,cbfaa1248]
    
29.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
    
30.         group:[2,-2016913365] file:[265,753976451] extent:4
    
31.         flags:0x0000 disk:3 au:391 lock:0 proc:0x0xc987576e8
    
32.       KFFMOP: hash link:[cbfaa1058,cbfaa1058] sobj link:[cbfaa0f78,cbfaa10e0]
    
33.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
    
34.         group:[2,-2016913365] file:[265,753976451] extent:5
    
35.         flags:0x0000 disk:1 au:392 lock:0 proc:0x0xc987576e8
    
36.       KFFMOP: hash link:[cbfaa0f68,cbfaa0f68] sobj link:[bf8c8e0c8,cbfaa1068]
    
37.         map kggrp:[0x0xcbff3bad8, 0, valid]  map id:2
    
38.         group:[2,-2016913365] file:[265,753976451] extent:13
    
39.         flags:0x0000 disk:1 au:394 lock:0 proc:0x0xc987576e8
    

复制代码

其中
file 265是控制文件Current.265.753976451
file 267是SYSAUX.267.753976401
但是对ASM map operations不是很了解无法进一步分析，也不清楚是不是它导致的hang

(3) call SO 0xc0ad8dc80

1. 
   
2. SO: 0xc0ad8dc80, type: 3, owner: 0xc987576e8, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
   
3.      proc=0xc987576e8, name=call, file=ksu.h LINE:12455, pg=0
   
4.     (call) sess: cur c888362c8, rec c7085cfa0, usr c888362c8; flg:30 fl2:1; depth:0
   
5.     svpt(xcb:(nil) sptn:0x76 uba: 0x00000000.0000.00)
   
6.     ksudlc FALSE at location: 0
   
7.       ----------------------------------------
   
8.       SO: 0xc7092a440, type: 8, owner: 0xc0ad8dc80, flag: INIT/-/-/0x00 if: 0x1 c: 0x1
   
9.        proc=0xc987576e8, name=enqueue, file=ksq1.h LINE:365, pg=0
   
10.       (enqueue) IS-00000000-00000000 DID: 0001-005E-00084048
    
11.       lv: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  res_flag: 0x2
    
12.       mode: X, lock_flag: 0x10, lock: 0xc7092a498, res: 0xcd8992e60
    
13.       own: 0xc888362c8, sess: 0xc888362c8, proc: 0xc987576e8, prv: 0xcd8992e70
    
14.       ----------------------------------------
    
15.       SO: 0xc7085cfa0, type: 4, owner: 0xc0ad8dc80, flag: INIT/-/-/0x00 if: 0x3 c: 0x3
    
16.        proc=0xc987576e8, name=session, file=ksu.h LINE:12459, pg=0
    
17.       (session) sid: 459 ser: 16449 trans: 0xc7cad5b40, creator: (nil)
    
18.                 flags: (0x2) -/REC flags_idl: (0x0) -/-/-/-/-/-
    
19.                 flags2: (0x0) -/-
    
20.                 DID: , short-term DID:
    
21.                 txn branch: (nil)
    
22.                 oct: 0, prv: 0, sql: (nil), psql: 0xcbfa7baf8, user: 0/SYS
    
23.       ksuxds FALSE at location: 0
    
24.       temporary object counter: 0
    
25.         KTU Session Commit Cache Dump for IDLs:
    
26.         KTU Session Commit Cache Dump for Non-IDLs:
    

复制代码

递归会话0xc7085cfa0发起事务0xc7cad5b40，起始时间17:06:48，但该会话目前没有SQL在执行。这是不是也是条线索？


看来仅凭一个processstate很难完整分析出当时系统情况，不过还是谢谢刘大

clevernby

又检查了一下lmhb进程的trace文件，请刘大过目，其中多次出现

1. LCK0 (ospid: 13607) has not moved for 20 sec (xxxxxxx.xxxxxxx)
   
2. kjfmGCR_HBCheckAll: LCK0 (ospid: 13607) has status 2
   
3.   : waiting for event 'rdbms ipc message' for 0 secs with wait_id xxxxxxx.
   
4.   ===[ Wait Chain ]===
   
5.   Wait chain is empty.

复制代码

tbdb1_lmhb_13465.rar (2.7 KB, 下载次数: 890)

2012-6-8 16:54 上传

点击文件名下载附件

Maclean Liu(刘相兵

*** 2012-06-01 17:20:36.601
==============================
LCK0 (ospid: 13607) has not moved for 20 sec (1338542436.1338542416)
kjfmGCR_HBCheckAll: LCK0 (ospid: 13607) has status 2
  : waiting for event 'rdbms ipc message' for 0 secs with wait_id 560181102.
  ===[ Wait Chain ]===
  Wait chain is empty.

*** 2012-06-01 17:20:56.607
==============================
LCK0 (ospid: 13607) has not moved for 20 sec (1338542456.1338542436)
kjfmGCR_HBCheckAll: LCK0 (ospid: 13607) has status 2
  : waiting for event 'rdbms ipc message' for 0 secs with wait_id 560181301.
  ===[ Wait Chain ]===
  Wait chain is empty.


出现的LCK0进程长期空闲等待中，一致也没有被KILL掉，只能说是另一种该问题的表现，而非原因

clevernby

开了SR，如果有新进展我会回复该帖。

Maclean Liu(刘相兵

Good reply !

clevernby

Oracle Support在查看了提供的lmhb trace文件后做了如下研究

1. 
   
2. Note: This is INTERNAL ONLY research.  No action should be taken by the customer on this information. This is research only, and may NOT be applicable to your specific situation.
   
3. 
   
4. KM SEARCH
   
5. -------------------
   
6. 
   
7. SR #: 3-5600337171
   
8. Summary: shutdown of RAC database hangs
   
9. Description: When we tried to perform a switchover from a primary RAC database to a physical standby the process stopped because shutdown of the primary RAC database hung.
   
10. 
    
11. The following messages was written in the lmhb trace file:
    
12. LMS0 (ospid: 17482) has not moved for 34 sec (1334571575.1334571541)
    
13. kjfmGCR_HBCheckAll: LMS0 (ospid: 17482) has status 2
    
14. : waiting for event 'gcs remote message' for 0 secs with wait_id 166465.
    
15. ===[ Wait Chain ]===
    
16. Wait chain is empty.
    
17. 
    
18. After searching the support web I found document ID 1440112.1.
    
19. We implemented the workaround by setting "_gc_defer_time=3", and that fixed the problem.
    
20. 
    
21. I am not 100% sure if you have hit this bug.
    
22. When looking at the messages in the trace file, then yes, it surely has all the symptoms
    
23. But I see no recording, that may be lack of info, that this problem hangs the instance during a shutdown.
    
24. 
    
25. The parameter "_gc_defer_time=3" configures the time (in ms) on a cache block that a LMS process gives to a user process
    
26. to complete his transaction on a local instance, before changing the lock and
    
27. sending the block to a requestor on another instance.
    
28. It "may" improve performance on local instance transactions.
    
29. 
    
30. That setting the hidden parameter solved the hang is interesting and does
    
31. add to the suspicion that this bug was involved
    
32. 
    
33. ===> 11.2.0.3
    
34. 
    
35. Bug 9886569: [11202-LNX-100628]LMHB DON'T KILL LCK0 EVEN THOUGH IT WAS HUNG FOR A LONG TIME
    

复制代码

我会继续跟进...

clevernby

backport BUG 9886569 to 11.2.0.2.0

1. KM Search
   
2. ------------------
   
3. keyword = shutdown hang kjfmGCR_HBCheckAll: LCK0 "Wait chain is empty"
   
4. 
   
5. Bug 9886569 [http://bug.oraclecorp.com/pls/bug/webbug_edit.edit_info_top?rptno=9886569] : [11202-LNX-100628]LMHB DON'T KILL LCK0 EVEN THOUGH IT WAS HUNG FOR A LONG TIME
   
6. 
   
7. RELEASE NOTES:
   
8. ]]LMHB does not terminate the instance even though it detcts that a fatal backg
   
9. ]]round has been stuck for a long time.
   
10. @
    
11. @INTERNAL PROBLEM DESCRIPTION:
    
12. @A flag is not reset in the LMHB codepath which prevents LMHB from taking any f
    
13. @atal action such as instance termination when required.
    
14. @
    
15. @INTERNAL FIX DESCRIPTION:
    
16. @The required flag is now reset at beginning of the action taking loop.
    
17. @
    
18. @BACKPORT FEASIBLE:
    
19. @Yes
    
20. @
    
21. @FORWARD MERGE REQUIRED:
    
22. @No (merged to main branch)
    
23. @
    
24. REDISCOVERY INFORMATION:
    
25. If LMHB tdetects that a fatal background is hung but it does not termiante the
    
26. instance then most probably this bug has been hit.
    
27. 
    
28. 
    
29. Bug 9894036 [http://bug.oraclecorp.com/pls/bug/webbug_edit.edit_info_top?rptno=9894036] : RFI BACKPORT OF BUG 9886569 [http://bug.oraclecorp.com/pls/bug/webbug_edit.edit_info_top?rptno=9886569] FOR INCLUSION IN 11.2.0.2.0 (RFI #350307)

复制代码

Maclean Liu(刘相兵

就SR的回复看GCS 从内部 bug database中找到了一个潜在可能的bug ，即lck hang ，但是 LMHB进程没有合理终止实例

clevernby

1. 
   
2. Dear customer,
   
3. 
   
4. From the trace file provided, we confirmed your issue hit Bug 9886569 : [11202-LNX-100628]LMHB DON'T KILL LCK0 EVEN THOUGH IT WAS HUNG FOR A LONG TIME
   
5. 
   
6. The bug will be fixed in 11.2.0.3. The backport patch request with
   
7. Bug 9894036 : RFI BACKPORT OF BUG 9886569 FOR INCLUSION IN 11.2.0.2.0 (RFI #350307)
   
8. is still under review.
   
9. 
   
10. The cause is the LMHB does not terminate the instance even though it detects that a fatal background has been stuck for a long time.
    
11. 
    
12. Please let me know whether you would like to have a backport patch on 11.2.0.2 which takes some time or any plan to upgrade to 11.2.0.3 recently?
    
13. 
    
14. Best Regards,
    
15. Oracle Global Software Support
    

复制代码

Maclean Liu(刘相兵

很好 ， 这是一个完整的case了。

clevernby

backport被拒绝，RnD team认为当时lck0进程并没有出现hang的迹象，理由是心跳正常，因此bug 9886569并不能解决我的问题，需要raise new bug.

1. 
   
2. Dear customer,
   
3. 
   
4. Thanks for your waiting.
   
5. 
   
6. I got a rejection from the back port patch request.
   
7. 
   
8. Please refer to the following from our RnD team
   
9. 
   
10. ------
    
11. I was looking at the SR trace files and I saw that LCK0 never stopped issuing HB more than 70 secs. Then LMHB should not attempt to kill the process.
    
12. 
    
13. Actually most of the times we had:
    
14. 
    
15. LCK0 (ospid: 13607) has not moved for 20 sec
    
16. 
    
17. which means that the process HB was not produced for 20 secs.
    
18. 
    
19. Then the patch is not useful here, you need to raise a new bug if this happens again and collect a couple of systemstate dumps.
    
20. ------
    
21. 
    
22. In the suspected bug, it has the symptom as
    
23. 
    
24. @ ORA-29770: global enqueue process LCK0 (OSID 13469) is hung for more than 150
    
25. @ seconds
    
26. 
    
27. So, we have to raise another new bug once issue reoccurred.
    
28. 
    
29. Before raising the bug, need to have the following log / information:
    
30. 
    
31. ACTION PLAN
    
32. -----------------------
    
33. 1. Please confirm whether we can reproduce the case?
    
34. 
    
35. 2. Once issue reoccurred, please
    
36. 
    
37. See Note 121779.1 Taking Systemstate Dumps when You cannot Connect to Oracle.
    
38. 
    
39. Please run the following on one instance as sysdba:
    
40. SQL>oradebug setmypid
    
41. SQL>oradebug unlimit
    
42. SQL>oradebug -g all hanganalyze 3
    
43. Wait for 30 seconds
    
44. SQL>oradebug -g all hanganalyze 3
    
45. SQL>exit
    
46. 
    
47. Open another session as sysdba:
    
48. SQL>oradebug setmypid
    
49. SQL>oradebug unlimit
    
50. SQL>oradebug -g all dump systemstate 10
    
51. Wait for 30 seconds
    
52. SQL>oradebug -g all dump systemstate 10
    
53. SQL>oradebug tracefile_name
    
54. SQL>exit
    
55. 
    
56. The generated trace files will be in the diag trace file in BDUMP for each instance, please upload these files.
    
57. 
    
58. 3. Provide alert log and related trace file during issue occurred period.
    
59. 
    
60. Best Regards,
    
61. Oracle Global Software Support
    
62. 
    

复制代码

接下来要漫长等待下次shutdown了，可能今年会有，也可能明年，甚至后年，还得再次触发，呵呵，似乎不了了之了...

重要：出现异常现象时，systemdump对于support团队诊断、制做patch至关重要，一定要记得做。

clevernby

刚才实验了下，lmhb心跳检查的阈值是70s，达到110s时会进行process dump并尝试唤醒对应进程

1. 
   
2. *** 2012-06-21 10:49:07.009
   
3. ==============================
   
4. LCK0 (ospid: 13261) has not moved for 110 sec (1340246946.1340246836)
   
5. kjfmGCR_HBCheckAll: LCK0 (ospid: 13261) has status 6
   
6. ==================================================
   
7. === LCK0 (ospid: 13261) Heartbeat Report
   
8. ==================================================
   
9. LCK0 (ospid: 13261) has no heartbeats for 110 sec. (threshold 70 sec)
   
10.   : waiting for event 'rdbms ipc message' for 100 secs with wait_id 37443.
    
11. ===[ Wait Chain ]===
    
12. Wait chain is empty.
    
13. ==============================
    
14. Dumping PROCESS LCK0 (ospid: 13261) States
    
15. ==============================
    
16. ...
    

复制代码

Maclean Liu(刘相兵

呵呵

GCS 最喜欢让人对hang的场景做 hanganalyze 和 systemstate了。

klby

这些内部note有什么办法看？

ora-hansey

好东西。