Query Tracing (or trace point SC930) is the ability to trace all queries processed by the DBMS Server regardless of the source, whether it be an interactive query, or from a JDBC, ODBC, or .NET connection.

Trace point SC930 creates an output file for each connected session.

The file names begin with “qtrace_” and end with .log. The file name contains the database name, the server process id and the internal session id as follows:

For example:

Each new session will have a SESSION BEGINS record.

Before enabling SC930 tracing, you must set the output directory.

Set the environment variable II_SC930_LOC before starting Actian X. For example:

Dynamically specify the directory using the SQL SET command. For example:

This command must be issued against every DBMS Server that has, or will have, SC930 enabled. Thus it is possible to use a different directory for each DBMS Server and switch the location while the trace is running.

Files are closed after each message, so you can move files out of the directory where they are being written to, and as long as a momentary delay is allowed (in case a line is currently being written). A new file will then be created in the original directory and the file can be archived.

If a write fails, SC930 tracing is switched off. It is possible to run a simple test query against each server to determine that tracing is still operating. In addition, if II_DBMS_LOG is set, you can check that log to see if a "switching on" or "off" command has been issued.

After the trace directory is set, SC930 tracing can be enabled.

SC930 tracing can be enabled on a per-server basis, as follows:

Tracing can be enabled by setting trace point SC930 as follows:

where N is 1, 2, 3, 4 or 5 as follows:

Issue either:

or

Recording is stopped for the DBMS Server.

The messages in the file are of the form:

record type : timestamp1/timestamp2 : information

where:

Excerpts from a sample trace file are shown here:

 

The SESSION BEGINS record shows the session connection information, including:

The QRY records show the queries being issued. The EQY records show when control was passed back to the front-end. They give a timestamp, the number of rows affected by the query and the last error (if any) associated with that session.

The PQTXT record prints the underlying "prepared statement" information with Execute statement, OPEN, FETCH and CLOSE cursor statements. In case of OPEN, FETCH or CLOSE cursor statements, underlying prepared statement information for a particular cursor will only be printed if it is not already printed in the current trace session.

For example, we can see that the DROP TABLE TEST failed with E_US0AC1 (table does not exist). We can also see that a SELECT * FROM TEST later on returned 3 rows. We can also calculate query execution time by looking at the timestamps of QRY and EQY records.

Because SC930 shows all queries, we can see that there are several queries which were executed "under the covers" by Terminal Monitor as part of the connection—the "select dbmsinfo('UNICODE_NORMALIZATION')."

We can see the QEP tracing (SC930 2) is switched on and a query producing a QEP. (If there were REPEATED queries we would only see the QEP the first time it is executed.)