> 数据库 > Oracle >

Oracle 11gR2光钎链路切换crs服务发生crash

Oracle 11gR2光钎链路切换crs服务发生crash

 

背景:

我们将Oracle 11gR2(11.2.0.4)在RedHat EnterPrise 5.8上通过RDAC完成的多路径链路冗余,在部署完成后,我们需要做多路径链路冗余测试,我们的光钎链路连接方式如下。我们做多路径测试完成了如下几个组合:

拔线测试组合一:

1、 先拔下光钎链路 ②和④ 一切正常没有问题;插上五分钟后执行第2步。

2、 再拔下光钎链路 ①和③ 数据库服务正常,crs进程crash无法访问,手工重启crs进程即可。

拔线测试组合二:

1、 先拔下光钎链路 ①和③ 一切正常没有问题;插上五分钟后执行第2步。

2、 再拔下光钎链路 ②和④ 数据库服务正常,crs进程crash无法访问,手工重启crs进程即可。

拔线测试组合三:

1、 先拔下光钎链路 ①和④ 一切正常没有问题;插上五分钟后执行第2步。

2、 再拔下光钎链路 ②和③ 一切正常没有问题;

拔线测试组合四:

1、 先拔下光钎链路 ②和③ 一切正常没有问题;插上五分钟后执行第2步。

2、 再拔下光钎链路 ①和④ 一切正常没有问题;

控制器切换测试组合:

1、 进入存储管理控制台,查看当前磁盘所在控制器为A控,手动全部切换到B,一切正常没有问题。

2、 五分钟之后,再次进入存储管理控制台,将所有磁盘从B控制器切换到A控制器,一切正常没有问题。

 

 

 

问题现象:

问题发生在第一组和第二组的的测试2上面,问题现象如下:

 

 
  1. [grid@db01 ~] $ crs_stat -t -v  
  2. CRS-0184: Cannot communicate with the CRS daemon.  
  3.   
  4. [root@db01 ~]# ps -ef|grep ora  
  5. oracle    2687     1  0 00:12 ?        00:00:00 ora_pmon_woo  
  6. oracle    2689     1  0 00:12 ?        00:00:00 ora_psp0_woo  
  7. oracle    2691     1  0 00:12 ?        00:00:00 ora_vktm_woo  
  8. oracle    2695     1  0 00:12 ?        00:00:00 ora_gen0_woo  
  9. oracle    2697     1  0 00:12 ?        00:00:00 ora_diag_woo  
  10. oracle    2699     1  0 00:12 ?        00:00:00 ora_dbrm_woo  
  11. oracle    2701     1  0 00:12 ?        00:00:00 ora_dia0_woo  
  12. oracle    2703     1  0 00:12 ?        00:00:00 ora_mman_woo  
  13. oracle    2705     1  0 00:12 ?        00:00:00 ora_dbw0_woo  
  14. oracle    2707     1  0 00:12 ?        00:00:00 ora_lgwr_woo  
  15. oracle    2709     1  0 00:12 ?        00:00:01 ora_ckpt_woo  
  16. oracle    2711     1  0 00:12 ?        00:00:00 ora_smon_woo  
  17. oracle    2713     1  0 00:12 ?        00:00:00 ora_reco_woo  
  18. oracle    2715     1  0 00:12 ?        00:00:00 ora_mmon_woo  
  19. oracle    2717     1  0 00:12 ?        00:00:00 ora_mmnl_woo  
  20. oracle    2719     1  0 00:12 ?        00:00:00 ora_d000_woo  
  21. oracle    2721     1  0 00:12 ?        00:00:00 ora_s000_woo  
  22. oracle    2728     1  0 00:12 ?        00:00:00 ora_rvwr_woo  
  23.   
  24. SQL> select host_name,instance_name,status from gv$instance;  
  25.   
  26. HOST_NAME  INSTANCE_NAME    STATUS  
  27. ---------- ---------------- ------------  
  28. db01       woo              OPEN  
  29. db02        woo               OPEN  

 

日志排查:

        OSmessage:

 

 
  1. Oct 30 13:48:23 db01 kernel: lpfc 0000:1b:00.0: 1:(0):0203 Devloss timeout on WWPN 20:34:00:80:e5:3f:7b:f0 NPort x0000e4 Data: x0 x7 x0  
  2. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:0 Selection Retry count exhausted  
  3. Oct 30 13:48:23 db01 kernel: 7 [RAIDarray.mpp]oracledb:0:0 Path Failed  
  4. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:0 No new path: fall to failover controller case. vcmnd SN 74635 pdev H8:C0:T0:L0 0x00/0x00/0x00 0x00010000 mpp_status:6  
  5. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:0 Failed controller to 1. retry. vcmnd SN 74635 pdev H8:C0:T0:L0 0x00/0x00/0x00 0x00010000 mpp_status:6  
  6. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:0 Selection Retry count exhausted  
  7. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:0 No new path: fall to failover controller case. vcmnd SN 74625 pdev H8:C0:T0:L0 0x00/0x00/0x00 0x00010000 mpp_status:6  
  8. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:0 Failed controller to 1. retry. vcmnd SN 74625 pdev H8:C0:T0:L0 0x00/0x00/0x00 0x00010000 mpp_status:6  
  9. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  10. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74645 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  11. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74645 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  12. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  13. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74644 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  14. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74644 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  15. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  16. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74643 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  17. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74643 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  18. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  19. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74642 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  20. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74642 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  21. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  22. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74634 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  23. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74634 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  24. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  25. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74632 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  26. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74632 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  27. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  28. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74631 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  29. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74631 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  30. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  31. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74624 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  32. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74624 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  33. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  34. Oct 30 13:48:23 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74622 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  35. Oct 30 13:48:23 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74622 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  36. Oct 30 13:48:23 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  37. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74621 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  38. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74621 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  39. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  40. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74620 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  41. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74620 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  42. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:1 Selection Retry count exhausted  
  43. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:1 No new path: fall to failover controller case. vcmnd SN 74619 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  44. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:1 Failed controller to 1. retry. vcmnd SN 74619 pdev H8:C0:T0:L1 0x00/0x00/0x00 0x00010000 mpp_status:6  
  45. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:2 Selection Retry count exhausted  
  46. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:2 No new path: fall to failover controller case. vcmnd SN 74641 pdev H8:C0:T0:L2 0x00/0x00/0x00 0x00010000 mpp_status:6  
  47. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:2 Failed controller to 1. retry. vcmnd SN 74641 pdev H8:C0:T0:L2 0x00/0x00/0x00 0x00010000 mpp_status:6  
  48. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:2 Selection Retry count exhausted  
  49. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:2 No new path: fall to failover controller case. vcmnd SN 74633 pdev H8:C0:T0:L2 0x00/0x00/0x00 0x00010000 mpp_status:6  
  50. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:2 Failed controller to 1. retry. vcmnd SN 74633 pdev H8:C0:T0:L2 0x00/0x00/0x00 0x00010000 mpp_status:6  
  51. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:2 Selection Retry count exhausted  
  52. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:2 No new path: fall to failover controller case. vcmnd SN 74623 pdev H8:C0:T0:L2 0x00/0x00/0x00 0x00010000 mpp_status:6  
  53. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:2 Failed controller to 1. retry. vcmnd SN 74623 pdev H8:C0:T0:L2 0x00/0x00/0x00 0x00010000 mpp_status:6  
  54. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:3 Selection Retry count exhausted  
  55. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:3 No new path: fall to failover controller case. vcmnd SN 74636 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  56. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:3 Failed controller to 1. retry. vcmnd SN 74636 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  57. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:3 Selection Retry count exhausted  
  58. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:3 No new path: fall to failover controller case. vcmnd SN 74626 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  59. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:3 Failed controller to 1. retry. vcmnd SN 74626 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  60. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:3 Selection Retry count exhausted  
  61. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:3 No new path: fall to failover controller case. vcmnd SN 74615 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  62. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:3 Failed controller to 1. retry. vcmnd SN 74615 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  63. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:3 Selection Retry count exhausted  
  64. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:3 No new path: fall to failover controller case. vcmnd SN 74610 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  65. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:3 Failed controller to 1. retry. vcmnd SN 74610 pdev H8:C0:T0:L3 0x00/0x00/0x00 0x00010000 mpp_status:6  
  66. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:4 Selection Retry count exhausted  
  67. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:4 No new path: fall to failover controller case. vcmnd SN 74637 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  68. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:4 Failed controller to 1. retry. vcmnd SN 74637 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  69. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:4 Selection Retry count exhausted  
  70. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:4 No new path: fall to failover controller case. vcmnd SN 74630 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  71. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:4 Failed controller to 1. retry. vcmnd SN 74630 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  72. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:4 Selection Retry count exhausted  
  73. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:4 No new path: fall to failover controller case. vcmnd SN 74614 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  74. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:4 Failed controller to 1. retry. vcmnd SN 74614 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  75. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:4 Selection Retry count exhausted  
  76. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:4 No new path: fall to failover controller case. vcmnd SN 74609 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  77. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:4 Failed controller to 1. retry. vcmnd SN 74609 pdev H8:C0:T0:L4 0x00/0x00/0x00 0x00010000 mpp_status:6  
  78. Oct 30 13:48:24 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:5 Selection Retry count exhausted  
  79. Oct 30 13:48:24 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:5 No new path: fall to failover controller case. vcmnd SN 74638 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  80. Oct 30 13:48:24 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:5 Failed controller to 1. retry. vcmnd SN 74638 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  81. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:5 Selection Retry count exhausted  
  82. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:5 No new path: fall to failover controller case. vcmnd SN 74629 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  83. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:5 Failed controller to 1. retry. vcmnd SN 74629 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  84. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:5 Selection Retry count exhausted  
  85. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:5 No new path: fall to failover controller case. vcmnd SN 74616 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  86. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:5 Failed controller to 1. retry. vcmnd SN 74616 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  87. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:5 Selection Retry count exhausted  
  88. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:5 No new path: fall to failover controller case. vcmnd SN 74613 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  89. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:5 Failed controller to 1. retry. vcmnd SN 74613 pdev H8:C0:T0:L5 0x00/0x00/0x00 0x00010000 mpp_status:6  
  90. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:6 Selection Retry count exhausted  
  91. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:6 No new path: fall to failover controller case. vcmnd SN 74639 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  92. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:6 Failed controller to 1. retry. vcmnd SN 74639 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  93. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:6 Selection Retry count exhausted  
  94. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:6 No new path: fall to failover controller case. vcmnd SN 74628 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  95. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:6 Failed controller to 1. retry. vcmnd SN 74628 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  96. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:6 Selection Retry count exhausted  
  97. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:6 No new path: fall to failover controller case. vcmnd SN 74618 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  98. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:6 Failed controller to 1. retry. vcmnd SN 74618 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  99. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:6 Selection Retry count exhausted  
  100. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:6 No new path: fall to failover controller case. vcmnd SN 74611 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  101. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:6 Failed controller to 1. retry. vcmnd SN 74611 pdev H8:C0:T0:L6 0x00/0x00/0x00 0x00010000 mpp_status:6  
  102. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:7 Selection Retry count exhausted  
  103. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:7 No new path: fall to failover controller case. vcmnd SN 74640 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  104. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:7 Failed controller to 1. retry. vcmnd SN 74640 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  105. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:7 Selection Retry count exhausted  
  106. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:7 No new path: fall to failover controller case. vcmnd SN 74627 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  107. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:7 Failed controller to 1. retry. vcmnd SN 74627 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  108. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:7 Selection Retry count exhausted  
  109. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:7 No new path: fall to failover controller case. vcmnd SN 74617 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  110. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:7 Failed controller to 1. retry. vcmnd SN 74617 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  111. Oct 30 13:48:25 db01 kernel: 94 [RAIDarray.mpp]oracledb:0:0:7 Selection Retry count exhausted  
  112. Oct 30 13:48:25 db01 kernel: 496 [RAIDarray.mpp]oracledb:0:0:7 No new path: fall to failover controller case. vcmnd SN 74612 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  113. Oct 30 13:48:25 db01 kernel: 497 [RAIDarray.mpp]oracledb:0:0:7 Failed controller to 1. retry. vcmnd SN 74612 pdev H8:C0:T0:L7 0x00/0x00/0x00 0x00010000 mpp_status:6  
  114. Oct 30 13:48:25 db01 kernel: 10 [RAIDarray.mpp]oracledb:1 Failover command issued  
  115. Oct 30 13:48:25 db01 kernel: 801 [RAIDarray.mpp]Failover succeeded to oracledb:1<strong>  
  116. </strong>  

 

ASMalert日志信息:

 
  1. Thu Oct 30 13:47:40 2014  
  2. kjbdomdet send to inst 2  
  3. detach from dom 4, sending detach message to inst 2  
  4. WARNING: Offline for disk OCR_VOTE1 in mode 0x7f failed.  
  5. WARNING: Offline for disk OCR_VOTE2 in mode 0x7f failed.  
  6. WARNING: Offline for disk OCR_VOTE3 in mode 0x7f failed.  
  7. WARNING: Offline for disk OCR_VOTE4 in mode 0x7f failed.  
  8. WARNING: Offline for disk OCR_VOTE5 in mode 0x7f failed.  
  9. Thu Oct 30 13:47:40 2014  
  10. List of instances:  
  11.  1 2  
  12. Dirty detach reconfiguration started (new ddet inc 1, cluster inc 4)  
  13.  Global Resource Directory partially frozen for dirty detach  
  14. * dirty detach - domain 4 invalid = TRUE   
  15.  17 GCS resources traversed, 0 cancelled  
  16. Dirty Detach Reconfiguration complete  
  17. Thu Oct 30 13:47:40 2014  
  18. WARNING: dirty detached from domain 4  
  19. NOTE: cache dismounted group 4/0x4558828B (OCR_VOT001)   
  20. SQL> alter diskgroup OCR_VOT001 dismount force /* ASM SERVER:1163428491 */   
  21. Thu Oct 30 13:47:40 2014  
  22. NOTE: cache deleting context for group OCR_VOT001 4/0x4558828b  
  23. GMON dismounting group 4 at 19 for pid 28, osid 17335  
  24. NOTE: Disk OCR_VOTE1 in mode 0x7f marked for de-assignment  
  25. NOTE: Disk OCR_VOTE2 in mode 0x7f marked for de-assignment  
  26. NOTE: Disk OCR_VOTE3 in mode 0x7f marked for de-assignment  
  27. NOTE: Disk OCR_VOTE4 in mode 0x7f marked for de-assignment  
  28. NOTE: Disk OCR_VOTE5 in mode 0x7f marked for de-assignment  
  29. NOTE:Waiting for all pending writes to complete before de-registering: grpnum 4  
  30. Thu Oct 30 13:47:58 2014  
  31.  Received dirty detach msg from inst 2 for dom 4  
  32. Thu Oct 30 13:47:58 2014  
  33. List of instances:  
  34.  1 2  
  35. Dirty detach reconfiguration started (new ddet inc 2, cluster inc 4)  
  36.  Global Resource Directory partially frozen for dirty detach  
  37. * dirty detach - domain 4 invalid = TRUE   
  38.  0 GCS resources traversed, 0 cancelled  
  39. freeing rdom 4  
  40. Dirty Detach Reconfiguration complete  
  41. Thu Oct 30 13:48:10 2014  
  42. NOTE:Waiting for all pending writes to complete before de-registering: grpnum 4  
  43. Thu Oct 30 13:48:24 2014  
  44. ASM Health Checker found 1 new failures  
  45. Thu Oct 30 13:48:26 2014  
  46. Errors in file /DBSoft/grid/diag/asm/+asm/+ASM1/trace/+ASM1_ora_6826.trc:  
  47. ORA-15079: ASM file is closed  
  48. Errors in file /DBSoft/grid/diag/asm/+asm/+ASM1/trace/+ASM1_ora_6826.trc:  
  49. ORA-15079: ASM file is closed  
  50. Errors in file /DBSoft/grid/diag/asm/+asm/+ASM1/trace/+ASM1_ora_6826.trc:  
  51. ORA-15079: ASM file is closed  
  52. Errors in file /DBSoft/grid/diag/asm/+asm/+ASM1/trace/+ASM1_ora_6826.trc:  
  53. ORA-15079: ASM file is closed  
  54. Errors in file /DBSoft/grid/diag/asm/+asm/+ASM1/trace/+ASM1_ora_6826.trc:  
  55. ORA-15079: ASM file is closed  
  56. WARNING: requested mirror side 1 of virtual extent 0 logical extent 0 offset 6754304 is not allocated; I/O request failed  
  57. WARNING: requested mirror side 2 of virtual extent 0 logical extent 1 offset 6754304 is not allocated; I/O request failed  
  58. WARNING: requested mirror side 3 of virtual extent 0 logical extent 2 offset 6754304 is not allocated; I/O request failed  
  59. Errors in file /DBSoft/grid/diag/asm/+asm/+ASM1/trace/+ASM1_ora_6826.trc:  
  60. ORA-15079: ASM file is closed  
  61. ORA-15079: ASM file is closed  
  62. ORA-15079: ASM file is closed  
  63. Thu Oct 30 13:48:26 2014  
  64. SQL> alter diskgroup OCR_VOT001 check /* proxy */   
  65. Thu Oct 30 13:48:40 2014  
  66. SUCCESS: diskgroup OCR_VOT001 was dismounted  
  67. SUCCESS: alter diskgroup OCR_VOT001 dismount force /* ASM SERVER:1163428491 */  
  68. Thu Oct 30 13:48:40 2014  
  69. ORA-15032: not all alterations performed  
  70. ORA-15001: diskgroup "OCR_VOT001" does not exist or is not mounted  
  71. ERROR: alter diskgroup OCR_VOT001 check /* proxy */  
  72. Thu Oct 30 13:48:40 2014  
  73. NOTE: diskgroup resource ora.OCR_VOT001.dg is offline  
  74. SUCCESS: ASM-initiated MANDATORY DISMOUNT of group OCR_VOT001  
  75. Thu Oct 30 13:48:46 2014  
  76. NOTE: client exited [6814]  
  77. Thu Oct 30 13:48:47 2014  
  78. NOTE: [crsd.bin@db01 (TNS V1-V3) 17643] opening OCR file  
  79. Thu Oct 30 13:48:49 2014  
  80. NOTE: [crsd.bin@db01 (TNS V1-V3) 17656] opening OCR file  
  81. Thu Oct 30 13:48:51 2014  
  82. NOTE: [crsd.bin@db01 (TNS V1-V3) 17673] opening OCR file  
  83. Thu Oct 30 13:48:53 2014  
  84. NOTE: [crsd.bin@db01 (TNS V1-V3) 17720] opening OCR file  
  85. Thu Oct 30 13:48:55 2014  
  86. NOTE: [crsd.bin@db01 (TNS V1-V3) 17740] opening OCR file  
  87. Thu Oct 30 13:49:02 2014  
  88. NOTE: [crsd.bin@db01 (TNS V1-V3) 17760] opening OCR file  
  89. Thu Oct 30 13:49:04 2014  
  90. NOTE: [crsd.bin@db01 (TNS V1-V3) 17773] opening OCR file  
  91. Thu Oct 30 13:49:06 2014  
  92. NOTE: [crsd.bin@db01 (TNS V1-V3) 17790] opening OCR file  
  93. Thu Oct 30 13:49:08 2014  
  94. NOTE: [crsd.bin@db01 (TNS V1-V3) 17812] opening OCR file  
  95. Thu Oct 30 13:49:10 2014  
  96. NOTE: [crsd.bin@db01 (TNS V1-V3) 17826] opening OCR file  
  97. Thu Oct 30 13:49:42 2014  
  98. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18043] opening OCR file  
  99. Thu Oct 30 13:49:43 2014  
  100. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18087] opening OCR file  
  101. Thu Oct 30 13:49:43 2014  
  102. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18221] opening OCR file  
  103. Thu Oct 30 13:49:44 2014  
  104. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18274] opening OCR file  
  105. Thu Oct 30 13:49:44 2014  
  106. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18292] opening OCR file  
  107. Thu Oct 30 13:49:45 2014  
  108. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18416] opening OCR file  
  109. Thu Oct 30 13:49:45 2014  
  110. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18434] opening OCR file  
  111. Thu Oct 30 13:49:46 2014  
  112. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18536] opening OCR file  
  113. Thu Oct 30 13:49:47 2014  
  114. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18641] opening OCR file  
  115. Thu Oct 30 13:49:47 2014  
  116. NOTE: [crsctl.bin@db01 (TNS V1-V3) 18659] opening OCR file  
  117. Thu Oct 30 13:53:36 2014  
  118. WARNING: Waited 15 secs for write IO to PST disk 0 in group 1.  
  119. WARNING: Waited 15 secs for write IO to PST disk 0 in group 1.  
  120. WARNING: Waited 15 secs for write IO to PST disk 0 in group 2.  
  121. WARNING: Waited 15 secs for write IO to PST disk 0 in group 2.  
  122. WARNING: Waited 15 secs for write IO to PST disk 0 in group 3.  
  123. WARNING: Waited 15 secs for write IO to PST disk 0 in group 3.  
  124. Thu Oct 30 13:54:43 2014  
  125. NOTE: [crsctl.bin@db01 (TNS V1-V3) 19810] opening OCR file  

CRS日志:

 
  1. 2014-10-30 13:48:26.715: [   CRSPE][1174640960]{2:1454:184} RI [ora.OCR_VOT001.dg db02 1] new target state: [OFFLINE] old value: [ONLINE]  
  2. 2014-10-30 13:48:26.716: [  CRSOCR][1166235968]{2:1454:184} Multi Write Batch processing...  
  3. 2014-10-30 13:48:26.716: [   CRSPE][1174640960]{2:1454:184} RI [ora.OCR_VOT001.dg db02 1] new internal state: [STOPPING] old value: [STABLE]  
  4. 2014-10-30 13:48:26.716: [   CRSPE][1174640960]{2:1454:184} Sending message to agfw: id = 3284  
  5. 2014-10-30 13:48:26.716: [   CRSPE][1174640960]{2:1454:184} CRS-2673: Attempting to stop 'ora.OCR_VOT001.dg' on 'db02'  
  6.   
  7. 2014-10-30 13:48:26.720: [   CRSPE][1174640960]{2:1454:184} Received reply to action [Stop] message ID: 3284  
  8. 2014-10-30 13:48:26.725: [  OCRRAW][1166235968]proprior: Header check from OCR device 0 offset 6651904 failed (26).  
  9. 2014-10-30 13:48:26.725: [  OCRRAW][1166235968]proprior: Retrying buffer read from another mirror for disk group [+OCR_VOT001] for block at offset [6651904]  
  10. 2014-10-30 13:48:26.725: [  OCRASM][1166235968]proprasmres: Total 0 mirrors detected  
  11. 2014-10-30 13:48:26.725: [  OCRASM][1166235968]proprasmres: Only 1 mirror found in this disk group.  
  12. 2014-10-30 13:48:26.725: [  OCRASM][1166235968]proprasmres: Need to invoke checkdg. Mirror #0 has an invalid buffer.   
  13. 2014-10-30 13:48:26.740: [   CRSPE][1174640960]{2:1454:184} Received reply to action [Stop] message ID: 3284  
  14. 2014-10-30 13:48:26.740: [   CRSPE][1174640960]{2:1454:184} RI [ora.OCR_VOT001.dg db02 1] new internal state: [STABLE] old value: [STOPPING]  
  15. 2014-10-30 13:48:26.740: [   CRSPE][1174640960]{2:1454:184} RI [ora.OCR_VOT001.dg db02 1] new external state [OFFLINE] old value: [ONLINE] label = []   
  16. 2014-10-30 13:48:26.740: [   CRSPE][1174640960]{2:1454:184} CRS-2677: Stop of 'ora.OCR_VOT001.dg' on 'db02' succeeded  
  17.   
  18. 2014-10-30 13:48:26.740: [  CRSRPT][1176742208]{2:1454:184} Published to EVM CRS_RESOURCE_STATE_CHANGE for ora.OCR_VOT001.dg  
  19. 2014-10-30 13:48:40.891: [  OCRASM][1166235968]proprasmres: kgfoControl returned error [8]  
  20. [  OCRASM][1166235968]SLOS : SLOS: cat=8, opn=kgfoCkDG01, dep=15032, loc=kgfokge  
  21.   
  22. 2014-10-30 13:48:40.891: [  OCRASM][1166235968]ASM Error Stack : ORA-27091: unable to queue I/O  
  23. ORA-15079: ASM file is closed  
  24. ORA-06512: at line 4  
  25.   
  26. 2014-10-30 13:48:55.542: [ CRSMAIN][199140176] Initializing OCR  
  27. [   CLWAL][199140176]clsw_Initialize: OLR initlevel [70000]  
  28. 2014-10-30 13:48:55.805: [  OCRASM][199140176]proprasmo: Error in open/create file in dg [OCR_VOT001]  
  29. [  OCRASM][199140176]SLOS : SLOS: cat=8, opn=kgfoOpen01, dep=15056, loc=kgfokge  
  30.   
  31. 2014-10-30 13:48:55.805: [  OCRASM][199140176]ASM Error Stack :   
  32. 2014-10-30 13:48:55.825: [  OCRASM][199140176]proprasmo: kgfoCheckMount returned [6]  
  33. 2014-10-30 13:48:55.825: [  OCRASM][199140176]proprasmo: The ASM disk group OCR_VOT001 is not found or not mounted  
  34. 2014-10-30 13:48:55.825: [  OCRRAW][199140176]proprioo: Failed to open [+OCR_VOT001]. Returned proprasmo() with [26]. Marking location as UNAVAILABLE.  
  35. 2014-10-30 13:48:55.825: [  OCRRAW][199140176]proprioo: No OCR/OLR devices are usable  
  36. 2014-10-30 13:48:55.825: [  OCRASM][199140176]proprasmcl: asmhandle is NULL  
  37. 2014-10-30 13:48:55.826: [    GIPC][199140176] gipcCheckInitialization: possible incompatible non-threaded init from [prom.c : 690], original from [clsss.c : 5343]  
  38. 2014-10-30 13:48:55.826: [ default][199140176]clsvactversion:4: Retrieving Active Version from local storage.  
  39. 2014-10-30 13:48:55.827: [ CSSCLNT][199140176]clssgsgrppubdata: group (ocr_db-cluster) not found  
  40. 2014-10-30 13:48:55.827: [  OCRRAW][199140176]proprio_repairconf: Failed to retrieve the group public data. CSS ret code [20]  
  41. 2014-10-30 13:48:55.830: [  OCRRAW][199140176]proprioo: Failed to auto repair the OCR configuration.  
  42. 2014-10-30 13:48:55.830: [  OCRRAW][199140176]proprinit: Could not open raw device   
  43. 2014-10-30 13:48:55.830: [  OCRASM][199140176]proprasmcl: asmhandle is NULL  
  44. 2014-10-30 13:48:55.831: [  OCRAPI][199140176]a_init:16!: Backend init unsuccessful : [26]  
  45. 2014-10-30 13:48:55.832: [  CRSOCR][199140176] OCR context init failure.  Error: PROC-26: Error while accessing the physical storage  
  46. 2014-10-30 13:48:55.832: [    CRSD][199140176] Created alert : (:CRSD00111:) :  Could not init OCR, error: PROC-26: Error while accessing the physical storage  
  47. 2014-10-30 13:48:55.832: [    CRSD][199140176][PANIC] CRSD exiting: Could not init OCR, code: 26  
  48. 2014-10-30 13:48:55.832: [    CRSD][199140176] Done.  

故障处理有两种方法:

多路径切换层面,参考如下:

FailOverQuiescenceTime:

Quiescence Timeout before Failover (Mode Select Page 2C) command. Thetime,in seconds,the array will wait for a quiescence condition to clear for an explicitfailover operation. A typical setting is 20 seconds.

 

FailedPathCheckingInterval:

This parameter defines how long (in seconds) the MPP drivershould wait before initiating a path-validation action.Default value is 60 seconds.

 

Egg:

 

 
  1. [root@db01 ~]# cat /etc/mpp.conf  
  2. VirtualDiskProductId=VirtualDisk  
  3. DebugLevel=0x0  
  4. NotReadyWaitTime=270  
  5. BusyWaitTime=270  
  6. QuiescenceWaitTime=270  
  7. InquiryWaitTime=60  
  8. MaxLunsPerArray=256  
  9. MaxPathsPerController=4  
  10. ScanInterval=60  
  11. InquiryInterval=1  
  12. MaxArrayModules=30  
  13. ErrorLevel=3  
  14. SelectionTimeoutRetryCount=0  
  15. UaRetryCount=10  
  16. RetryCount=10  
  17. SynchTimeout=170  
  18. FailOverQuiescenceTime=20  
  19. FailoverTimeout=120  
  20. FailBackToCurrentAllowed=1  
  21. ControllerIoWaitTime=300  
  22. ArrayIoWaitTime=600  
  23. DisableLUNRebalance=0  
  24. SelectiveTransferMaxTransferAttempts=5  
  25. SelectiveTransferMinIOWaitTime=3  
  26. IdlePathCheckingInterval=60  
  27. RecheckFailedPathWaitTime=30  
  28. FailedPathCheckingInterval=60  
  29. ArrayFailoverWaitTime=300  
  30. PrintSenseBuffer=0  
  31. ClassicModeFailover=0  
  32. AVTModeFailover=0  
  33. LunFailoverDelay=3  
  34. LoadBalancePolicy=1  
  35. ImmediateVirtLunCreate=0  
  36. BusResetTimeout=150  
  37. LunScanDelay=2  
  38. AllowHBAsgDevs=0  
  39. S2ToS3Key=471f51f35ec5426e  

 

 

ASM检测时间方面:

        只需要调整ASM隐含参数 _asm_hbeatiowait的值将其调大些,我这直接调到120了,重新执行五组测试,问题没有再现,故障解决。

(参看隐含参数值得方法参考:archive-1980)

 

Egg:

 

 
  1. [root@db01 ~] # su – gird  
  2. [grid@db01 ~] $ sqlplus sysasm/oracle  
  3. SQL*Plus: Release 11.2.0.4.0 Production on Wed Nov 12 22:15:18 2014  
  4. Copyright (c) 1982, 2013, Oracle.  All rights reserved.  
  5.   
  6. Connected to:  
  7. Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production  
  8. With the Partitioning, OLAP, Data Mining and Real Application Testing options  
  9.   
  10. SQL> alter system set "_asm_hbeatiowait"=120 scope=spfile sid='*';  
  11. System altered.  
  12. SQL> <span style="color:#ff0000;">  
  13. </span>  



(责任编辑:IT)