ORA-12560: ora.crsd fails to startup with high number of users in oinstall group

(Doc ID 2420305.1)

Last updated on JULY 12, 2018

Applies to:

Oracle Database - Enterprise Edition - Version 11.2.0.3 to 11.2.0.3 [Release 11.2]
Information in this document applies to any platform.

Symptoms

The ora.crsd fails to start with the following errors

/export/home/oragrid $ crsctl stat res -t -init

--------------------------------------------------------------------------------
NAME TARGET STATE SERVER STATE_DETAILS
--------------------------------------------------------------------------------
Cluster Resources
--------------------------------------------------------------------------------
ora.asm
1 ONLINE ONLINE  Started
ora.cluster_interconnect.haip
1 ONLINE ONLINE 
ora.crf
1 ONLINE ONLINE 
ora.crsd
1 ONLINE OFFLINE

 

alert log:

2012-11-14 13:50:33.981 [ohasd (5249)] CRS-1301: The Oracle high availability service was started on node a05cdacb.
2012-11-14 13:50:33.991 [ohasd (5249)] CRS-8017: Location: There are 2 reboot advisor log files in / var / opt / oracle / lastgasp (0 notified and 0 errors occurred)
2012-11-14 13:50:35.327 [/opt/oracle/app/11.2.0/grid/bin/oraagent.bin(5415)] CRS - 5019: All OCR locations are on the ASM disk group [DG_CRS] and any disk group is mounted Not.
Details are in "(: CLSN00100 :)" ("/opt/oracle/app/11.2.0/grid/log/test/agent/ohasd/oraagent_grid/oraagent_grid.log").
2012-11-14 13:50:41.862 [ohasd (5249)] CRS - 2302: Can not get GPnP profile. Error CLSGPNP_NO_DAEMON (GPNPD daemon is not running).
2012-11-14 13:50:42.086 [gpnpd (5605)] CRS - 2328: GPNPD was started on node a 05 cdacb.
2012-11-14 13:50:44.945 [cssd (5725)] CRS - 1713: CSSD daemon is running in clustered mode
012-11-14 13:50:46.497 [ohasd (5249)] CRS-2767: Recovery of resource state for 'ora.diskmon' was not attempted because target state is offline
2012-11-14 13:51:06.495 [cssd (5725)] CRS-1707: Lease acquisition for node a 05 cdacb, number 1 has been completed
2012-11-14 13:51:18.904 [cssd (5725)] CRS - 1605: CSSD voting file is online: / dev / sfdsk / DB_class 0001 / rdsk / crs - 01. For details, see /opt/oracle/app/11.2.0/grid/log/test/cssd/ocssd.log.
2012-11-14 13:51:18.930 [cssd (5725)] CRS - 1605: The CSSD voting file is online: / dev / sfdsk / DB_class 0001 / rdsk / crs _ 02. For details, see /opt/oracle/app/11.2.0/grid/log/test/cssd/ocssd.log.
2012-11-14 13:51:18.947 [cssd (5725)] CRS - 1605: CSSD voting file is online: / dev / sfdsk / DB_class 0001 / rdsk / crs _ 03. For details, see /opt/oracle/app/11.2.0/grid/log/test/cssd/ocssd.log.
2012-11-14 13:51:27.971 [cssd (5725)] CRS-1601: CSSD reconfiguration is complete. The active node is a55 cdacb.
2012-11-14 13:51:29.969 [ctssd (6476)] CRS-2403: The cluster time synchronization service of host a 05 cdacb is in observer mode.
2012-11-14 13:51:30.358 [ctssd (6476)] CRS-2407: The reference node of the new cluster time synchronization service is host a05cdacb.
2012-11-14 13:51:30.359 [ctssd (6476)] CRS - 2401: Cluster time synchronization service started on host a05cdacb.
2012-11-14 13:51:30.359 [ctssd (6476)] CRS-2401: Cluster time synchronization service started on host a05cdacb.
2012-11-14 13:51:57.244 [crsd (6964)] CRS - 1013: Can not access OCR location in ASM disk group. For details, see /opt/oracle/app/11.2.0/grid/log/test/crsd/crsd.log.
2012-11-14 13:51:57.305 [crsd (6964)] CRS - 0804: Cluster Ready Service failed with Oracle Cluster Registry error [PROC - 26: An error occurred while accessing physical storage
ORA-12560: TNS: protocol adapter error occurred
] Was interrupted. For details, see (: CRSD00111:) (/ opt / oracle / app / 11.2.0 / grid / log / test / crsd / crsd.log).

2012-11-14 13:51:57.809 [ohasd (5249)] CRS - 2765: Resource 'ora.crsd' failed on server 'test'.
2012-11-14 13:51:59.285 [crsd (7011)] CRS-1013: Unable to access OCR location in ASM disk group. For details, see /opt/oracle/app/11.2.0/grid/log/test/crsd/crsd.log.
2012-11-14 13:51:59.305 [crsd (7011)] CRS - 0804: Cluster Ready Service failed with Oracle Cluster Registry error [PROC - 26: An error occurred while accessing physical storage
ORA-12560: TNS: protocol adapter error occurred
] Was interrupted. For details, see (: CRSD00111:) (/ opt / oracle / app / 11.2.0 / grid / log / test / crsd / crsd.log).
2012-11-14 13:51:59.870 [ohasd (5249)] CRS - 2765: Resource 'ora.crsd' failed on server 'test'.

crsd.log

2012-11-14 13:51:56.803: [ CRSMAIN][1] Initializing OCR
[ CLWAL][1]clsw_Initialize: OLR initlevel [70000]
2012-11-14 13:51:57.220: [ OCRASM][1]proprasmo: Error in open/create file in dg [DG_CRS]
[ OCRASM][1]SLOS : SLOS: cat=7, opn=kgfoAl06, dep=12560, loc=kgfokge

2012-11-14 13:51:57.220: [ OCRASM][1]ASM Error Stack : ORA-12560:TNS: protocol adapter error occurred

2012-11-14 13:51:57.243: [ OCRASM][1]proprasmo: kgfoCheckMount returned [7]
2012-11-14 13:51:57.244: [ OCRASM][1]proprasmo: The ASM instance is down
2012-11-14 13:51:57.245: [ OCRRAW][1]proprioo: Failed to open [+DG_CRS]. Returned proprasmo() with [26]. Marking location as UNAVAILABLE.
2012-11-14 13:51:57.245: [ OCRRAW][1]proprioo: No OCR/OLR devices are usable
2012-11-14 13:51:57.245: [ OCRASM][1]proprasmcl: asmhandle is NULL
2012-11-14 13:51:57.245: [ GIPC][1] gipcCheckInitialization: possible incompatible non-threaded init from [prom.c : 690], original from [clsss.c : 5326]
2012-11-14 13:51:57.254: [ default][1]clsvactversion:4: Retrieving Active Version from local storage.
2012-11-14 13:51:57.292: [ CSSCLNT][1]clssgsgrppubdata: group (ocr_A05CDACA) not found

2012-11-14 13:51:57.292: [ OCRRAW][1]proprio_repairconf: Failed to retrieve the group public data. CSS ret code [20]
2012-11-14 13:51:57.303: [ OCRRAW][1]proprioo: Failed to auto repair the OCR configuration.
2012-11-14 13:51:57.303: [ OCRRAW][1]proprinit: Could not open raw device
2012-11-14 13:51:57.303: [ OCRASM][1]proprasmcl: asmhandle is NULL
2012-11-14 13:51:57.304: [ OCRAPI][1]a_init:16!: Backend init unsuccessful : [26]
2012-11-14 13:51:57.305: [ CRSOCR][1] OCR context init failure. Error: PROC - 26: An error occurred while accessing physical storage
ORA-12560: TNS: protocol adapter error occurred

2012-11-14 13:51:57.305: [ CRSMAIN][1] Created alert : (:CRSD00111:) : Could not init OCR, error: PROC - 26: An error occurred while accessing physical storage
ORA-12560: TNS: protocol adapter error occurred

2012-11-14 13:51:57.305: [ CRSD][1][PANIC] CRSD exiting: Could not init OCR, code: 26
2012-11-14 13:51:57.305: [ CRSD][1] Done.

 ocrconfig log

2012-11-14 13:51:24.301: [OCRCHECK][1]ocrcheck starts...
[ CLWAL][1]clsw_Initialize: OLR initlevel [30000]
2012-11-14 13:51:34.692: [ OCRASM][1]proprasmo: Failed to open file in dirty mode
2012-11-14 13:51:34.692: [ OCRASM][1]proprasmo: Error in open/create file in dg [DG_CRS]
[ OCRASM][1]SLOS : SLOS: cat=8, opn=kgfolclcpi1, dep=204, loc=kgfokge

2012-11-14 13:51:34.692: [ OCRASM][1]ASM Error Stack : ORA-12560: TNS:protocol adapter error
2012-11-14 13:51:34.793: [ OCRASM][1]proprasmo: kgfoCheckMount returned [7]
2012-11-14 13:51:34.793: [ OCRASM][1]proprasmo: The ASM instance is down
2012-11-14 13:51:34.816: [ OCRRAW][1]proprioo: Failed to open [+DG_CRS].
Returned proprasmo() with [26]. Marking location as UNAVAILABLE.
2012-11-14 13:51:34.816: [ OCRRAW][1]proprioo: No OCR/OLR devices are usable
2012-11-14 13:51:34.816: [ OCRASM][1]proprasmcl: asmhandle is NULL
2012-11-14 13:51:34.816: [ OCRRAW][1]proprinit: Could not open raw device
2012-11-14 13:51:34.816: [ OCRASM][1]proprasmcl: asmhandle is NULL
2012-11-14 13:51:34.816: [ default][1]a_init:7!: Backend init unsuccessful : [26]
2012-11-14 13:51:34.816: [OCRCHECK][1]initreboot: Failed to initialize OCR in REBOOT level. Retval:[26] Error:[PROC-26: Error while accessing the
physical storage Operating System error
ORA-12560: TNS:protocol adapter error ] [OCRCHECK][1]initreboot: Attempting to initialize OCR in DEFAULT level and update a key so that vote information is updated.
2012-11-14 13:51:34.817: [ OCRMSG][1]prom_waitconnect: CONN NOT ESTABLISHED (0,29,1,2)
2012-11-14 13:51:34.817: [ OCRMSG][1]GIPC error [29] msg [gipcretConnectionRefused]
2012-11-14 13:51:34.817: [ OCRMSG][1]prom_connect: error while waiting for connection complete [24]
2012-11-14 13:51:34.817: [OCRCHECK][1]initreboot: Failed to initialize OCR in DEFAULT level. Retval:[32] Error:[PROC-32: Cluster Ready Services on the
local node is not running Messaging error [gipcretConnectionRefused] [29]]
2012-11-14 13:51:34.817: [OCRCHECK][1]Failed to access OCR repository. Retval [26] Error [PROC-26: Error while accessing the physical storage Operating System error
ORA-12560: TNS:protocol adapter error ]
2012-11-14 13:51:34.817: [OCRCHECK][1]Failed to initialize ocrchek2
2012-11-14 13:51:34.817: [OCRCHECK][1]Exiting [status=failed]...

There are many users for "oinstall" group in /etc/group
oinstall::200:gipblk,gzpctm,gzpuse,gzpfuo,gisfu001,gisme001,aas00001,aaa00001,rfs00011,rfp00011,RFH00011,rfs00021,                        rfp00021,rfs00022,rfp00022,aap00001,AAH00001,aas00011,aap00011,aas00021,aap00021,aas00022,aap00022,aas00012, aap00012,aas00013,aap00013,afs00001,afp00001,AFH00001,afs00021,afp00021,afs00022,afp00022,afs00023,afp00023, ags00001,agp00001,AGH00001,ags00021,agp00021,ags00022,agp00022,ahs00001,ahp00001,AHH00001,ahs00021,ahp00021, ajs00001,ajp00001,AJH00001,ajs00021,ajp00021,ajs00022,ajp00022,aqs00001,aqp00001,AQH00001,aqs00021,aqp00021

 sqlnet trace:

[19-12-2012 13:53:46:080] nsmal: 168 bytes at 0x100141190

[19-12-2012 13:53:46:080] nsmal: normal exit

[19-12-2012 13:53:46:080] nsbal: normal exit

[19-12-2012 13:53:46:080] nsiorini: exit (0)

[19-12-2012 13:53:46:080] nscpxget: entry

[19-12-2012 13:53:46:080] snsbitts_ts: entry

[19-12-2012 13:53:46:080] snsbitts_ts: acquired the bit

[19-12-2012 13:53:46:080] snsbitts_ts: normal exit

[19-12-2012 13:53:46:080] snsbitcl_ts: entry

[19-12-2012 13:53:46:080] snsbitcl_ts: normal exit

[19-12-2012 13:53:46:080] nscpxget: normal exit

[19-12-2012 13:53:46:080] nsopenalloc_nsntx: nlhthput on mplx_ht_nsgbu:ctx=28f950, nsntx=43c010

[19-12-2012 13:53:46:080] nsopenmplx: normal exit

[19-12-2012 13:53:46:080] ntpcon: entry

[19-12-2012 13:53:46:080] ntpcon: toc = 6

[19-12-2012 13:53:46:080] ntpcon: exit

[19-12-2012 13:53:46:080] nsopen: opening transport...

[19-12-2012 13:53:46:080] ntpcon: entry

[19-12-2012 13:53:46:080] ntpcon: toc = 1

[19-12-2012 13:53:46:080] sntpcall: entry

[19-12-2012 13:53:46:083] sntpcall: detaching from parent with additional fork

[19-12-2012 13:53:46:086] sntpcall: hdl[IR]=18, hdl[IW]=17

[19-12-2012 13:53:46:103] sntpcall: result string is NTP3 0

[19-12-2012 13:53:46:103] sntpcall: Can't read from pipe; err[1] = 3

[19-12-2012 13:53:46:103] sntpcall: exit

[19-12-2012 13:53:46:103] ntpcon: exit

[19-12-2012 13:53:46:103] nserror: entry

[19-12-2012 13:53:46:103] nserror: nsres: id=0, op=65, ns=12560, ns2=0; nt[0]=530, nt[1]=3, nt[2]=0; ora[0]=0, ora[1]=0, ora[2]=0

[19-12-2012 13:53:46:103] nsopen: unable to open transport

[19-12-2012 13:53:46:103] nstoClearTimeout: entry

[19-12-2012 13:53:46:103] nstoClearTimeout: ATO disabled for ctx=0x10028f950

[19-12-2012 13:53:46:103] nstoClearTimeout: STO disabled for ctx=0x10028f950

[19-12-2012 13:53:46:103] nstoClearTimeout: RTO disabled for ctx=0x10028f950

[19-12-2012 13:53:46:103] nstoClearTimeout: PITO disabled for ctx=0x10028f950

[19-12-2012 13:53:46:103] nstoUpdateActive: entry

[19-12-2012 13:53:46:103] nstoUpdateActive: Active timeout is -1 (see nstotyp)

[19-12-2012 13:53:46:103] snsbitts_ts: entry

[19-12-2012 13:53:46:103] snsbitts_ts: acquired the bit

[19-12-2012 13:53:46:103] snsbitts_ts: normal exit

[19-12-2012 13:53:46:103] snsbitcl_ts: entry

[19-12-2012 13:53:46:103] snsbitcl_ts: normal exit

 

Changes

 

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms