srvctl fails to start/stop listener (Doc ID 2184058.1)

Last updated on OCTOBER 02, 2016

Applies to:

Oracle Database - Enterprise Edition - Version 11.2.0.4 and later
Information in this document applies to any platform.

Symptoms

GI "srvctl start listener" fails:

$ srvctl start listener
PRCR-1079 : Failed to start resource ora.LISTENER.lsnr
CRS-5014: Agent "/u01/app/11.2.0.4/grid/bin/oraagent.bin" timed out starting process "/u01/app/11.2.0.4/grid/bin/lsnrctl" for action "clean": details at "(:CLSN00009:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log"
CRS-5017: The resource action "ora.LISTENER.lsnr clean" encountered the following error:
(:CLSN00009:)Utils:execCmd aborted. For details refer to "(:CLSN00106:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log".

CRS-5014: Agent "/u01/app/11.2.0.4/grid/bin/oraagent.bin" timed out starting process "/u01/app/11.2.0.4/grid/bin/lsnrctl" for action "check": details at "(:CLSN00009:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log"
CRS-5017: The resource action "ora.LISTENER.lsnr check" encountered the following error:
(:CLSN00009:)Utils:execCmd aborted. For details refer to "(:CLSN00109:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log".

CRS-2680: Clean of 'ora.LISTENER.lsnr' on 'racnode1' failed

In agen trace:

2016-09-18 08:35:47.873: [ AGFW][299448640]{1:8926:484} Preparing STOP command for: ora.LISTENER.lsnr racnode1 1
2016-09-18 08:35:47.873: [ AGFW][299448640]{1:8926:484} ora.LISTENER.lsnr racnode1 1 state changed from: UNKNOWN to: STOPPING
2016-09-18 08:35:47.873: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00108:) clsn_agent::stop {
2016-09-18 08:35:47.873: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] LsnrAgent::stop {
2016-09-18 08:35:47.873: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] getResAttrib: attrib name USR_ORA_OPI value false len 5
2016-09-18 08:35:47.873: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] lsnrctl stop LISTENER

2016-09-18 08:35:47.874: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] getOracleHomeAttrib: oracle_home = /u01/app/11.2.0.4/grid
2016-09-18 08:35:47.874: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] Utils::execCmd 1 USR_ORA_ENV:ORACLE_BASE=/u01/app/grid oracleHome:/u01/app/11.2.0.4/grid CrsHome:/u01/app/11.2.0.4/grid
2016-09-18 08:35:47.874: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] Adding Environment Variables ORACLE_HOME=/u01/app/11.2.0.4/grid
2016-09-18 08:35:47.874: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] Adding Environment Variables TNS_ADMIN=/u01/app/11.2.0.4/grid/network/admin/
2016-09-18 08:35:47.874: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] Adding Environment variable from USR_ORA_ENV ORACLE_BASE=/u01/app/grid
2016-09-18 08:35:47.874: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] Utils:execCmd action = 2 flags = 38 ohome = (null) cmdname = lsnrctl.
2016-09-18 08:35:47.874: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] getOracleHomeAttrib: oracle_home = /u01/app/11.2.0.4/grid
2016-09-18 08:35:47.975: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00010:)
2016-09-18 08:35:47.975: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00010:)LSNRCTL for Linux: Version 11.2.0.4.0 - Production on 18-SEP-2016 08:35:47
2016-09-18 08:35:47.975: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00010:)
2016-09-18 08:35:47.975: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00010:)Copyright (c) 1991, 2013, Oracle. All rights reserved.
2016-09-18 08:35:47.975: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00010:)
2016-09-18 08:35:47.975: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00010:)Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER)))
2016-09-18 08:35:47.975: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00010:)
....
....
2016-09-18 08:36:47.885: [ AGENT][303651136]{1:8926:484} {1:8926:484} Created alert : (:CRSAGF00113:) : Aborting the command: stop for resource: ora.LISTENER.lsnr racnode1 1
2016-09-18 08:36:47.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] (:CLSN00110:) clsn_agent::abort {
2016-09-18 08:36:47.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] abort {
2016-09-18 08:36:47.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] Agent::abort last call info: "Agent::Agent refreshAttr"
2016-09-18 08:36:47.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] abort command: stop
2016-09-18 08:36:47.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] tryActionLock {
2016-09-18 08:36:47.913: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00009:)Utils:execCmd abort request: killing /u01/app/11.2.0.4/grid/bin/lsnrctl
2016-09-18 08:36:47.913: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] clsnUtils::error Exception type=2 string=
CRS-5014: Agent "/u01/app/11.2.0.4/grid/bin/oraagent.bin" timed out starting process "/u01/app/11.2.0.4/grid/bin/lsnrctl" for action "stop": details at "(:CLSN00009:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log"

2016-09-18 08:36:47.913: [ AGFW][299448640]{1:8926:484} Agent sending reply for: RESOURCE_STOP[ora.LISTENER.lsnr racnode1 1] ID 4099:2155
2016-09-18 08:36:47.914: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] clsnUtils::error Exception type=2 string=
CRS-5017: The resource action "ora.LISTENER.lsnr stop" encountered the following error:
(:CLSN00009:)Utils:execCmd aborted. For details refer to "(:CLSN00108:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log".

2016-09-18 08:36:47.914: [ora.LISTENER.lsnr][284932416]{1:8926:484} [stop] (:CLSN00108:) clsn_agent::stop }
2016-09-18 08:36:47.914: [ AGFW][299448640]{1:8926:484} Agent sending reply for: RESOURCE_STOP[ora.LISTENER.lsnr racnode1 1] ID 4099:2155
2016-09-18 08:36:51.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] got lock
2016-09-18 08:36:51.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] tryActionLock }
2016-09-18 08:36:51.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] abort }
2016-09-18 08:36:51.885: [ora.LISTENER.lsnr][303651136]{1:8926:484} [stop] (:CLSN00110:) clsn_agent::abort }
2016-09-18 08:36:51.885: [ AGFW][303651136]{1:8926:484} Command: stop for resource: ora.LISTENER.lsnr racnode1 1 completed with status: TIMEDOUT
2016-09-18 08:36:51.886: [ AGFW][299448640]{1:8926:484} Agent sending reply for: RESOURCE_STOP[ora.LISTENER.lsnr racnode1 1] ID 4099:2155
2016-09-18 08:36:51.886: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] getOracleHomeAttrib: oracle_home = /u01/app/11.2.0.4/grid
2016-09-18 08:36:51.886: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] Utils::execCmd 1 USR_ORA_ENV:ORACLE_BASE=/u01/app/grid oracleHome:/u01/app/11.2.0.4/grid CrsHome:/u01/app/11.2.0.4/grid
2016-09-18 08:36:51.886: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] Adding Environment Variables ORACLE_HOME=/u01/app/11.2.0.4/grid
2016-09-18 08:36:51.886: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] Adding Environment Variables TNS_ADMIN=/u01/app/11.2.0.4/grid/network/admin/
2016-09-18 08:36:51.886: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] Adding Environment variable from USR_ORA_ENV ORACLE_BASE=/u01/app/grid
2016-09-18 08:36:51.886: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] Utils:execCmd action = 3 flags = 38 ohome = (null) cmdname = lsnrctl.
2016-09-18 08:36:51.886: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] getOracleHomeAttrib: oracle_home = /u01/app/11.2.0.4/grid
2016-09-18 08:36:51.988: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00010:)
2016-09-18 08:36:51.988: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00010:)LSNRCTL for Linux: Version 11.2.0.4.0 - Production on 18-SEP-2016 08:36:51
2016-09-18 08:36:51.988: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00010:)
2016-09-18 08:36:51.988: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00010:)Copyright (c) 1991, 2013, Oracle. All rights reserved.
2016-09-18 08:36:51.988: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00010:)
2016-09-18 08:36:51.988: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00010:)Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER)))
2016-09-18 08:36:51.988: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00010:)
....
....
2016-09-18 08:38:51.900: [ AGENT][293337408]{1:8926:484} {1:8926:484} Created alert : (:CRSAGF00113:) : Aborting the command: check for resource: ora.LISTENER.lsnr racnode1 1
2016-09-18 08:38:51.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] (:CLSN00110:) clsn_agent::abort {
2016-09-18 08:38:51.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] abort {
2016-09-18 08:38:51.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] Agent::abort last call info: "Agent::Agent refreshAttr"
2016-09-18 08:38:51.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] abort command: check
2016-09-18 08:38:51.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] tryActionLock {
2016-09-18 08:38:51.973: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] (:CLSN00009:)Utils:execCmd abort request: killing /u01/app/11.2.0.4/grid/bin/lsnrctl
2016-09-18 08:38:51.974: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] clsnUtils::error Exception type=2 string=
CRS-5014: Agent "/u01/app/11.2.0.4/grid/bin/oraagent.bin" timed out starting process "/u01/app/11.2.0.4/grid/bin/lsnrctl" for action "check": details at "(:CLSN00009:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log"

2016-09-18 08:38:51.974: [ AGFW][299448640]{1:8926:484} Agent sending reply for: RESOURCE_STOP[ora.LISTENER.lsnr racnode1 1] ID 4099:2155
2016-09-18 08:38:51.974: [ora.LISTENER.lsnr][282831168]{1:8926:484} [check] clsnUtils::error Exception type=2 string=
CRS-5017: The resource action "ora.LISTENER.lsnr check" encountered the following error:
(:CLSN00009:)Utils:execCmd aborted. For details refer to "(:CLSN00109:)" in "/u01/app/11.2.0.4/grid/log/racnode1/agent/crsd/oraagent_grid/oraagent_grid.log".

2016-09-18 08:38:51.975: [ AGFW][299448640]{1:8926:484} Agent sending reply for: RESOURCE_STOP[ora.LISTENER.lsnr racnode1 1] ID 4099:2155
2016-09-18 08:38:55.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] got lock
2016-09-18 08:38:55.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] tryActionLock }
2016-09-18 08:38:55.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] abort }
2016-09-18 08:38:55.900: [ora.LISTENER.lsnr][293337408]{1:8926:484} [check] (:CLSN00110:) clsn_agent::abort }
2016-09-18 08:38:55.900: [ AGFW][293337408]{1:8926:484} Command: check for resource: ora.LISTENER.lsnr racnode1 1 completed with status: TIMEDOUT
2016-09-18 08:38:55.900: [ AGFW][299448640]{1:8926:484} ora.LISTENER.lsnr racnode1 1 state changed from: STOPPING to: UNKNOWN
2016-09-18 08:38:55.900: [ AGFW][299448640]{1:8926:484} Agent sending last reply for: RESOURCE_STOP[ora.LISTENER.lsnr racnode1 1] ID 4099:2155
2016-09-18 08:38:55.908: [ AGFW][299448640]{1:8926:484} Agent received the message: RESOURCE_CLEAN[ora.LISTENER.lsnr racnode1 1] ID 4100:2226
2016-09-18 08:38:55.908: [ AGFW][299448640]{1:8926:484} Preparing CLEAN command for: ora.LISTENER.lsnr racnode1 1
2016-09-18 08:38:55.908: [ AGFW][299448640]{1:8926:484} ora.LISTENER.lsnr racnode1 1 state changed from: UNKNOWN to: CLEANING
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00106:) clsn_agent::clean {
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] LsnrAgent::clean {
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] lsnrctl clean LISTENER

2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] getOracleHomeAttrib: oracle_home = /u01/app/11.2.0.4/grid
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] Utils::execCmd 1 USR_ORA_ENV:ORACLE_BASE=/u01/app/grid oracleHome:/u01/app/11.2.0.4/grid CrsHome:/u01/app/11.2.0.4/grid
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] Adding Environment Variables ORACLE_HOME=/u01/app/11.2.0.4/grid
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] Adding Environment Variables TNS_ADMIN=/u01/app/11.2.0.4/grid/network/admin/
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] Adding Environment variable from USR_ORA_ENV ORACLE_BASE=/u01/app/grid
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] Utils:execCmd action = 4 flags = 38 ohome = (null) cmdname = lsnrctl.
2016-09-18 08:38:55.909: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] getOracleHomeAttrib: oracle_home = /u01/app/11.2.0.4/grid
2016-09-18 08:38:56.011: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00010:)
2016-09-18 08:38:56.011: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00010:)LSNRCTL for Linux: Version 11.2.0.4.0 - Production on 18-SEP-2016 08:38:55
2016-09-18 08:38:56.011: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00010:)
2016-09-18 08:38:56.011: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00010:)Copyright (c) 1991, 2013, Oracle. All rights reserved.
2016-09-18 08:38:56.011: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00010:)
2016-09-18 08:38:56.011: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00010:)Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER)))
2016-09-18 08:38:56.011: [ora.LISTENER.lsnr][293337408]{1:8926:484} [clean] (:CLSN00010:)

ps command show's lisener process is there:

$ ps -ef|grep lsnr
....
grid 42962 33731 0 13:57 ? 00:00:00 /u01/app/11.2.0.4/grid/bin/lsnrctl status LISTENER
grid 68619 1 0 Aug16 ? 06:44:22 /u01/app/11.2.0.4/grid/bin/tnslsnr LISTENER -inherit

However, the following command hangs:

$ lsnrctl service listener

LSNRCTL for Linux: Version 11.2.0.4.0 - Production on 18-SEP-2016 14:15:10

Copyright (c) 1991, 2013, Oracle. All rights reserved.

Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER)))
==>> hangs here

 

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