Using the SQL Trace Facility

NuoDB SQL lets you log non-DDL statements to a persistent table that users can query. This trace facility allows users to review the SQL statements that execute, including the explain plan, which can assist with performance tuning. The trace table can also be used for debugging purposes, especially when trying to identify the statements that execute inside a stored procedure. This trace facility can also be useful for extracting all non-DDL SQL statements that executed and saving them to a file for replaying. It should be noted that turning the trace facility on can have a negative impact on performance due to the overhead of inserting the statements into the trace table.

The table that NuoDB SQL logs to does not exist as a database object until tracing is turned on the first time. The user that turns on tracing initially, causing the trace table to be created, is the owner of the trace table. Once the trace table exists, it is a persistent table defined to the database. Only the table owner can DROP the trace table or DELETE rows from the trace table. The table owner can grant the DELETE privilege on the trace table to other users. The next time tracing is turned on, this same persistent table will be used for logging.

About Default Trace Behavior

Use the SET command to turn tracing on or off. By default, NuoDB SQL tracing behaves such that it will:

Create a persistent database table named TRACETABLE. The schema that this table is created in will depend on the level of tracing that is set, either GLOBAL or CONNECTION (see trace_level below). If the trace level is set to CONNECTION then the table is created in the current schema. If the trace level is set to GLOBAL then the trace table is created in a schema named TRACESCHEMA.

Logs all non-DDL statements, including all non-DDL statements that execute inside stored procedures.

When you turn tracing on, you can specify optional parameters (see opt_trace_params below) that allow the user to override this default behavior. This can be useful if a user wants to set tracing on at the CONNECTION level and create their own trace table to log to. Only the SQL statements that this user executes on the current connection will be logged to this table. And only this user will have the ability to DROP or DELETE rows from this table.

Dropping a trace table is the equivalent of issuing the SET command to turn trace off. Statements can no longer be logged to the trace table. To resume trace, you must set trace off and then set trace back on and specify a table name that is different from the name of the table that was dropped. If you do not specify a different table name, NuoDB SQL does not create the trace table.

Tracing does not log any of the SHOW command statements executed or any statements that the system generates when the SHOW command is executed.

Note: Query plans stored in the Tracetable EXPLAIN column contain performance counter and elapsed time indicators at the query plan sub-operation level that help indicate how long each timed operation took to execute. See

Format for Turning Tracing On

The SET command format for controlling tracing is as follows:

SET [ trace_level ] TRACE { ON [ opt_trace_params ] | OFF }

Defining the Trace Level

The NuoDB SQL trace facility allows for an optional trace_level parameter that can be specified when setting tracing on. This option defines which non-DDL statements will be logged. The valid values are CONNECTION or GLOBAL. If no option is specified, the default is CONNECTION. These tracing levels are defined as:

CONNECTION — This is the default. Connection level tracing logs non-DDL statements executed by the current user in the current connection. In each new connection, if you want tracing then you must turn it on by executing the SET command. Connection level tracing will end for that user when they disconnect from the current connection or when they turn tracing off by executing the SET command.

For CONNECTION level tracing, the default trace table name is TRACETABLE and is created in the current schema. This can be overridden with the use of the TABLE optional parameter (see below for description of opt_trace_params). Other users that are also in that current schema when they set trace on at the CONNECTION level will, by default, also log to this same trace table. If the trace table does not already exist, the trace table is created immediately upon setting tracing on, and before any non-DDL statement is executed.

The user who causes a trace table to be created is the owner of that table. This is the user that sets tracing on at the CONNECTION level. Users can create trace tables in all schemas where they have CREATE privilege. Several users can share the same CONNECTION level trace table, or create their own trace table using the optional parameters described below. All users can invoke INSERT and SELECT on a trace table. Only the owner can invoke DELETE and DROP on a trace table. The owner can also GRANT the DELETE privilege on the trace table to other users.

GLOBAL — Global level tracing logs non-DDL statements executed by all users connected to the database. Only a user that has been granted the ADMINISTRATOR role can turn global tracing on and off. The administrator user can disconnect from a database after turning global tracing on or off. The setting specified by that administrator user remains in effect for all currently connected database users as well as for new users that connect to the database.

For GLOBAL level tracing, the default trace table name is TRACESCHEMA.TRACETABLE. The default behavior is that all non-DDL statements executed by existing users, as well as users who subsequently connect to the database, will be logged to this trace table. For this reason this trace table can grow very large very quickly and should be monitored. If this trace table does not already exist, this trace table is created when the first non-DDL statement is executed and logged.

CONNECTION level tracing takes precedence over GLOBAL level tracing. Suppose that GLOBAL level tracing has been turned on for a given database and you connect to that database and turn CONNECTION level tracing on. The statements that you execute will be logged to the trace table that has been defined for CONNECTION level tracing. The statements that all other users of the database execute will continue to be logged to the trace table that has been defined for GLOBAL level tracing. After you have turned tracing off at the CONNECTION level, the statements that you execute will log to the trace table that has been defined for GLOBAL level tracing.

A user can use the SHOW command to view the current trace parameter settings. This will show both the GLOBAL and CONNECTION level trace settings. By default, tracing is set to off.

Parameters for Changing Default Tracing Behavior

NuoDB SQL logs all non-DDL statements to a particular table according to the defined level of tracing. You can change the default behavior by specifying one or more parameters when you turn tracing on. For example, you can control which non-DDL statements are logged. You can also override the default trace table where the statements will be logged.

To change default tracing behavior, replace opt_trace_params with one or more parameter name/value pairs in the following format:

The parameters you can specify are described below. The settings you specify are in effect as long as tracing is turned on. The settings reset to the default values when tracing is turned off. One or more of these parameters can be specified when tracing is turned on. If more than one parameter value is provided, only SQL statements that meet ALL criteria defined by these parameter values are logged.

If tracing is already turned on, a user can change the tracing behavior by executing the SET command to turn tracing on and providing different values for these parameter settings. This has the same effect as turning tracing off and then turning tracing back on.

Specify the name of the table in which to log the non-DDL statements. If the table you specify does not exist NuoDB SQL creates it. The behavior related to overriding the use of the default table depends on whether tracing is set at the connection level or the global level.

For CONNECTION level tracing, the user that creates a trace table, by turning trace on, is the owner of that trace table. Only that user can delete from that trace table. Only that user can drop that trace table. Any other users who specify the same table name can only insert or select on that table.

You can optionally qualify the table name with a schema name. If you do not specify a schema, NuoDB SQL creates the table in the current schema. You cannot specify the SYSTEM schema.

Any number of users can override logging to the default trace table.

For GLOBAL level tracing, only a user that has been granted the ADMINISTRATOR role can override the use of the default TRACESCHEMA.TRACETABLE table. Specification of a schema name is required and it cannot be the SYSTEM schema.

Only the administrator user who created the trace table can delete from that trace table. Only that user can drop that trace table. Any other users who subsequently turn global tracing on and specify that same table name can only insert or select on that table.

Specify an expression to filter which statements to log. Only non-DDL statements that contain a match for this expression are logged. For example, suppose you specify PATTERN 'SCORING'. This causes the trace facility to log statements that select from a table or column named SCORING or specify SCORING as a matching string literal in a WHERE clause.

Specify a threshold runtime in seconds. Only non-DDL SQL statement that have a runtime that is greater than or equal to this threshold value will be logged to the trace table. To indicate a fraction of a second specify a decimal value. For example, a value of 0.5 will log only non-DDL SQL statements that have a runtime value that is greater than or equal to one half (1/2) of a second.

For each of the following to be logged, its runtime must be greater than or equal to the specified threshold value:

Execute command for a stored procedure. That is, the total runtime of the stored procedure must be greater than or equal to the threshold value.

An individual SQL statement that executes inside a stored procedure.

A processing block in a stored procedure, for example, an IF statement, WHILE loop, FOR loop.

An individual SQL statement that executes inside a processing block.

A nested stored procedure.

An individual SQL statement in a nested stored procedure.

See Example 3, which shows how the SQL trace facility logs SQL statements that execute inside a stored procedure.

Specify one or more stored procedures that will log to the trace table when executed. Qualify each procedure name with a schema name and enclose them in parentheses, separating each by a comma. A stored procedure does not have to exist at the time that tracing is turned on with the PROCEDURES parameter.

NuoDB SQL logs the stored procedure EXECUTE statement as well as all non-DDL SQL statements that execute inside the stored procedures that have been specified with the PROCEDURES parameter. All other non-DDL SQL statements that execute, including stored procedures and the SQL statements that execute inside the stored procedures, will not be logged to the trace table. See Example 4.

Tracing SQL statements inside User Defined Functions (UDFs)

Tracing for the current connection is controlled by the command set trace on and also applies for UDFS. The SQL trace whose documentation can be viewed in NuoSQL by running help set trace. If the TABLE option is specified, the traces are written in that table, otherwise a TRACETABLE is created in the current schema.

Tracing can also be controlled globally, by manipulating the system properties DB_TRACE, DB_TRACE_TABLE, DB_TRACE_MIN_TIME, DB_TRACE_PATTERN and DB_TRACE_PROCEDURES.

Using the function listed in the summary, these statements produce the following output:

Description of Trace Table Content

The following table describes the content of a trace table.

Column

Type

Description

SQLSTRING

string

A non-DDL SQL statement that was executed and logged. A SQL statement is logged upon completion of execution. A logged statement can be the execute statement for a stored procedure as well as a processing block statement, such as an IF statement, WHILE loop, FOR loop, from a stored procedure.

COMPILETIME

bigint

In microseconds, the amount of time it took to compile the executed SQL statement. If the statement is already cached, this can be 0.

For stored procedures, this will usually be 0 because stored procedures are compiled when they are created. The exception to this is when the stored procedure contains dynamic SQL. The dynamic SQL statements are compiled at runtime. Therefore, this COMPILETIME is the sum of the compile time of all dynamic SQL statements.

RUNTIME

bigint

The duration of the statement execution specified in microseconds. This RUNTIME also includes the COMPILETIME for the statement. To compute actual RUNTIME only, subtract COMPILETIME from RUNTIME.

USER

string

The SQL username for the database connection that executed the SQL statement.

SCHEMA

string

The current SQL schema for the database connection where the SQL statement being logged is being executed. The SQL statement itself can contain database objects from different schemas.

NUMPARAM

integer

The number of SQL parameters specified in the SQL statement. This is 0 if there are no parameter values.

For an execute statement for a stored procedure, this includes parameters in statements that are executed inside the stored procedure.This does not include parameters that are passed to a stored procedure, unless it is an actual NuoDB SQL parameter, for example, execute proc1(?,?)).

PARAMS

string

A string that represents the parameters specified in the statement. Each parameter is delimited from the next with a '#' character. This can be ambiguous if the parameter string also happens to contain the '#' character. If the parameter is an assigned value to a variable in a stored procedure, both the variable name and the value are logged. See Example 3.

CALLSTACK

string

The call stack lists the names of stored procedures that are currently active and that lead to the execution of SQL statements being logged. See Example 4.

NODEID

integer

The identifier for the transaction engine (TE) to which the client was connected.

CONNID

integer

A unique identifier for the connection.

EXECID

integer

An identifier assigned to each SQL statement executed on a connection and logged to the trace table. This identifier:

Is unique across all statements logged for a given connection.

Starts with a value of 1 and is incremented by 1 for each statement logged on the connection.

Is reset back to 1 for each user connection.

EXECBLOCKID

string

Specifies the EXECIDs of all statements that are currently active in the CALLSTACK and lead to the execution of this current SQL statement that is being logged.

For example, an EXECUTE statement for a stored procedure is assigned an EXECID of 1. The first SQL statement that is executed inside that stored procedure is assigned an EXECID of 2. Since the EXECUTE statement for the stored procedure remains active in the CALLSTACK, the EXECID for this EXECUTE statement is assigned to the EXECBLOCKID column of the row being inserted for this first SQL statement that is executed inside that stored procedure. See Example 4.

TRANSID

integer

The identifier for the transaction that was executed on the connection and logged to the trace table. This value corresponds to ID in SYSTEM.TRANSACTIONS.

NROWS

integer

The number of rows in the result set of a SELECT statement or the number of records updated for DML statements.

TIMESTAMP

string

Indicates when statement execution began.

EXPLAIN

string

The EXPLAIN string for the statement. See EXPLAIN for more information. Due to the large size of this column, SET OUTPUT VERTICAL can be useful when browsing the contents of the trace table.

Note the EXPLAIN text stored during tracing includes the same performance counter/timer information, as the one shown by EXPLAIN (analyze on) command.

It starts by turning tracing on at the GLOBAL database level and then also at the CONNECTION level. The CONNECTION level tracing takes precedent. Therefore, the GLOBAL trace table is not created.

This example then turns the connection tracing level off and so NuoDB SQL starts logging to the GLOBAL trace table. Note that when a SQL statement runs a second time and is logged to the GLOBAL trace table, the compile time is 0. The SQL statement has already been compiled.

The parameter values are stored in the PARAM column of the trace table, separated by "#".

Example 2This example turns on tracing for statements that contain the word SELECT. In this example, both the INSERT and the SELECT statements are logged to the trace table. The DELETE statement is not logged to the trace table.

Example 3This example shows tracing for SQL statements that are executed in a stored procedure. After executing the prc_trace_proc(35) stored procedure, the output from the trace table shows:

Row

Description of what is logged in the trace table

1

The INSERT into the hockeydup table. Note the CALLSTACK column has the stored procedure name, prc_trace_proc(). The EXECBLOCKID is the EXECID of the EXECUTEprc_trace_proc() statement (row #17). SQL statements are logged when they finish execution, not when they begin execution. Therefore, a stored procedure is not logged until after all of its SQL statements are logged.

2

The SELECT statement that executes as defined by the FOR SELECT statement (row #16). This SELECT statement is logged for each iteration of the FOR SELECT statement. The EXECBLOCKID shows the EXECID of both the stored procedure execute statement and the FOR SELECT statement.

3-6

The variable assignment statements that execute inside the FOR SELECT statement of the EXECUTE stored procedure statement.

7

The variable assignment executed in the nested stored procedure, prc_trace_proc_nested(). Note the CALLSTACK column, which shows all active SQL statements at the time this statement executed. It shows both the calling stored procedure and the current stored procedure that executed this statement. Also, the EXECBLOCKID shows the EXECID of the currently active statements.

8

The IF statement being evaluated. (row #11). The fact that this IF statement is logged to the trace table does not necessarily mean it evaluated to TRUE. This can be tested by checking to see if the statements inside the IF processing block executed (see Row #9).

9

The UPDATE statement that executed as a result of the IF statement evaluating to TRUE.

10

A variable assignment.

11

The IF processing block statement about to be evaluated (see Row #8 where it is evaluated).

12

The nested stored procedure, prc_trace_proc_nested(), being executed.

13

The IF statement being evaluated (Row #15).

14

The INSERT statement that executed as a result of the IF statement evaluating to TRUE (Row #13).

15

The IF processing block statement about to be evaluated (Row #13).

16

The FOR SELECT processing block statement that will be executed and return a result set (Row #2).