記一次ohasd程序啟動失敗啟庫失敗
故障現象：crsctl start crs失敗
第一次嘗試啟crs
| [[email protected] bin]# ./crsctl start crs CRS-4124: Oracle High Availability Services startup failed. CRS-4000: Command Start failed, or completed with errors. |
檢視資料庫的asm日誌，除了ohasdOUT.log外沒有任何日誌寫入
|
[[email protected] ohasd]$ tail -100 ohasdOUT.log 2018-11-13 03:08:05 Changing directory to /u01/app/11.2.0/grid/log/odsrac1/ohasd OHASD starting OHASD stderr redirected to ohasdOUT.log 2018-11-13 03:10:55 Changing directory to /u01/app/11.2.0/grid/log/odsrac1/ohasd OHASD starting OHASD stderr redirected to ohasdOUT.log 2018-11-13 03:16:52 Changing directory to /u01/app/11.2.0/grid/log/odsrac1/ohasd OHASD starting |
檢視程序狀態
| [[email protected] bin]# ps -ef |grep ohas root 908 93879 0 03:10 pts/2 00:00:00 grep --color=auto grid root 196038 1 0 03:08 ? 00:00:00 /u01/app/11.2.0/grid/bin/ohasd.bin reboot |
再次strace 啟庫
|
[[email protected] bin]# strace ./crsctl start crs 。。。。。。。。。。。。。。省略。。。。。。。。。。。。。。。。。 socket(AF_INET6, SOCK_DGRAM, IPPROTO_IP) = 3 bind(3, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0 getsockname(3, {sa_family=AF_INET6, sin6_port=htons(57023), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0 getpeername(3, 0x7ffe466055c8, 0x7ffe46605698) = -1 ENOTCONN (Transport endpoint is not connected) getsockopt(3, SOL_SOCKET, SO_SNDBUF, [262144], [4]) = 0 getsockopt(3, SOL_SOCKET, SO_RCVBUF, [262144], [4]) = 0 fcntl(3, F_SETFD, FD_CLOEXEC) = 0 fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK) = 0 times({tms_utime=4, tms_stime=3, tms_cutime=0, tms_cstime=0}) = 542893845 socket(AF_LOCAL, SOCK_STREAM, 0) = 5 access("/var/tmp/.oracle/sOHASD_UI_SOCKET", F_OK) = -1 ENOENT (No such file or directory) access("/var/tmp/o/sOHASD_UI_SOCKET", F_OK) = -1 ENOENT (No such file or directory) close(5) = 0 brk(NULL) = 0x1a67000 brk(NULL) = 0x1a67000 brk(0x196e000) = 0x196e000 brk(NULL) = 0x196e000 close(3) = 0 open("/u01/app/11.2.0/grid/crs/mesg/crsus.msb", O_RDONLY) = 3 fcntl(3, F_SETFD, FD_CLOEXEC) = 0 lseek(3, 0, SEEK_SET) = 0 read(3, "\25\23\"\1\23\3\t\t\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 256) = 256 lseek(3, 512, SEEK_SET) = 512 read(3, "L\26\n(\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 lseek(3, 1024, SEEK_SET) = 1024 read(3, "\t\0\16\0\22\0\26\0\31\0u\0\242\0\256\0\272\0\325\0\341\0\362\0\374\0\4\1\17\0010\1"..., 512) = 512 lseek(3, 112640, SEEK_SET) = 112640 read(3, "\t\0\33\22\1\0>\0\34\22\0\0{\0\35\22\0\0\227\0\36\22\0\0\343\0\37\22\0\0\16\1"..., 512) = 512 lseek(3, 162816, SEEK_SET) = 162816 read(3, "\377\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 lseek(3, 163328, SEEK_SET) = 163328 read(3, "\377\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 lseek(3, 163840, SEEK_SET) = 163840 read(3, "\0\0\0\0\0\0\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 close(3) = 0 open("/u01/app/11.2.0/grid/crs/mesg/crsus.msb", O_RDONLY) = 3 fcntl(3, F_SETFD, FD_CLOEXEC) = 0 lseek(3, 0, SEEK_SET) = 0 read(3, "\25\23\"\1\23\3\t\t\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 256) = 256 lseek(3, 512, SEEK_SET) = 512 read(3, "L\26\n(\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 lseek(3, 1024, SEEK_SET) = 1024 read(3, "\t\0\16\0\22\0\26\0\31\0u\0\242\0\256\0\272\0\325\0\341\0\362\0\374\0\4\1\17\0010\1"..., 512) = 512 lseek(3, 112640, SEEK_SET) = 112640 read(3, "\t\0\33\22\1\0>\0\34\22\0\0{\0\35\22\0\0\227\0\36\22\0\0\343\0\37\22\0\0\16\1"..., 512) = 512 lseek(3, 162816, SEEK_SET) = 162816 read(3, "\377\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 lseek(3, 163328, SEEK_SET) = 163328 read(3, "\377\377\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 lseek(3, 163840, SEEK_SET) = 163840 read(3, "\0\0\0\0\0\0\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512 close(3) = 0nanosleep({5, 0}, ^Cstrace: Process 66414 detached |
檢視asm告警日誌
|
[[email protected] odsrac1 ]$ tail -100f alertodsrac1.log 。。。。。。。。。。。。。。。省略。。。。。。。。。。。。。。。。。。。 2018-11-13 04:14:53.667: [ohasd(31535)]CRS-0715:Oracle High Availability Service has timed out waiting for init.ohasd to be started. 2018-11-13 04:40:47.385: [ohasd(41793)]CRS-0715:Oracle High Availability Service has timed out waiting for init.ohasd to be started. 2018-11-13 04:47:50.922: [ohasd(44582)]CRS-0715:Oracle High Availability Service has timed out waiting for init.ohasd to be started. 2018-11-13 04:58:57.003: [ohasd(49155)]CRS-0715:Oracle High Availability Service has timed out waiting for init.ohasd to be started. 2018-11-13 05:07:06.904: [ohasd(52377)]CRS-0715:Oracle High Availability Service has timed out waiting for init.ohasd to be started. 2018-11-13 05:12:00.189: [ohasd(54529)]CRS-0715:Oracle High Availability Service has timed out waiting for init.ohasd to be started. 2018-11-13 05:24:20.235: [ohasd(59551)]CRS-0715:Oracle High Availability Service has timed out waiting for init.ohasd to be started. |
檢視ohasd的執行級別
| cd /u01/app/11.2.0/grid/log/odsrac1/ohasd [[email protected] ohasd]$ who -r run-level 5 2018-10-31 11:44 [[email protected] ohasd]$ |
手動啟ohasd
|
cd /etc/init.d/ [[email protected] init.d]# ls functions init.ohasd netconsole network ohasd README [[email protected] init.d]# nohup /etc/init.d/init.ohasd run & [1] 71336 [[email protected] init.d]# nohup: ignoring input and appending output to ‘nohup.out’ [[email protected] init.d]# |
檢視程序狀態
| [[email protected] init.d]# ps -ef|grep ohas root 66419 1 0 05:31 ? 00:00:01 /u01/app/11.2.0/grid/bin/ohasd.bin reboot root 71336 54328 0 05:44 pts/11 00:00:00 /bin/sh /etc/init.d/init.ohasd run root 72019 54328 0 05:44 pts/11 00:00:00 grep --color=auto ohas [[email protected] init.d]# |
再次啟動crs
| [[email protected] bin]# ./crsctl start crs [[email protected] bin]# [[email protected] bin]# ./crsctl check crs CRS-4638: Oracle High Availability Services is online CRS-4535: Cannot communicate with Cluster Ready Services CRS-4529: Cluster Synchronization Services is online CRS-4534: Cannot communicate with Event Manager [[email protected] bin]# |
CRS啟動成功
| [[email protected] bin]# ./crsctl stat res -t -------------------------------------------------------------------------------- NAME TARGET STATE SERVER STATE_DETAILS -------------------------------------------------------------------------------- Local Resources -------------------------------------------------------------------------------- ora.CRS_VOTE_01.dg ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.LISTENER.lsnr ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.ODS_DATA_01.dg ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.asm ONLINE ONLINE odsrac1 Started ONLINE ONLINE odsrac2 Started ora.gsd OFFLINE OFFLINE odsrac1 OFFLINE OFFLINE odsrac2 ora.net1.network ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.ons ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 -------------------------------------------------------------------------------- Cluster Resources -------------------------------------------------------------------------------- ora.LISTENER_SCAN1.lsnr 1 ONLINE ONLINE odsrac2 ora.cvu 1 ONLINE ONLINE odsrac2 ora.oc4j 1 ONLINE ONLINE odsrac2 ora.odsdb.db 1 OFFLINE OFFLINE 2 ONLINE ONLINE odsrac2 Open ora.odsrac1.vip 1 ONLINE ONLINE odsrac1 ora.odsrac2.vip 1 ONLINE ONLINE odsrac2 ora.scan1.vip 1 ONLINE ONLINE odsrac2 [[email protected] bin]# |
最後啟庫的時候還有一點小插曲：
|
[[email protected] bin]# ./srvctl start database -d odsdb PRCC-1014 : odsdb was already running PRCR-1004 : Resource ora.odsdb.db is already running PRCR-1079 : Failed to start resource ora.odsdb.db CRS-5017: The resource action "ora.odsdb.db start" encountered the following error: ORA-01078: failure in processing system parameters ORA-01565: error in identifying file '+ODS_DATA_01/odsdb/spfileodsdb.ora' ORA-17503: ksfdopn:2 Failed to open file +ODS_DATA_01/odsdb/spfileodsdb.ora ORA-01034: ORACLE not available ORA-27123: unable to attach to shared memory segment Linux-x86_64 Error: 13: Permission denied Additional information: 26 Additional information: 8781886 . For details refer to "(:CLSN00107:)" in "/u01/app/11.2.0/grid/log/odsrac1/agent/crsd/oraagent_oracle//oraagent_oracle.log". CRS-2674: Start of 'ora.odsdb.db' on 'odsrac1' failed CRS-2528: Unable to place an instance of 'ora.odsdb.db' as all possible servers are occupied by the resource [[email protected] bin]# |
手動啟庫
| SQL> startup ORA-01078: failure in processing system parameters ORA-01565: error in identifying file '+ODS_DATA_01/odsdb/spfileodsdb.ora' ORA-17503: ksfdopn:2 Failed to open file +ODS_DATA_01/odsdb/spfileodsdb.ora ORA-01034: ORACLE not available ORA-27123: unable to attach to shared memory segment Linux-x86_64 Error: 13: Permission denied Additional information: 26 Additional information: 8781886 SQL> |
這個報錯以前遇到過，檢視Oracle的二進位制檔案的許可權
| [[email protected] bin]# ls -rlt /u01/app/oracle/product/11.2.0/dbhome_1/bin/oracle -rwsr-s--x. 1 oracle asmadmin 239501424 Nov 13 04:01 /u01/app/oracle/product/11.2.0/dbhome_1/bin/oracle [[email protected] bin]# |
木有問題，傻眼了，幾經週轉，發現了只看了oracle使用者
檢視grid使用者的oracle二進位制檔案許可權
| [[email protected] bin]$ ls -rlt oracle -rwxr-xr-x. 1 grid oinstall 209836184 Nov 1 05:38 oracle [[email protected] bin]$ |
重新授權
| [[email protected] bin]$ chmod 6751 oracle [[email protected] bin]$ ls -rlt oracle -rwsr-s--x. 1 grid oinstall 209836184 Nov 1 05:38 oracle [[email protected] bin]$ |
再次啟庫：
|
SQL> startup ORACLE instance started. Total System Global Area 1.6195E+11 bytes Fixed Size 2261968 bytes Variable Size 2.5770E+10 bytes Database Buffers 1.3583E+11 bytes Redo Buffers 345251840 bytes Database mounted. Database opened. SQL> |
檢視叢集狀態
| [[email protected] bin]# ./crsctl stat res -t -------------------------------------------------------------------------------- NAME TARGET STATE SERVER STATE_DETAILS -------------------------------------------------------------------------------- Local Resources -------------------------------------------------------------------------------- ora.CRS_VOTE_01.dg ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.LISTENER.lsnr ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.ODS_DATA_01.dg ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.asm ONLINE ONLINE odsrac1 Started ONLINE ONLINE odsrac2 Started ora.gsd OFFLINE OFFLINE odsrac1 OFFLINE OFFLINE odsrac2 ora.net1.network ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 ora.ons ONLINE ONLINE odsrac1 ONLINE ONLINE odsrac2 -------------------------------------------------------------------------------- Cluster Resources -------------------------------------------------------------------------------- ora.LISTENER_SCAN1.lsnr 1 ONLINE ONLINE odsrac2 ora.cvu 1 ONLINE ONLINE odsrac2 ora.oc4j 1 ONLINE ONLINE odsrac2 ora.odsdb.db 1 ONLINE ONLINE odsrac1 Open 2 ONLINE ONLINE odsrac2 Open ora.odsrac1.vip 1 ONLINE ONLINE odsrac1 ora.odsrac2.vip 1 ONLINE ONLINE odsrac2 ora.scan1.vip 1 ONLINE ONLINE odsrac2 [[email protected] bin]# |
至此，本次故障處理完成