1 Reply Latest reply: Dec 12, 2012 12:10 AM by asahide RSS

    root.sh script is failing with ora.diskmon failed to start error CLSN00010

    911818
      Hi ,

      At the time of Oracle Grid installation - I executed root.sh script on first node and it got successful but after running on second node it is getting failed with the below error. It seems ora.diskmon process is not getting start.

      Your help will be appreciated..................


      2012-12-12 14:17:40.166: [CRSTIMER][2950585232] Timer Thread Starting.
      2012-12-12 14:17:46.163: [ora.diskmon][2982054800] [start] DiskmonAgent::connect {
      2012-12-12 14:18:39.086: [    AGFW][2971564944] Agent received the message: AGENT_HB[Engine] ID 12293:1278
      2012-12-12 14:18:40.533: [    AGFW][2992544656]Created alert : (:CRSAGF00113:) : Aborting the command: start for resource: ora.diskmon 1 1
      2012-12-12 14:18:40.533: [ora.diskmon][2992544656] [start] clsn_agent::abort {
      2012-12-12 14:18:40.533: [ora.diskmon][2992544656] [start] abort {
      2012-12-12 14:18:40.533: [ora.diskmon][2992544656] [start] abort command: start
      2012-12-12 14:18:40.533: [ora.diskmon][2992544656] [start] tryActionLock {
      2012-12-12 14:18:40.779: [ora.diskmon][2982054800] [start] DiskmonAgent::connect: skgznp_connect failed with error 56815 and the timeout expired
      2012-12-12 14:18:40.780: [ora.diskmon][2982054800] [start] (null) category: 56815, operation: connect, loc: skgznpcon6, OS error: 2, other:
      2012-12-12 14:18:40.780: [ora.diskmon][2982054800] [start] DiskmonAgent::connect } error
      2012-12-12 14:18:40.780: [ora.diskmon][2982054800] [start] DiskmonAgent::start }
      2012-12-12 14:18:40.780: [ora.diskmon][2982054800] [start] clsn_agent::start }
      2012-12-12 14:18:44.536: [ora.diskmon][2992544656] [start] got lock
      2012-12-12 14:18:44.536: [ora.diskmon][2992544656] [start] tryActionLock }
      2012-12-12 14:18:44.536: [ora.diskmon][2992544656] [start] abort }
      2012-12-12 14:18:44.536: [ora.diskmon][2992544656] [start] clsn_agent::abort }
      2012-12-12 14:18:44.536: [    AGFW][2992544656] Command: start for resource: ora.diskmon 1 1 completed with status: TIMEDOUT
      2012-12-12 14:18:44.537: [    AGFW][2992544656] Executing command: check for resource: ora.diskmon 1 1
      2012-12-12 14:18:44.537: [ora.diskmon][2992544656] [check] DiskmonAgent::check {
      2012-12-12 14:18:44.537: [ora.diskmon][2992544656] [check] DiskmonAgent::connect {
      2012-12-12 14:18:44.537: [ora.diskmon][2992544656] [check] DiskmonAgent::connect: skgznp_connect failed with error 56815 and the timeout expired
      2012-12-12 14:18:44.537: [ora.diskmon][2992544656] [check] (null) category: 56815, operation: connect, loc: skgznpcon6, OS error: 2, other:
      2012-12-12 14:18:44.537: [ora.diskmon][2992544656] [check] DiskmonAgent::connect } error
      2012-12-12 14:18:44.537: [ora.diskmon][2992544656] [check] DiskmonAgent::check } 5
      2012-12-12 14:18:44.537: [    AGFW][2992544656] check for resource: ora.diskmon 1 1 completed with status: FAILED
      2012-12-12 14:18:44.538: [    AGFW][2971564944] Agent sending reply for: RESOURCE_START[ora.diskmon 1 1] ID 4098:1111
      2012-12-12 14:18:44.540: [    AGFW][2971564944] ora.diskmon 1 1 state changed from: STARTING to: FAILED
      2012-12-12 14:18:44.541: [    AGFW][2971564944] Agent sending last reply for: RESOURCE_START[ora.diskmon 1 1] ID 4098:1111
      2012-12-12 14:18:44.541: [    AGFW][2971564944] Agent has no resources to be monitored.Sending suicide request.
      2012-12-12 14:18:44.541: [    AGFW][2971564944] Agent sending message to PE: AGENT_SUICIDE[Proxy] ID 20486:42
      2012-12-12 14:18:44.566: [    AGFW][2971564944] Agent is commiting suicide.
      2012-12-12 14:18:44.570: [    AGFW][2971564944] Agent is exiting with exit code: 1
      2012-12-12 14:18:45.117: [    AGFW][3045365456] Starting the agent: /u01/app/11.2.0/grid/log/rac2/agent/ohasd/orarootagent_root/
      2012-12-12 14:18:45.119: [   AGENT][3045365456] Agent framework initialized, Process Id = 11988
      2012-12-12 14:18:45.127: [ USRTHRD][3045365456] Utils::getCrsHome crsHome /u01/app/11.2.0/grid
      2012-12-12 14:18:45.129: [ USRTHRD][3045365456] Process::convertPidToString pid = 11988
      2012-12-12 14:18:45.130: [    AGFW][3045365456] SERVER IPC CONNECT STR: (ADDRESS=(PROTOCOL=IPC)(KEY=OHASD_IPC_SOCKET_11))
      2012-12-12 14:18:45.131: [CLSFRAME][3045365456] Inited lsf context 0x9a25d68
      2012-12-12 14:18:45.131: [CLSFRAME][3045365456] Initing CLS Framework messaging
      2012-12-12 14:18:45.132: [CLSFRAME][3045365456] New Framework state: 2
      2012-12-12 14:18:45.132: [CLSFRAME][3045365456] M2M is starting...
      2012-12-12 14:18:45.143: [ CRSCOMM][3045365456] m_pClscCtx=0x9a4fb50m_pUgblm=0x9a52428
      2012-12-12 14:18:45.143: [ CRSCOMM][3045365456] Starting send thread
      2012-12-12 14:18:45.152: [ CRSCOMM][3034270608] clsIpc: sendWork thread started.
      2012-12-12 14:18:45.153: [ CRSCOMM][3023780752] IPC Client thread started listening
      2012-12-12 14:18:45.153: [ CRSCOMM][3023780752] init data sent from server
      2012-12-12 14:18:45.153: [CLSFRAME][3045365456] New IPC Member:Relative:OHASD:rac2
      2012-12-12 14:18:45.154: [CLSFRAME][3045365456] New process connected to us ID:Relative Info:OHASD:rac2
      2012-12-12 14:18:45.155: [CLSFRAME][3045365456] Starting thread model named: MultiThread
      2012-12-12 14:18:45.160: [CLSFRAME][3045365456] Starting thread model named: SingleThread
      2012-12-12 14:18:45.160: [CLSFRAME][3045365456] Starting thread model named: SingleThreadT
      2012-12-12 14:18:45.160: [CLSFRAME][3045365456] New Framework state: 3
      2012-12-12 14:18:45.161: [    AGFW][3045365456] Agent Framework started successfully
      2012-12-12 14:18:45.162: [    AGFW][2971331472] Agfw engine module has enabled...
      2012-12-12 14:18:45.163: [CLSFRAME][2971331472] Module Enabling is complete
      2012-12-12 14:18:45.163: [CLSFRAME][2971331472] New Framework state: 6
      2012-12-12 14:18:45.165: [    AGFW][2971331472] Agent is started with userid: root , expected user: root
      2012-12-12 14:18:45.165: [    AGFW][2971331472] Agent sending message to PE: AGENT_HANDSHAKE[Proxy] ID 20484:14
      2012-12-12 14:18:45.205: [    AGFW][2971331472] Agent received the message: RESTYPE_ADD[ora.crs.type] ID 8196:1318
      2012-12-12 14:18:45.206: [    AGFW][2971331472] Added new restype: ora.crs.type
      2012-12-12 14:18:45.207: [    AGFW][2971331472] Agent sending last reply for: RESTYPE_ADD[ora.crs.type] ID 8196:1318
      2012-12-12 14:18:45.208: [    AGFW][2971331472] Agent received the message: RESTYPE_ADD[ora.ctss.type] ID 8196:1320
      2012-12-12 14:18:45.208: [    AGFW][2971331472] Added new restype: ora.ctss.type
      2012-12-12 14:18:45.209: [    AGFW][2971331472] Agent sending last reply for: RESTYPE_ADD[ora.ctss.type] ID 8196:1320
      2012-12-12 14:18:45.209: [    AGFW][2971331472] Agent received the message: RESTYPE_ADD[ora.diskmon.type] ID 8196:1322
      2012-12-12 14:18:45.209: [    AGFW][2971331472] Added new restype: ora.diskmon.type
      2012-12-12 14:18:45.209: [    AGFW][2971331472] Agent sending last reply for: RESTYPE_ADD[ora.diskmon.type] ID 8196:1322
      2012-12-12 14:18:45.211: [    AGFW][2971331472] Agent received the message: RESTYPE_ADD[ora.drivers.acfs.type] ID 8196:1324
      2012-12-12 14:18:45.211: [    AGFW][2971331472] Added new restype: ora.drivers.acfs.type
      2012-12-12 14:18:45.212: [    AGFW][2971331472] Agent sending last reply for: RESTYPE_ADD[ora.drivers.acfs.type] ID 8196:1324
      2012-12-12 14:18:45.212: [    AGFW][2971331472] Agent received the message: RESOURCE_ADD[ora.diskmon 1 1] ID 4356:1326
      2012-12-12 14:18:45.213: [    AGFW][2971331472] Added new resource: ora.diskmon 1 1 to the agfw
      2012-12-12 14:18:45.214: [    AGFW][2971331472] Agent sending last reply for: RESOURCE_ADD[ora.diskmon 1 1] ID 4356:1326
      2012-12-12 14:18:45.216: [    AGFW][2971331472] Agent received the message: RESOURCE_CLEAN[ora.diskmon 1 1] ID 4100:1327
      2012-12-12 14:18:45.216: [    AGFW][2971331472] Preparing CLEAN command for: ora.diskmon 1 1
      2012-12-12 14:18:45.216: [    AGFW][2971331472] ora.diskmon 1 1 state changed from: UNKNOWN to: CLEANING
      2012-12-12 14:18:45.218: [    AGFW][2981821328] Executing command: clean for resource: ora.diskmon 1 1
      2012-12-12 14:18:45.218: [ora.diskmon][2981821328] [clean] clsn_agent::clean {
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] DaemonAgent{
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] }DaemonAgent
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] DiskmonAgent::DiskmonAgent {
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] InitAttrs {
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] __IS_HASD_AGENT=TRUE
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] }InitAttrs
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] DiskmonAgent::DiskmonAgent }
      2012-12-12 14:18:45.219: [ora.diskmon][2981821328] [clean] DiskmonAgent::clean {
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Arg Value = -d
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Arg Value = -z
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Arg Value = 8
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Total Count of Environment Variables = 3
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Adding Environment Variables ORAAGENT_ACTION=TRUE
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Adding Environment Variables __IS_HASD_AGENT=
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Adding Environment variable from USR_ORA_ENV CTSS_REBOOT=TRUE
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] Utils:execCmd action = 4 flags = 6 ohome = (null) cmdname = diskmon.
      2012-12-12 14:18:45.220: [ora.diskmon][2981821328] [clean] getOracleHomeAttrib: oracle_home = /u01/app/11.2.0/grid
      2012-12-12 14:18:45.222: [ora.diskmon][2981821328] [clean] Utils:execCmd Running the binary from /u01/app/11.2.0/grid/bin/diskmon
      2012-12-12 14:18:45.240: [CRSTIMER][2950351760] Timer Thread Starting.
      2012-12-12 14:18:45.543: [ora.diskmon][2981821328] [clean] (:CLSN00010:)Utils:execCmd scls_process_join() uret 1

      2012-12-12 14:18:45.545: [ora.diskmon][2981821328] [clean] Exception type=2 string=CRS-5016: Process "/u01/app/11.2.0/grid/bin/diskmon" spawned by agent "/u01/app/11.2.0/grid/bin/orarootagent.bin" for action "clean" failed: details at "(:CLSN00010:)" in "/u01/app/11.2.0/grid/log/rac2/agent/ohasd/orarootagent_root/orarootagent_root.log"

      2012-12-12 14:18:45.545: [    AGFW][2981821328] sending status msg [CRS-5016: Process "/u01/app/11.2.0/grid/bin/diskmon" spawned by agent "/u01/app/11.2.0/grid/bin/orarootagent.bin" for action "clean" failed: details at "(:CLSN00010:)" in "/u01/app/11.2.0/grid/log/rac2/agent/ohasd/orarootagent_root/orarootagent_root.log"
      ] for clean for resource: ora.diskmon 1 1
      2012-12-12 14:18:45.547: [ora.diskmon][2981821328] [clean] execCmd ret = 1
      2012-12-12 14:18:45.547: [ora.diskmon][2981821328] [clean] DiskmonAgent::clean } nopipe
      2012-12-12 14:18:45.547: [ora.diskmon][2981821328] [clean] clsn_agent::clean }
      2012-12-12 14:18:45.547: [    AGFW][2981821328] Command: clean for resource: ora.diskmon 1 1 completed with status: SUCCESS
      2012-12-12 14:18:45.549: [    AGFW][2992311184] Executing command: check for resource: ora.diskmon 1 1
      2012-12-12 14:18:45.549: [ora.diskmon][2992311184] [check] DiskmonAgent::check {
      2012-12-12 14:18:45.550: [ora.diskmon][2992311184] [check] DiskmonAgent::connect {
      2012-12-12 14:18:45.550: [ora.diskmon][2992311184] [check] DiskmonAgent::connect: skgznp_connect failed with error 56815 and the timeout expired
      2012-12-12 14:18:45.550: [ora.diskmon][2992311184] [check] (null) category: 56815, operation: connect, loc: skgznpcon6, OS error: 2, other:
      2012-12-12 14:18:45.550: [ora.diskmon][2992311184] [check] DiskmonAgent::connect } error
      2012-12-12 14:18:45.550: [ora.diskmon][2992311184] [check] DiskmonAgent::check } 2
      2012-12-12 14:18:45.550: [    AGFW][2992311184] check for resource: ora.diskmon 1 1 completed with status: PLANNED_OFFLINE
      2012-12-12 14:18:45.551: [    AGFW][2971331472] Agent sending reply for: RESOURCE_CLEAN[ora.diskmon 1 1] ID 4100:1327
      2012-12-12 14:18:45.560: [    AGFW][2971331472] Agent sending reply for: RESOURCE_CLEAN[ora.diskmon 1 1] ID 4100:1327
      2012-12-12 14:18:45.567: [    AGFW][2971331472] ora.diskmon 1 1 state changed from: CLEANING to: PLANNED_OFFLINE
      2012-12-12 14:18:45.567: [    AGFW][2971331472] Agent sending last reply for: RESOURCE_CLEAN[ora.diskmon 1 1] ID 4100:1327
      2012-12-12 14:18:45.606: [    AGFW][2971331472] Agent has no resources to be monitored.Sending suicide request.
      2012-12-12 14:18:45.607: [    AGFW][2971331472] Agent sending message to PE: AGENT_SUICIDE[Proxy] ID 20486:40