require secondary error message for "ORA-12537: TNS:connection closed"

[nalbion]

I'm getting an intermittent error which I'm trying to debug:

error: ORA-12537: TNS:connection closed

My DBA and AWS support are both demanding that I provide the "secondary error message", but it is not being logged

    oracledb.getConnection(config).then(function (conn) {
        console.info('Connected to Oracle', host, database);
        return conn;
    }).then(function(conn) {
        return conn.execute('SELECT 1').then(function(result) {
            console.info('result', result);
            return conn.release();
        });
    }).catch(function(err) {
        console.info(err);
    });

[dmcghan]

@nalbion There were lots of questions in the new issue template that you didn't answer. Please answer these:

• What is your Node.js version? Is it 64-bit or 32-bit? Run version.js from https://github.com/oracle/node-oracledb/blob/master/examples/version.js

• What is your node-oracledb version?

• What OS (and version) is Node.js executing on?

• What is your Oracle client (e.g. Instant Client) version? Is it 64-bit or 32-bit? How was it installed? Where is it installed?

• What is your Oracle Database version?

Also, is the example you provided really demonstrative of the code generating the error? That code doesn't use a connection pool, doesn't have a valid query, etc. Perhaps you could share something closer to what you're actually running?

[nalbion]

@dmcghan sorry, I threw that together before running out the door for the day.

• Node 6.10 on AWS Lambda
• node-oracledb 1.9.3
• AWS Linux
• instantclient-basic-linux.x64-12.1.0.2.0 - ./lib/libociei.so ./lib/libociei.so
• Oracle 11g (11.2.4)

Note that I have been able to connect to Oracle, but there is an intermittent problem which we are trying to diagnose. Yes, when this code does successfully establish a connection it complains about the query, but the sole purpose of the code above is to demonstrate that the error only provides:

ORA-12537: TNS:connection closed

This is just an "informational error", apparently it's useless without the secondary error which should look something like this (12537 is an umbrella error code, with several possible causes, I want to know my specific cause and action):

ORA-12537 TNS:connection closed
Cause: Normal "end of file" condition has been reached; partner has disconnected. 
Action: None needed; this is an information message.

http://www.dba-oracle.com/t_ora_12537_tns_error.htm

Because this code runs on AWS Lambda, I don't think that using connection pools are possible (or even re-using connections).

• Lambda serves only one request concurrently per container, even if the request blocks on IO for several seconds the container will be idle until the IO responds with data etc.
• Lambda may spin up any number of containers to serve concurrent requests
• Lambda may re-use the same container to serve another request within, say, 15 minutes but I'm not confident that the container would be able to close any connection/pools which were kept open for re-use. I've got a few ideas to experiment with in the future, but that's another story for another day (or month)

[cjbj]

The ODPI-C access layer should/could loop over the lower OCI call to get multiple Oracle error messages.

In the meantime, try some SQL*Net tracing. Look at ADR tracing for Oracle Net https://docs.oracle.com/database/122/NETRF/parameters-for-the-sqlnet-ora-file.htm#NETRF398

For example, create a file sqlnet.ora with

ADR_BASE=/tmp/mylogs
TRACE_LEVEL_CLIENT=16

Set TNS_ADMIN so that Node can read $TNS_ADMIN/sqlnet.ora and run mkdir /tmp/mylogs. Execute the app and maybe the /tmp/mylogs/.../trace/sqlnet.log will show something recognizable.

For example, I tried to connect to a DB in a suspended virtualbox VM. I had the above and also SQLNET.OUTBOUND_CONNECT_TIMEOUT=5 in my sqlnet.ora file so after 5 seconds the node-oracledb connection returned just 'ORA-12170: TNS:Connect timeout occurred'

My sqlnet.log file contained:

Fatal NI connect error 12170.

  VERSION INFORMATION:
    TNS for MacOS X Server: Version 12.2.0.1.0 - Production
    TCP/IP NT Protocol Adapter for MacOS X Server: Version 12.2.0.1.0 - Production
  Time: 23-AUG-2018 10:32:23
  Tracing to file: 
  Tns error struct:
    ns main err code: 12535

TNS-12535: Message 12535 not found; No message file for product=network, facility=TNS
    ns secondary err code: 12606
    nt main err code: 0
    nt secondary err code: 0
    nt OS err code: 0
  Client address: <unknown>

[nalbion]

@cjbj is that something that would be done on the Oracle server, or on the client? I don't think that's possible on Lambda.

[cjbj]

@nalbion In this case, it could be done on the client side: https://oracle.github.io/node-oracledb/doc/api.html#tnsadmin

What are the circumstances that the error occurs in?

[cjbj]

@nalbion there was some analysis instigated by @anthony-tuininga into this. It uncovered a couple of things. The first is that there may not be any useful secondary messages for ORA-12537. A second thing is that Oracle Client changes are needed to pass some classes of secondary messages back to the error message routines that node-oracledb uses. I logged an Oracle enhancement for this, bug 29517652. If/when any changes occur in Oracle Client, the messages should automatically appear so no node-oracledb change is needed. I will close this issue.