Profiling ODBC Driver Performance
The Microsoft® SQL Server™ ODBC driver can profile two types of performance data:
- Long-running queries.
The driver can write to a log file any query that does not get a response from the server within a specified amount of time. Application programmers or database administrators can then research each logged SQL statement to determine how they can improve its performance.
- Driver-performance data.
The driver can record performance statistics and either write them to a file or make them available to an application through a driver-specific data structure named SQLPERF. The file containing the performance statistics is a tab-delimited file that can be easily analyzed with any spreadsheet that supports tab-delimited files, such as Microsoft Excel.
Either type of profiling can be turned on by:
- Connecting to a data source that specifies logging.
- Calling SQLSetConnectAttr to set driver-specific attributes that control profiling.
Each application process gets its own copy of the SQL Server ODBC driver, and profiling is global to the combination of a driver copy and an application process. When anything in the application turns on profiling, profiling records information for all connections active in the driver from that application. Even connections that did not specifically call for profiling are included.
After the driver has opened a profiling log (either the performance data or long-running query log), it does not close the log until the driver is unloaded by the ODBC Driver Manager, when an application frees all the environment handles it opened in the driver. If the application opens a new environment handle, a new copy of the driver is loaded. If the application then either connects to a data source that specifies the same log file or sets the driver-specific attributes to log to the same file, the driver overwrites the old log.
If an application starts profiling to a log file and a second application attempts to start profiling to the same log file, the second application is not able to log any profiling data. If the second application starts profiling after the first application has unloaded its driver, the second application overwrites the log file from the first application.
If an application connects to a data source that has profiling enabled, the driver returns SQL_ERROR if the application calls SQLSetConnectOption to start logging. A call to SQLGetDiagRec then returns:
SQLState: 01000, pfNative = 0 ErrorMsg: [Microsoft][ODBC SQL Server Driver] An error has occurred during the attempt to access the log file, logging disabled.
The driver stops gathering performance data when an environment handle is closed. If an ODBC 3.x application has multiple connections, each with its own environment handle, then the driver will stop gathering performance data when any of the associated environment handles are closed.
The driver's performance data can either be stored in the SQLPERF data structure or logged in a tab-delimited file. The data includes the following categories of statistics:
- Application profile
In the following table, the descriptions of the fields in the SQLPERF data structure also apply to the statistics recorded in the performance log file.
|Application Profile Statistics:|
|TimerResolution||Minimum resolution of the server's clock time in milliseconds. This is usually reported as 0 (zero) and should only be considered if the number reported is large. If the minimum resolution of the server clock is larger than the likely interval for some of the timer-based statistics, those statistics could be inflated.|
|SQLidu||Number of INSERT, DELETE, or UPDATE statements after SQL_PERF_START.|
|SQLiduRows||Number of INSERT, DELETE, or UPDATE statements after SQL_PERF_START.|
|SQLSelects||Number of SELECT statements processed after SQL_PERF_START.|
|SQLSelectRows||Number of rows selected after SQL_PERF_START.|
|Transactions||Number of user transactions after SQL_PERF_START, including rollbacks. When an ODBC application is running with SQL_AUTOCOMMIT_ON, each command is considered a transaction.|
|SQLPrepares||Number of SQLPrepare calls after SQL_PERF_START.|
|ExecDirects||Number of SQLExecDirect calls after SQL_PERF_START.|
|SQLExecutes||Number of SQLExecute calls after SQL_PERF_START.|
|CursorOpens||Number of times the driver has opened a server cursor after SQL_PERF_START.|
|CursorSize||Number of rows in the result sets opened by cursors after SQL_PERF_START.|
|CursorUsed||Number of rows actually retrieved through the driver from cursors after SQL_PERF_START.|
|PercentCursorUsed||Equals CursorUsed/CursorSize. For example, if an application causes the driver to open a server cursor to do "SELECT COUNT(*) FROM authors," 23 rows will be in the result set for the SELECT statement. If the application then fetches only three of these rows, CursorUsed/CursorSize is 3/23, so PercentCursorUsed is 13.043478.|
|SQLFetchTime||Cumulative amount of time it took fetches against server cursors to complete.|
|SQLFetchCount||Number of fetches done against server cursors after SQL_PERF_START.|
|CurrentStmtCount||Number of statement handles currently open on all connections open in the driver.|
|MaxOpenStmt||Maximum number of concurrently opened statement handles after SQL_PERF_START.|
|SumOpenStmt||Number of statement handles that have been opened after SQL_PERF_START.|
|CurrentConnectionCount||Current number of active connection handles the application has open to the server.|
|MaxConnectionsOpened||Maximum number of concurrent connection handles opened after SQL_PERF_START.|
|SumConnectionsOpened||Sum of the number of connection handles that have been opened after SQL_PERF_START.|
|SumConnectionTime||Sum of the amount of time that all of the connections have been opened after SQL_PERF_START. For example, if an application opened 10 connections and maintained each connection for 5 seconds, then SumConnectionTime would be 50 seconds.|
|AvgTimeOpened||Equals SumConnectionsOpened/ SumConnectionTime.|
|ServerRndTrips||The number of times the driver sent commands to the server and got a reply back.|
|BuffersSent||Number of Tabular Data Stream (TDS) packets sent to SQL Server by the driver after SQL_PERF_START. Large commands can take multiple buffers, so if a large command is sent to the server and it fills six packets, ServerRndTrips is incremented by one and BuffersSent is incremented by six.|
|BuffersRec||Number of TDS packets received by the driver from SQL Server after the application started using the driver.|
|BytesSent||Number of bytes of data sent to SQL Server in TDS packets after the application started using the driver.|
|BytesRec||Number of bytes of data in TDS packets received by the driver from SQL Server after the application started using the driver.|
|msExecutionTime||Cumulative amount of time the driver spent processing after SQL_PERF_START, including the time spent waiting for replies from the server.|
|msNetworkServerTime||Cumulative amount of time the driver spent waiting for replies from the server.|
To profile driver performance data
To log long-running queries