The SQL Info facility generates information for each SQL statement processed by solidDB®.
To generate the SQL Info, you run your application with the SQL Info facility enabled. The SQL Info facility can be enabled in the following ways:
▪Sql.Info=<info_level> parameter
▪ADMIN COMMAND 'trace on info <info_level>' command
▪SET SQL INFO ON LEVEL info_level FILE file_name statement
The tracing level (info_level) is defined as an integer between 0 (no tracing) and 8 (solidDB® info from every fetched row).
Info level
Description
0
no output
1
table, index, and view info in SQL format
2
SQL execution graphs (technical support use only)
3
some SQL estimate info, solidDB® selected key name
4
all SQL estimate info, solidDB® selected key info
5
solidDB® info also from discarded keys
6
solidDB® table level info
7
SQL info from every fetched row
8
solidDB® info from every fetched row
The trace information is output by default to the soltrace.out file in the solidDB® working directory. You can also specify the output file using the SQL.InfoFileName parameter. This is recommended since the soltrace.out file may contain information from several sources.
Examples
[SQL]
Info = 1
InfoFileName = solidsql_trace.txt
The following command turns on the SQL Info facility on level 3, outputting the trace information to a my_query.txt file in the working directory. This SQL Info facility is turned on only for the client that executes the statement. SET SQL INFO ON LEVEL 1 FILE 'my_query.txt'
The following SQL statement turns off the SQL Info facility: SET SQL INFO OFF
Analyzing Monitor facility trace output:
The Monitor 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 Monitor 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 09:21:22 Version: 7.0.0.0 Build 2012-10-03 Operating system: Linux 2.6.18 AMD64 64bit MT solidDB® 7.0 2012-11-17 09:21:23 User 'DBA' connected, user id 23, machine id solidhost.unicom.com (127.0.0.1). 2012-11-17 09:21:23.676 23:0:opencursor SQL_CUR1 'SET PASSTHROUGH READ NONE WRITE NONE' 2012-11-17 09:21:23.676 23:0:execute SET PASSTHROUGH READ NONE WRITE NONE 2012-11-17 09:21:23.676 23:0:exec rowcount 0 2012-11-17 09:21:23.677 23:1:opencursor SQL_CUR2 '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 09:21:23.677 23:2:opencursor SQL_CUR3 'Select D_NEXT_O_ID, D_TAX from DISTRICT where D_W_ID = ? and D_ID = ? for update' 2012-11-17 09:21:23.678 23:3:opencursor SQL_CUR4 'Update DISTRICT set D_NEXT_O_ID = ? where D_W_ID = ? and D_ID = ?' 2012-11-17 09:21:23.678 23:4:opencursor SQL_CUR5 'Insert into ORDERS values (?, ?, ?, ?, ?, ?, ?, ?)' 2012-11-17 09:21:23.678 23:1: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 09:21:23.678 23:1:param 1:3838 2012-11-17 09:21:23.678 23:1:param 2:2 2012-11-17 09:21:23.678 23:1:param 3:23 2012-11-17 09:21:23.678 23:1:param 4:3838 2012-11-17 09:21:23.679 23:1:fetch next, 1 rows, total 1 2012-11-17 09:21:23.679 23:2:execute Select D_NEXT_O_ID, D_TAX from DISTRICT where D_W_ID = ? and D_ID = ? for update 2012-11-17 09:21:23.679 23:2:param 1:3838 2012-11-17 09:21:23.679 23:2:param 2:2 2012-11-17 09:21:23.679 23:2:fetch next, 1 rows, total 1 2012-11-17 09:21:23.679 23:3:execute Update DISTRICT set D_NEXT_O_ID = ? where D_W_ID = ? and D_ID = ? 2012-11-17 09:21:23.679 23:3:param 1:32 2012-11-17 09:21:23.679 23:3:param 2:3838 2012-11-17 09:21:23.679 23:3:param 3:2 2012-11-17 09:21:23.679 23:3:exec rowcount 1 2012-11-17 09:21:23.679 23:4:execute Insert into ORDERS values (?, ?, ?, ?, ?, ?, ?, ?) 2012-11-17 09:21:23.680 23:4:param 1:31 2012-11-17 09:21:23.680 23:4:param 2:23 2012-11-17 09:21:23.680 23:4:param 3:2 2012-11-17 09:21:23.680 23:4:param 4:3838 2012-11-17 09:21:23.680 23:4:param 5:2012-11-17 09:21:23 2012-11-17 09:21:23.680 23:4:param 6:NULL 2012-11-17 09:21:23.680 23:4:param 7:8 2012-11-17 09:21:23.680 23:4:param 8:1 2012-11-17 09:21:23.680 23:4:exec rowcount 1 2012-11-17 09:21:23.680 23:transopt commit (6) 2012-11-17 09:21:23.680 23:0:close 2012-11-17 09:21:23.680 23:1:close 2012-11-17 09:21:23.680 23:2:close 2012-11-17 09:21:23.681 23:3:close 2012-11-17 09:21:23.681 23:4:close 2012-11-17 09:21:23 User 'DBA' disconnected, user id 23, machine id coralxib02.orolab.UNICOM.com (127.0.0.1).
The output can be divided into four columns as follows:
2012-11-17 09:21:23.679 | 23: | 3: | execute Update DISTRICT set D_NEXT_O_ID = ? where D_W_ID = ? and D_ID = ?
Timestamp (2012-11-17 09:21:23.679)
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 (23)
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.
Statement ID or transaction operation (0-4)
The column token is either a statement ID or a transaction level operation. The example shows the output from five SQL statements that are run within one transaction. The statement IDs for the five statements vary from 0 to 4. When a workload is running with more than one client that runs many SQL statements, the combination of connection ID and statement ID can identify each entry in the trace output uniquely. When the third token is not the statement ID, it is usually a transaction level operation, such as commit or rollback.
You can use grep or search facilities in any file viewing utility to use the combination to isolate and view one sequence of operations quickly.
To limit the amount of output the server produces, you can enable the Monitor facility for a specific user only by issuing the command ADMIN COMMAND 'monitor on user username'.
Trace data (execute Update DISTRICT set D_NEXT_O_ID = ? where D_W_ID = ? and D_ID = ?)
The fourth 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.
Example: Analyzing the Monitor facility output
SELECT statement (ID 2)
Focusing on statement ID 2, which is a SELECT statement, you can see that the start timestamp for the prepare, shown as open cursor followed by the internally assigned cursor identifier is 2010-11-17 09:21:23.677. The execute started at 2010-11-17 09:21:23.679, which means that prepare took about 2 milliseconds to complete. The fetch completed at 2010-11-17 09:21:23.679, therefore it appears to have taken 0 milliseconds. The 0 millisecond duration typically means that the execution completed in sub-milliseconds or microseconds. Because the timer precision cannot be set to show microseconds, microsecond-level information is not available. Because of the precision limitation, the duration of the operations is approximate.
In the example output, the prepare operation takes about twice as long as the execute operation. This aligns with the known fact that preparing SQL statements is more expensive than executing them. To optimize the performance of your database, prepare statements as few times as possible.
In the example output, the statement ID 2 fetches a total of 1 row. Typically, the more rows you need to fetch, the longer the statement execution takes and the less advantage an in-memory database has over traditional disk-based database management systems.
INSERT statement (ID 4)
Focusing on statement ID 4, which is an INSERT statement, you can see that the prepare operation started at 2010-11-17 09:21:23.678, the execute started at 2010-11-17 09:21:23.679, and the execute completed at 2010-11-17 09:21:23.680. By looking at the time stamps, you can see the prepare took about 1 millisecond and the execute took less than 1 millisecond.
Transaction duration
You can use the timestamp information to calculate the duration of a transaction. In the example, the transaction executed by connection ID 23 started at about 2010-11-17 09:21:23.676. The end of the transaction execution is marked by the by the operation transopt commit (6) (the digit 6 in parentheses is an internal identifier for a commit transaction operation). The timestamp associated with transopt commit (6) is 2010-11-17 09:21:23.680. It took about 4 milliseconds to complete the transaction.
Reconstructing executed SQL statements
The trace output shows the parameter values for the dynamic SQL statements. You can use the trace output to reconstruct the actual SQL statements that were executed. For example, you can execute the statements with the same parameters in solidDB® SQL Editor (solsql) to analyze the statement further.
Analyzing SQL Trace facility output:
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.
Comparison of the Monitor facility and the SQL Trace facility:
The output of the Monitor facility and the SQL Trace facility is slightly different. For example, you need to use the SQL Trace facility to trace statements that are executed in stored procedures.
Description
Monitor
SQL trace
Trace SQL statements executed in stored procedures
No
Yes
Dynamic SQL parameter values
Yes
No
Statement row counts
Yes
No
Commit return code
No
Yes
User connect and disconnect messages
Yes
No
trans begin displayed at the start of transactions
No
Yes
Same statement ID displayed as in ADMIN COMMAND 'userlist' and ADMIN COMMAND 'sqllist' outputs
Yes
No
Using stack trace facility
The stack traces facility collects diagnostics information upon server failures. In general, solidDB® Support and development teams use the stack traces facility for troubleshooting. You can also generate stack traces to gain information about a problem that you are investigating, but its use is rather limited without knowledge of the solidDB® source code.
About this task
The stack traces facility is controlled with the Srv.StackTraceEnabled parameter. When set to 'yes' (default), the stack trace information is output to ssstacktrace-<process_id>-<thread_id>.out file in the solidDB® working directory.
The following signals invoke the stack traces output automatically:
▪SIGSEGV
▪SIGILL
▪SIGBUS
▪SIGTRAP
▪SIGSYS
▪SIGEMT
The stack traces information is produced only about the thread that received the signal.
Additionally, you can generate the stack traces information for all currently running threads by sending the server the SIGUSR1 signal.
Note The stack traces facility is not supported on Windows operating systems.
Procedure
▪To enable or disable the stack traces facility, set the Srv.StackTraceEnabled parameter to 'yes' or 'no'.
▪To output the stack trace information manually without shutting down the server, send the server the SIGUSR1 signal.
For example, use the following command in Linux environments:
kill -SIGUSR1 <process_id>
Tracing communication between client and server
solidDB® provides the following tools for observing the communication between an application and a database server:
▪Network trace facility
Use the network trace facility when you want to know why a connection is not established to the solidDB® server.
▪Ping facility
Use the ping facility to determine how fast packets are transferred between an application and the solidDB® server.
Network trace facility: Network tracing can be done on the solidDB® node, on the application node, or concurrently on both nodes. The trace information is written to the default trace file or the file specified with the Com.TraceFile parameter.
The default name of the output file is soltrace.out. This file is created in the current working directory of the server or client depending on which end the tracing is started.
The file contains information about:
▪loaded DLLs
▪network addresses
▪possible errors
You can turn on the network trace facility in the following ways:
▪Use the Com.Trace and Com.TraceFile parameters.
Defining the TraceFile configuration parameter automatically turns on the Network trace facility.
▪Use the environment variables SOLTRACE and SOLTRACEFILE.
The environment variable settings override the definitions in the solid.ini file. Defining the SOLTRACEFILE environment variable automatically turns on the Network trace facility.
▪Use the option -t and/or -ofilename as a part of the network name.
– Option -t turns on the Network trace facility.
– Option -o turns on the facility and defines the name of the trace output file.
Defining trace parameters in the client-side configuration file
Scanning listening keyword Listen from section Com. No listening information found from section Com. Generating default listening info. Parsing address 'TCP/IP 1964'. Address information: fullname : 'TCP/IP 1964' lisname : '1964' protocol : 'tcp' (TCP/IP) enabled : Yes ping :0 trace : No Reading communication configuration from file D:\solid\solid.ini. Parsing address 'TCP/IP 1964'. Address information: fullname : 'TCP/IP 1964' lisname : '1964' protocol : 'tcp' (TCP/IP) enabled : Yes ping :0 trace : No Initialising protocol 'tcp' (TCP/IP). Searching DLL 'DTCW3237'. DLL s:\soldll\DTCW3237.DLL loaded. SOLID version 03.70.0026, DLL interface version 4. Build information Tue Oct 25 00:18:07 2002. Initialization of protocol 'tcp' succeeded. Protocol TCP/IP using configuration : MaxPhysMsgLen: 8192 ReadBufSize: 2048 WriteBufSize: 2048 SelectThread: Yes Trace: Yes MinWritePoolBuffers: 4 MaxWritePoolBuffers: -1 WritePoolIncrement: 1 SyncRead: No SyncWrite: No 26.07 15:12:21 Initializing server. Listen info 'TCP/IP 1964'. Starting the listening of 'TCP/IP 1964'.
Ping facility: The solidDB® ping facility can be used to test the performance and functionality of the network connection. The ping facility is built into all solidDB® client applications and is turned on with the network name option -p level .
The output file is written to the current working directory of the computer where the parameter is given. The default name of the output file is soltrace.out.
Clients can always use the ping facility at level 1. Levels 2, 3, 4 or 5 can be used only if the server is set to use the ping facility at least at the same level.
Setting
Function
Description
0
No operation
Do nothing, default
1
Check that server is alive
Exchange one 100 byte message
2
Basic functional test
Exchange messages of sizes 0.1K, 1K, 2K..30K, increment 1K
3
Basic speed test
Exchange 100 messages of sizes 0.1K, 1K, 8K and display each sub-result and total time
4
Heavy speed test
Exchange 100 messages of sizes 0.1K, 1K, 2K, 4K, 8K, 16K and display each sub-result and total time
5
Heavy functional test
Exchange messages of sizes 1..30K, increment 1 byte
Note If the solidDB® client does not have an existing server connection, you can use the SQLConnect() function with the connect string option -p1 (ping test, level 1) to check if solidDB® is listening in a certain address. Without logging in to solidDB®, SQLConnect() can then check the network layer and ensure solidDB® is listening. When used in this manner, SQLConnect() generates error code 21507, which means the server is alive.
Running ping facility at level 1
Turn on the ping facility by using the following network name syntax:
protocol_name -p level server_name
For example, to run the ping facility with solidDB® SQL Editor (solsql), use the following command:
solsql "tcp -p1 -oping.out 1964"
The above command runs the ping facility at the level 1 and outputs the results into soltrace.out. The ping facility checks if the server is alive and exchanges one 100 byte message to the server.
After the ping facility has been run, the client exits with the following message:
SOLID Communication return code xxx: Ping test successful/failed, results are in file FFF.XX
Com.Listen parameter and restrictions on the ping facility
The server-side ping level that is set with the Com.Listen parameter restricts the available ping levels on the client side. Clients can always use the ping facility at level 1 (0 is no operation/default). Levels 2, 3, 4 or 5 can be used only if the server is set to use the ping facility at least at the same level.
Note Ping clients running at level greater than 3 may cause heavy network traffic and may slow down any application that is using the network, including any SQL clients connected to the same solidDB®.