ORACLE_HOME entry in Listener and mismatch in OCR caused to failed to start Listener in 5-node 11gR2 RAC

This is 5-node RAC of 11gR2, Due to some storage changes CRS went down on the two nodes, however the CRS were started after the node reboot and all the services are up and unfortunately listeners from all the nodes aren’t started. I got chance to correct the mistake where the issue was and i captured all the logs what user been executed and will see how it is been fixed.

racnode3707> ./crsctl start resource ora.LISTENER.lsnr
CRS-2672: Attempting to start 'ora.LISTENER.lsnr' on 'racnode3707'
CRS-2672: Attempting to start 'ora.LISTENER.lsnr' on 'racnode3702'
CRS-2672: Attempting to start 'ora.LISTENER.lsnr' on 'racnode3703'
CRS-2672: Attempting to start 'ora.LISTENER.lsnr' on 'racnode3708'
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3707/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3702/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3703/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3708/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3702/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3703/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3707/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-5016: Process "/u00/app/11.2.0.3/grid/bin/lsnrctl" spawned by agent "/u00/app/11.2.0.3/grid/bin/oraagent.bin" for action "start" failed: details at "(:CLSN00010:)" in "/u00/app/11.2.0.3/grid/log/racnode3708/agent/crsd/oraagent_oracle/oraagent_oracle.log"
CRS-2674: Start of 'ora.LISTENER.lsnr' on 'racnode3702' failed
CRS-2674: Start of 'ora.LISTENER.lsnr' on 'racnode3703' failed
CRS-2674: Start of 'ora.LISTENER.lsnr' on 'racnode3707' failed
CRS-2674: Start of 'ora.LISTENER.lsnr' on 'racnode3708' failed
CRS-4000: Command Start failed, or completed with errors.

Now we will verify the TNS_ADMIN environment and if not set by default, Then we can export and then try?

racnode3708> echo $TNS_ADMIN
/u00/app/11.2.0.3/grid/network/admin
racnode3708>

Again tried to start listener using “LSNRCTL” command and hence the same result. Listener failed to start on all the nodes.

racnode3707> lsnrctl start LISTENER
LSNRCTL for Linux: Version 11.2.0.3.0 - Production on 13-JUN-2013 05:43:37
Copyright (c) 1991, 2011, Oracle.  All rights reserved.
Starting /u00/app/oracle/product/11.2.0.3/database/bin/tnslsnr: please wait...
TNSLSNR for Linux: Version 11.2.0.3.0 - Production
System parameter file is /u00/app/11.2.0.3/grid/network/admin/listener.ora
Log messages written to /u00/app/oracle/diag/tnslsnr/racnode3707/listener/alert/log.xml
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=LISTENER)))
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.84.120.18)(PORT=9101)))
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.84.78.13)(PORT=9101)))
TNS-01201: Listener cannot find executable /u00/app/oracle/product/11.1.0/database/bin/oracle for SID amys
Listener failed to start. See the error message(s) above...
ora.LISTENER.lsnr
               ONLINE  ONLINE       racnode3701
               ONLINE  OFFLINE      racnode3702
               ONLINE  OFFLINE      racnode3703
               ONLINE  OFFLINE      racnode3707
               ONLINE  OFFLINE      racnode3708

Well, the database version is 11.2.0.3.0 and when listener trying to start from 11.1.0 ORACLE_HOME? We will see now the OCR configuration to check which home is attached.

racnode3707> srvctl config database -d amys01 -a
Database unique name: amys01
Database name:
Oracle home: /u00/app/oracle/product/11.2.0.3/database
Oracle user: oracle
Spfile:
Domain:
Start options: mount
Stop options: immediate
Database role: PHYSICAL_STANDBY
Management policy: AUTOMATIC
Server pools: amys01
Database instances: amys011,amys012,amys013,amys14,amys015
Disk Groups: REDO1,REDO2,DATA01
Mount point paths:
Services: amys01_srv_wcs_adhoc,amys01_srv_wcs_bodl,amys01_srv_wcs_estore,amys01_srv_wcs_estore_node1,amys01_srv_wcs_estore_node2,amys01_srv_wcs_estore_node3,amys01_srv_wcs_estore_node4,amys01_srv_wcs_estore_node5
Type: RAC
Database is enabled
Database is administrator managed
racnode3707>

So as expected the ORACLE_HOME is set to 11.2.0.3 which is correct home, Still its a question why listener is trying to use the 11.1.0 ORACLE_HOME? Now verified the listener.ora file to check the ORACLE_HOME mentioned.

#LISTENER=(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER))))           # line added by Agent
# listener.ora.racnode3701 Network Configuration File: /u00/app/11.2.0/grid/network/admin/listener.ora.racnode3701
# Generated by Oracle configuration tools.
# may need to commend out next line
ENABLE_GLOBAL_DYNAMIC_ENDPOINT_LISTENER_SCAN1 = ON
ENABLE_GLOBAL_DYNAMIC_ENDPOINT_LISTENER = ON
LISTENER_racnode3707 =
  (DESCRIPTION =
    (ADDRESS_LIST =
      (ADDRESS = (PROTOCOL = TCP)(HOST = racnode3707-vip)(PORT = 9101))
      (ADDRESS = (PROTOCOL = TCP)(HOST = 10.84.80.13)(PORT = 9101)(IP = FIRST))
    )
  )
LISTENER =
  (DESCRIPTION =
    (ADDRESS_LIST =
      (ADDRESS = (PROTOCOL = IPC)(KEY = LISTENER))
      (ADDRESS = (PROTOCOL = TCP)(HOST = 10.84.120.18)(PORT = 9101))
      (ADDRESS=(PROTOCOL=TCP)(HOST=racnode3707-dg)(PORT = 9101)
         (SEND_BUF_SIZE=9375000)
         (RECV_BUF_SIZE=9375000))
    )
  )
SID_LIST_LISTENER =
        ( SID_LIST =
        (SID_DESC =
                (GLOBAL_DBNAME = amys01_DGMGRL)
                (ORACLE_HOME = /u00/app/oracle/product/11.1.0/database)
                (SID_NAME = amys)
        )
  )
INBOUND_CONNECT_TIMEOUT_LISTENER=10
racnode3707>

Aah yes, listener.ora has wrong entry with ORACLE_HOME of 11.1.0 and hence when try to start the listener of course it uses the ORACLE_HOME mentioned in the file even though you have configured the correct home, Now modified the listener.ora file with 11.2.0.3 home and then started the listener as follows.

New listener.ora file after modifying ORACLE_HOME

SID_LIST_LISTENER =
         ( SID_LIST =
         (SID_DESC =
                 (GLOBAL_DBNAME = amys01_DGMGRL)
                 (ORACLE_HOME = /u00/app/oracle/product/11.2.0.3/database)
                 (SID_NAME = amys)
         )
   )
racnode3708> ./crsctl start resource ora.LISTENER.lsnr
CRS-2672: Attempting to start 'ora.LISTENER.lsnr' on 'racnode3708'
CRS-2676: Start of 'ora.LISTENER.lsnr' on 'racnode3708' succeeded
racnode3708>

Check the services are registered with listener or not by checking the status of Listener.

racnode3708>lsnrctl status LISTENER
LSNRCTL for Linux: Version 11.2.0.3.0 - Production on 13-JUN-2013 06:29:03
Copyright (c) 1991, 2011, Oracle.  All rights reserved.
Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER)))
STATUS of the LISTENER
------------------------
Alias                     LISTENER
Version                   TNSLSNR for Linux: Version 11.2.0.3.0 - Production
Start Date                13-JUN-2013 06:20:45
Uptime                    0 days 0 hr. 8 min. 18 sec
Trace Level               off
Security                  ON: Local OS Authentication
SNMP                      OFF
Listener Parameter File   /u00/app/11.2.0.3/grid/network/admin/listener.ora
Listener Log File         /u00/app/11.2.0.3/grid/log/diag/tnslsnr/racnode3708/listener/alert/log.xml
Listening Endpoints Summary...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=LISTENER)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.84.120.19)(PORT=9101)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.84.78.14)(PORT=9101)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.84.80.14)(PORT=9101)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.84.80.21)(PORT=9101)))
Services Summary...
Service "+ASM" has 1 instance(s).
  Instance "+ASM5", status READY, has 1 handler(s) for this service...
Service "amys01_DGMGRL" has 1 instance(s).
  Instance "amys015", status UNKNOWN, has 1 handler(s) for this service...
Service "amys01" has 1 instance(s).
  Instance "amys015", status READY, has 1 handler(s) for this service...
Service "amys01_DGB" has 1 instance(s).
  Instance "amys015", status READY, has 1 handler(s) for this service...
The command completed successfully
racnode3708>

Now we will verify listener status on all the nodes

racnode3708> srvctl status listener -l LISTENER
Listener LISTENER is enabled
Listener LISTENER is running on node(s): racnode3701,racnode3702,racnode3707,racnode3703,racnode3708
racnode3708>

All is well, Listener is running on all the nodes. But not sure why wrong ORACLE_HOME exist when there is only one ORACLE_HOME installed. However its wrong entry and changed the value in all the nodes of listener file and able to start the listener on all the nodes.

— Happy Reading —