20. Tracing with node-oracledb

20.1. Application Tracing

There are multiple approaches for application tracing and monitoring:

Oracle Database has a number of tracing capabilities and controls, including the DBMS_MONITOR package.

PL/SQL users may be interested in using PL/Scope.

20.1.1. End-to-End Tracing, Mid-tier Authentication, and Auditing

Oracle Database end-to-end application tracing simplifies diagnosing application code flow and performance problems in multi-tier or multi-user environments.

The Connection properties action, module, clientId, clientInfo, ecId, and dbOp set metadata for end-to-end tracing. The values can be tracked in database views, shown in audit trails, and seen in tools such as Enterprise Manager.

Applications should set the properties because they can greatly help troubleshooting. They can help identify and resolve unnecessary database resource usage, or improper access.

The clientId property can also be used by applications that do their own mid-tier authentication but connect to the database using the one database schema. By setting clientId to the application’s authenticated user name, the database is aware of who the actual end user is. This can, for example, be used by Oracle Virtual Private Database policies to automatically restrict data access by that user.

The attributes are set on a connection object and sent to the database on the next round-trip from node-oracledb, for example, with execute():

const connection = await oracledb.getConnection(
  {
    user          : "hr",
    password      : mypw,  // mypw contains the hr schema password
    connectString : "localhost/orclpdb1"
  }
);

connection.clientId = "Chris";
connection.clientInfo = "My demo application";
connection.module = "End-to-end example";
connection.action = "Query departments";
connection.dbOp   = "Billing"

const result = await connection.execute(`SELECT . . .`);

While the connection is open, the attribute values can be seen, for example with SQL*Plus:

SQL> SELECT username, client_identifier, client_info, action, module FROM v$session WHERE username = 'HR';

USERNAME   CLIENT_IDENTIFIER    CLIENT_INFO            ACTION               MODULE
---------- -------------------- ---------------------- -------------------- --------------------
HR         Chris                My demo application    Query departments    End-to-end example

The value of connection.dbOp will be shown in the DBOP_NAME column of the V$SQL_MONITOR table:

SQL> SELECT dbop_name FROM v$sql_monitor;
DBOP_NAME
------------------------------
Billing
. . .

Other ways to access metadata include querying V$SQLAREA and sys_context(), for example SELECT SYS_CONTEXT('userenv', 'client_info') FROM dual.

Metadata values can also be manually set by calling DBMS_APPLICATION_INFO procedures or DBMS_SESSION.SET_IDENTIFIER. However, these cause explicit round-trips, reducing scalability.

Applications should be consistent about how, and when, they set the end-to-end tracing attributes so that current values are recorded by the database.

Idle connections released back to a connection pool will retain the previous attribute values of that connection. This avoids the overhead of a round-trip to reset the values. After getting a connection from a pool, an application that uses end-to-end tracing should set new values appropriately.

When a Connection object is displayed, such as with console.log(), the end-to-end tracing attributes will show as null even if values have been set and are being sent to the database. This is for architectural, efficiency and consistency reasons. When an already established connection is retrieved from a local pool, node-oracledb is not able to efficiently retrieve values previously established in the connection. The same occurs if the values are set by a call to PL/SQL code - there is no efficient way for node-oracledb to know the values have changed.

The attribute values are commonly useful to DBAs. However, if knowing the current values is useful in an application, the application should save the values as part of its application state whenever the node-oracledb attributes are set. Applications can also find the current values by querying the Oracle data dictionary or using PL/SQL procedures such as DBMS_APPLICATION_INFO.READ_MODULE() with the understanding that these require round-trips to the database.

20.1.2. Debugging PL/SQL with the Java Debug Wire Protocol

The Java Debug Wire Protocol (JDWP) for debugging PL/SQL can be used with node-oracledb.

Node-oracledb applications that call PL/SQL can step through that PL/SQL code using JDWP in a debugger. This allows Node.js and PL/SQL code to be debugged in the same debugger environment. You can enable PL/SQL debugging in the node-oracledb modes as follows:

  • If you are using node-oracledb Thick mode, set the ORA_DEBUG_JDWP environment variable to host=hostname;port=portnum indicating where the PL/SQL debugger is running. Then run the application.

  • In node-oracledb Thin mode, you can additionally set the connection parameter debugJdwp during connection. This variable defaults to the value of the ORA_DEBUG_JDWP environment variable.

See DBMS_DEBUG_JDWP and Debugging PL/SQL from ASP.NET and Visual Studio.

20.1.3. Tracing Executed Statements

Database statement tracing is commonly used to identify performance issues. Oracle Database trace files can be analyzed after statements are executed. Tracing can be enabled in various ways at a database system or individual session level. Refer to Oracle Database Tuning documentation. Setting a customer identifier is recommended to make searching for relevant log files easier:

ALTER SESSION SET tracefile_identifier='My-identifier' SQL_TRACE=TRUE

The Thick mode of node-oracledb is implemented using the ODPI-C wrapper on top of the Oracle Client libraries. The ODPI-C tracing capability can be used to log executed node-oracledb statements to the standard error stream. Before executing Node.js, set the environment variable DPI_DEBUG_LEVEL to 16.

At a Windows command prompt, this could be done with:

set DPI_DEBUG_LEVEL=16

On Linux, you might use:

export DPI_DEBUG_LEVEL=16

After setting the variable, run the Node.js Script, for example on Linux:

node end-to-endtracing.js 2> log.txt

For an application that does a single query, the log file might contain a tracing line consisting of the prefix ‘ODPI’, a thread identifier, a timestamp, and the SQL statement executed:

ODPI [6905309] 2017-09-13 09:02:46.140: SQL select sysdate from dual where :b = 1

See ODPI-C Debugging for documentation on DPI_DEBUG_LEVEL.

20.1.4. Tracing Bind Values

Sometimes it is useful to trace the bind data values that have been used when executing statements. Several methods are available.

In the Oracle Database, the view V$SQL_BIND_CAPTURE can capture bind information. Tracing with Oracle Database’s DBMS_MONITOR.SESSION_TRACE_ENABLE() may also be useful.

You can also write your own wrapper around execute() and log any parameters.

20.1.5. Database Views

This section shows some sample column values for database views.

20.1.5.1. V$SESSION_CONNECT_INFO

The following table lists sample values for some V$SESSION_CONNECT_INFO columns for the node-oracledb Thin and Thick modes:

Table 20.1 Sample V$SESSION_CONNECT_INFO column values

Column

Thick Value

Thin Value

CLIENT_OCI_LIBRARY

The Oracle Client or Instant Client type, such as “Full Instant Client”

“Unknown”

CLIENT_VERSION

The Oracle Client library version number (for example, 19.3.0.0.0)

“6.0.0.0.0” (the node-oracledb version number with an extra .0.0)

CLIENT_DRIVER

“node-oracledb thk : 6.0.0”

“node-oracledb thn : 6.0.0”

20.1.5.2. V$SESSION

The following table list sample values for columns with differences in V$SESSION.

Table 20.2 Sample V$SESSION column values

Column

Thick value

Thin value

TERMINAL

similar to ttys001

the string “unknown”

PROGRAM

similar to node@myuser-mac2 (TNS V1-V3)

defaults to binary name

MODULE

similar to node@myuser-mac2 (TNS V1-V3)

defaults to binary name

20.2. Finding the node-oracledb Mode

You can find the current mode of the node-oracledb driver using the boolean attribute oracledb.thin. The boolean attributes connection.thin and pool.thin can be used to show the current mode of a node-oracledb connection or pool, respectively. The node-oracledb version can be shown with oracledb.version.

The information can also be seen in the Oracle Database data dictionary table V$SESSION_CONNECT_INFO:

const result = await connection.execute(
  `SELECT UNIQUE CLIENT_DRIVER FROM V$SESSION_CONNECT_INFO WHERE
   SID = SYS_CONTEXT('USERENV', 'SID')`)

In the node-oracledb Thin mode, the output will be:

node-oracledb thn : 6.0.0

In the node-oracledb Thick mode, the output will be:

node-oracledb thk : 6.0.0

Database Administrators (DBAs) can verify whether applications are using the desired add-on version. For example:

SQL> SELECT UNIQUE sid, client_driver
     FROM v$session_connect_info
     WHERE client_driver LIKE 'node-oracledb%'
     ORDER BY sid;

    SID CLIENT_DRIVER
---------- ------------------------------
    16 node-oracledb thn : 6.0.0
    33 node-oracledb thk : 6.0.0

If you are using the node-oracledb Thick mode, the CLIENT_DRIVER value can be configured with a call to oracledb.initOracleClient() such as oracledb.initOracleClient({driverName:'myapp : 2.0.0'}). The driverName attribute in initOracleClient() can be used to override the value that will be shown in the CLIENT_DRIVER column. See Other node-oracledb Thick Mode Initialization.

The CLIENT_DRIVER value is not configurable in node-oracledb Thin mode.

Note if oracledb.connectionClass is set for a non-pooled connection, the CLIENT_DRIVER value will not be set for that connection.

20.3. Low Level node-oracledb Driver Tracing

Low level tracing is mostly useful to maintainers of node-oracledb.

  • For the node-oracledb Thin mode, packets can be traced by setting the environment variable:

    NODE_ORACLEDB_DEBUG_PACKETS=1

    Output goes to stdout. The logging is similar to an Oracle Net trace of level 16.

  • The node-oracledb Thick mode can be traced using: