11g: ORA-609 TNS-12537 and TNS-12547 or TNS-12170 in 11g Alert.log (文档 ID 1...

郑全

11g:  ORA-609  TNS-12537 and TNS-12547 or TNS-12170 in 11g Alert.log
(文档 ID 1116960.1)


In this Document

Symptoms
Changes
Cause
Solution
References


Applies to:
Oracle Net Services - Version 11.1.0.7 to 11.2.0.4 [Release 11.1 to 11.2]
Oracle Net Services - Version 12.1.0.2 to 12.1.0.2 [Release 12.1]
Information in this document applies to any platform.
***Checked for relevance on 21-APR-2014***
The issue documented here is limited in scope to 11g and newer instances.

Symptoms
The following errors are intermittently posted to the alert.log of an 11g database.
TNS-12547: TNS: Lost contact
ORA-609 Opiodr Aborting Process Unknown Ospid <nnnn>

TNS-12537: TNS: Connection closed
ORA-609 Opiodr Aborting Process Unknown Ospid

The ORA-609 might be accompanied by either the TNS-12537 or the TNS-12547 and might also include the following timeout messages:

Fatal NI connect error 12170.

TNS-12535: TNS:operation timed out
ns secondary err code: 12560
nt main err code: 505




Changes
This is likely a new installation of the 11g database.   The ORA-609 error code was introduced in 11g.  Also introduced in 11g is the ADR diagnostic method which results in TNS errors such as this to be thrown in the alert versus the sqlnet.log.
Cause
The ORA-609 error is thrown when a client connection of any kind failed to complete or aborted the connection process before the connection/authentication process was complete.
Very often, this connection abort is due to a timeout.  Beginning with 10gR2, a default value for inbound connect timeout has been set at 60 seconds.  This time limit is often inadequate for the entire connection process to complete.   
We have also discovered that the ORA-609 occurs frequently in installations where the database is monitored by DB Console and the Enterprise Manager agent (emagent).   After the DB Console is started and as a matter of routine, the emagent will repeatedly try to connect to the target instances.  We can see frequent emagent connections in the listener.log without error.  However, on occasion it may have failed to complete the connection process at the database so an ORA-609 is thrown.  The emagent will simply retry the connection and may be successful on the subsequent try.  (Provided there is no real fault occurring at the listener or database).  This temporary failure to connect will not be reported back to DB Console and there will be no indication, except for the ORA-609, that a fault occurred.
Solution


If the RDBMS is running on a Windows server, please reference the troubleshooting found in Note: 987162.1  as well as this note.


It can be somewhat challenging  to determine the origin of the client that is causing the error.
For that reason, we often recommend increasing the values for INBOUND_CONNECT_TIMEOUT at both listener and server side sqlnet.ora file as a preventive measure.  If the problem  is due to connection timeouts, an increase in the following parameters should eliminate or reduce the occurrence of the ORA-609s.
e.g.
Sqlnet.ora: SQLNET.INBOUND_CONNECT_TIMEOUT=180
Listener.ora: INBOUND_CONNECT_TIMEOUT_listener_name=120

These settings are in seconds.  Again, the default is 60.  A setting of 120 seconds should resolve most if not all ORA-609 errors.
As explained in the Cause section, The ORA-609 error is thrown when a client connection of any kind failed to complete or aborted the connection process, so ORA-609 and TNS- errors are expected while shutting down the database - as client connection will fail to complete or aborted the connection process before the connection/authentication process was complete. So please ignore the ORA-609 and TNS- errors, if these are appear while database instance is shutting down.
If the issue persists and inbound connect does not have any effect, the following steps are intended to help locate  the client that may be causing the errors.
1)  Suppress the TNS errors in the alert.log by setting the following sqlnet.ora file parameter:  
sqlnet.ora file (on the server): DIAG_ADR_ENABLED = OFF
Reload the listener following this change.
This will cause the TNS errors to be posted to the ORACLE_HOME/network/log/sqlnet.log file that is local to the database and may yield useful information about the client's address.
For example, here's a snippet from a server side sqlnet.log where client address information was posted:
Production Time: 15-FEB-2010 07:15:01
Fatal NI connect error 12537, connecting to:
(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(Host=yourhost)(Port=1521))(CONNECT_DATA=(SID=PROD1DR)(CID=(PROGRAM=sqlplus)(HOST=client_host)(USER=client))))

Observe the PROGRAM and HOST fields on the last line.  This is where the connection originated.
Be sure to match timestamps in the sqlnet.log with the timestamps of the alert.log errors.  Once you've located the offending client, you can enable client tracing to try and determine the cause.  
Add the following parameters to the sqlnet.ora file that would be referenced  by the client.
TRACE_LEVEL_CLIENT=16
TRACE_DIRECTORY_CLIENT=<dir location>
TRACE_TIMESTAMP_CLIENT=TRUE
DIAG_ADR_ENABLED=off   <====Use this only with 11g and newer clients
If you need assistance with client or server tracing, please open an SR with Global Customer Support.

2)  Check the listener.log for client connections that were logged at timestamps that match the ORA-609 timestamps as they appear in the alert.log.  The client information is recorded in each listener.log entry.  Since this error occurs AFTER the listener has handled the connection, do not expect to see errors in the listener.log.
Here's an example snippet of an incoming client connection that was posted to the listener.log:
20-JAN-2009 17:08:45 (CONNECT_DATA=(SID=orcl)(CID=(PROGRAM=D:\oracle\product\10.1.0\Db_1\perl\5.6.1\bin\MSWin32-x86\perl.exe)(HOST=myclient)

Note that the exact timestamp, program name and client host will often be recorded.  Again, once you've located the offending client, enable tracing (see above) to try to capture the connection failure.
3)  Enable server side Oracle Net tracing and capture the TNS error along with the incoming connection.
Match the PID that accompanies the ORA-609 to the server trace label.  e.g.  
ORA-609 : opiodr aborting process unknown ospid (4799_1)  *Note the PID
This PID would correspond to server trace labeled:  svr_4799.trc.  Check the server trace for either TNS error (the 609 will not appear) and try to locate the originating client address.  If assistance is needed for this investigation, please open an SR with Oracle Support.
See below for instuctions on enabling Oracle Net server tracing.

The following details the discovery of the source of an ORA-609 for a real case:
The alert.log reports the following messages intermittently but frequently:
Mon Nov 16 22:39:22 2009
ORA-609 : opiodr aborting process unknown ospid (nnnn)

Enabled Oracle Net server tracing in the sqlnet.ora file that would be referenced by the instance where the ORA-609 is being thrown.
TRACE_LEVEL_SERVER=16
TRACE_DIRECTORY_SERVER=<dir location>
TRACE_TIMESTAMP_SERVER=TRUE
DIAG_ADR_ENABLED=off
It's important to note that in GRID installations, the instance or database would reference .ora files in RDBMS_HOME/network/admin by default.  Versus GRID_HOME.

ORA-609 : opiodr aborting process unknown ospid (5233_1)

Note that the server trace file set that corresponded to this event was named svr_5233*.trc.
Of course the timestamps of the alert.log event and the server trace creation matched as well.
A review of the server trace showed only an EOF failure and the  TNS-12537 error:
Read unexpected EOF ERROR
nserror: nsres: id=0, op=68, ns=12537

In this particular case, there was no information about the client in the trace. This is atypical for a server trace.   It may be that the client aborted before all the client information was posted to the file.  However, there was post in the listener.log for an emagent connection that was established at the same point in time.
Here's an excerpt from a listener.log entry where an emagent establishes a connection:
PROGRAM=D:\oracle\product\10.1.0\Db_1\bin\emagent.exe

Checked the EM Agent traces and logs and discovered the following entry:
Fatal NI connect error 12547, connecting to:
(LOCAL=NO)
VERSION INFORMATION:
TNS for Solaris: Version 11.1.0.7.0 - Production
Oracle Bequeath NT Protocol Adapter for Solaris: Version 11.1.0.7.0 - Production
TCP/IP NT Protocol Adapter for Solaris: Version 11.1.0.7.0 - Production
Time: 16-NOV-2009 22:39:22
****Tracing to file: /backup/sid_traces/sqlnetlog/svr_5233.trc
Tns error struct:
ns main err code: 12547
TNS-12547: TNS:lost contact
ns secondary err code: 12560
nt main err code: 0
nt secondary err code: 0
nt OS err code: 0
****Note the name of the server trace which contains the PID:  svr_5233.trc
Also, the timestamp of the agent event matches the timestamp of the alert.log error.

Check the following locations for EM Agent traces. If working with support on this issue and the EM Agent is suspected, upload ALL files under:
$ORACLE_HOME/sysman/log/emagent.trc < Single node agent trace location
$ORACLE_HOME/host/sysman/log/emagent.trc < RAC agent trace location

It was determined that in this case, the emagent was aborting the connection before it was complete and then simply reconnecting and succeeding on the subsequent try.  No errors were reported in the listener log or listener trace. No errors were returned to the DB Console.  There was no apparent outage of any kind.  No action was taken to correct the ORA-609 in this case.  It was decided that the message was informational and completely benign.

Please review the following documents for more information about timeouts and tracing:
Note: 119706.1 Troubleshooting Guide TNS-12535 or ORA-12535 or ORA-12170
Errors
Note: 345197.1 Connections that Used to Work in Oracle 10.1 Now
Intermittently Fail with ORA-3113,ORA-3106 or ORA-3136 from
10.2 Onwards
Note: 405755.1 Files Needed for Troubleshooting an EM 10G Service Request
if an RDA is not Available
Note: 395525.1 How to Enable Oracle SQLNet Client , Server , Listener ,
Kerberos and External procedure Tracing from Net Manager
Note: 454927.1 Using and Disabling the Automatic Diagnostic Repository
(ADR) with Oracle Net for 11g
It has been reported that the following 11g DNS issue can cause the error to get thrown because of the delay in establishing a connection.

Note: 561429.1 DNS Issue: Connections To Oracle 11g are Slow or Delayed
References
NOTE:395525.1 - How to Enable Oracle SQL*Net Client , Server , Listener , Kerberos and External procedure Tracing from Net Manager
NOTE:405755.1 - Files Needed for Troubleshooting an EM 10G Service Request if an RDA is not Available
NOTE:454927.1 - Using and Disabling the Automatic Diagnostic Repository (ADR) with Oracle Net for 11g
NOTE:345197.1 - Connections that Used to Work in Oracle 10gR1 Now Intermittently Fail with ORA-3113,ORA-3106 or ORA-3136 from 10.2 Onwards
NOTE:1121357.1 - Troubleshooting Guide ORA-609 : Opiodr aborting process unknown ospid
NOTE:119706.1 - Troubleshooting Guide for TNS-12535 or ORA-12535 or ORA-12170 Errors