The SQL Trace facility provides information that you can use to analyze and tune performance at the individual SQL statement level.
The following example shows the contents of the SQL Trace output in soltrace.out for a solidDB® server that is running a simplified transaction from a benchmark. In the example, the following statements are issued:
▪SET
▪SELECT (2 statements)
▪UPDATE
▪INSERT
2012-11-17 11:11:38.959 2:sql:161:prepare SET PASSTHROUGH READ NONE WRITE NONE 2012-11-17 11:11:38.959 2:sql:161:execute:SET PASSTHROUGH READ NONE WRITE NONE 2012-11-17 11:11:38.960 2:sql:163:prepare SELECT C_LAST, C_CREDIT, C_DISCOUNT, W_TAX FROM CUSTOMER, WAREHOUSE WHERE C_W_ID = ? AND C_D_ID = ? AND C_ID = ? AND W_ID = ? 2012-11-17 11:11:38.961 2:sql:164:prepare SELECT D_NEXT_O_ID, D_TAX FROM DISTRICT WHERE D_W_ID = ? AND D_ID = ? FOR UPDATE 2012-11-17 11:11:38.961 2:sql:165:prepare UPDATE DISTRICT SET D_NEXT_O_ID = ? WHERE D_W_ID = ? AND D_ID = ? 2012-11-17 11:11:38.961 2:sql:166:prepare INSERT INTO ORDERS VALUES (?, ?, ?, ?, ?, ?, ?, ?) 2012-11-17 11:11:38.961 2:sql:trans begin 2012-11-17 11:11:38.961 2:sql:163:execute:SELECT C_LAST, C_CREDIT, C_DISCOUNT, W_TAX FROM CUSTOMER, WAREHOUSE WHERE C_W_ID = ? AND C_D_ID = ? AND C_ID = ? AND W_ID = ? 2012-11-17 11:11:38.962 2:sql:163:fetch 2012-11-17 11:11:38.962 2:sql:164:execute:SELECT D_NEXT_O_ID, D_TAX FROM DISTRICT WHERE D_W_ID = ? AND D_ID = ? FOR UPDATE 2012-11-17 11:11:38.962 2:sql:164:fetch 2012-11-17 11:11:38.962 2:sql:165:execute:UPDATE DISTRICT SET D_NEXT_O_ID = ? WHERE D_W_ID = ? AND D_ID = ? 2012-11-17 11:11:38.962 2:sql:stmt commit (0) 2012-11-17 11:11:38.963 2:sql:166:execute:INSERT INTO ORDERS VALUES (?, ?, ?, ?, ?, ?, ?, ?) 2012-11-17 11:11:38.963 2:sql:stmt commit (0) 2012-11-17 11:11:38.963 2:sql:trans commit (0) 2012-11-17 11:11:38.963 2:sql:161:close 2012-11-17 11:11:38.963 2:sql:163:close 2012-11-17 11:11:38.963 2:sql:164:close 2012-11-17 11:11:38.963 2:sql:165:close 2012-11-17 11:11:38.963 2:sql:166:close
The output can be divided into five columns as follows:
2012-11-17 11:11:38.962 | 2: | sql: |165: | execute:UPDATE DISTRICT SET D_NEXT_O_ID = ? WHERE D_W_ID = ? AND D_ID = ?
Timestamp (2012-11-17 11:11:38.962)
The first column is the time stamp. To ensure that the output has millisecond precision, the SRV.TraceSecDecimals parameter must be set to 3 (default).
Connection ID (2)
The second column is the connection ID. This number identifies each client connection to the solidDB® server uniquely. In the example, only one connection is used, which is represented by connection ID 23. The example also shows when the user connected and disconnected.
sql The third column is the SQL trace identifier sql. It is displayed so that you can differentiate the SQL trace information from other component trace information in the trace file.
Transaction ID or transaction operation (165)
The fourth column is either a transaction statement ID (such as 165) or a transaction level operation (such as trans begin). The transaction ID is an internal number assigned by the server to each transaction.
Note The transaction ID in the SQL Trace output differs from the statement ID in the Monitor facility output.
The trans begin token is output when the transaction is started. In solidDB®, transactions are started during the first SQL statement execution. Prepares and most SET statements are not part of a transaction.
The trans commit token is output when the transaction is committed. You can use the trans begin and trans commit tokens to calculate the duration of the transaction. For example, the timestamp for the trans begin token is 2010-11-17 11:11:38.961 and the timestamp for the trans commit token is 2010-11-17 11:11:38.963. Therefore, this transaction took approximately 2 milliseconds to complete.
The value in parentheses after the trans commit token is the return code of the commit.
Trace data (execute:UPDATE DISTRICT SET D_NEXT_O_ID = ? WHERE D_W_ID = ? AND D_ID = ?)
The fifth column shows the actual trace data for the operation. It can be the actual SQL statement being prepared or executed, the parameters being used, or another statement level operation that the server is performing.
The SQL Trace facility does not include the dynamic SQL parameter values in the output. You cannot use the SQL Trace output to reconstruct exact SQL execution as you can with the Monitor facility. The SQL Trace facility is best for analyzing the flow of statement execution.