Purpose
The purpose of this wiki is to show how request logging can be used to find out expensive queries.
Overview
Request logging has been available in SQL Anywhere since version 8.0. It has been enhanced over the years with more functionality which was designed to help diagnose database performance problems. Although the information gathered with 'request logging' doesn't log as much information as 'database tracing' (introduced in version 10), it provides a quick and simple way to gather enough information for concurrency analysis without service interruption. This is particularly important for systems running 24/7 when we don't want to affect the end users and wish to minimize the performance impact on the system.
With request logging, database administrator can identify all SQL requests that are being sent to the database, their duration with query plan information, as well as blocking information which is required to help diagnose performance issues.
Below is an example that demonstrates how to identify expensive queries, using the request logging feature with SQL Anywhere 16.0.0.
Turn request logging 'On'
In order to start request-level logging, connect with dbisql utility and execute:
CALL dbo.sa_server_option('RequestLogFile',<request.log>);
CALL dbo.sa_server_option('RequestLogging',<options>);
Where : <request.log> - file where request logging information is stored and <options>:
- PLAN - enables logging of execution plans (short form).
- HOSTVARS - enables logging of host variable values.
- PROCEDURES - enables logging of statements executed from within procedures.
- TRIGGERS - enables logging of statements executed from within triggers.
- OTHER - enables logging of additional request types not included by SQL, such as FETCH and PREFETCH. .
- BLOCKS - enables logging of details showing when a connection is blocked and unblocked
- REPLACE - at the start of logging, the existing request log is replaced.
- ALL logs all supported information.
- NO or NONE turns off logging to the request log.
Example:
-- to start request logging for all connections
CALL dbo.sa_server_option( 'RequestLogging', 'all' );
-- example to log SQL , procedures and blocking
CALL dbo.sa_server_option( 'RequestLogging', 'SQL+PROCEDURES+BLOCKS' );
CALL dbo.sa_server_option( 'RequestLogFile', 'D:\v16.req' );
-- to start request logging for connection conn_id = 8
CALL dbo.sa_server_option( 'RequestFilterConn', '8' );
Or start server with -zo <request_log> -zr <option> . E.g.:
dbsrv16 -zr ALL -zo req.log demo16.db
Turn request logging 'Off'
In order to disable request logging execute following :
CALL dbo.sa_server_option( 'RequestLogging', 'none' );
CALL dbo.sa_server_option( 'RequestFilterConn', '-1' );
CALL dbo.sa_server_option( 'RequestFilterDB', '-1' );
CALL dbo.sa_server_option( 'RequestLogFile', '' );
Load request log into temporary tables
SAP SQL Anywhere provides a set of 2 stored procedures needed to load request log files into temporary tables. Once data has been loaded into these tables it's very easy to analyze it with simple SQL statements.
-- import request log file into global temp tables
call sa_get_request_profile('D:\v16.req');
call sa_get_request_times('D:\v16.req');
See: sa_get_request_times() and sa_get_request_profile()
Analyse request log information
Once satisfied with the data collected during logging, e.g long running query and specific user , run following queries to determine possible issues :
-- analyses the request log to determine the execution times of similar statements
select * From satmp_request_profile;
-- review requests ordered by duration
select * From satmp_request_time order by millisecs desc;
-- see if there was any blocking
select * From satmp_request_block;
-- to see blocked connections
SELECT *, DATEDIFF(ms,block_time,unblock_time) as dur_ms
FROM dbo.satmp_request_block
-- to see which actual SQL requests were blocked with e.g:
-- to see which SQL requests were blocked by what statements with e.g:
SELECT t.req_id, t.conn_id ,b.block_time, t.millisecs, t.stmt,b.blocked_on
,t1.req_id as blocking_req_id, t1.stmt ,t1.start_time,dateadd(ms,t1.millisecs,t1.start_time) blocker_end_time
FROM satmp_request_time t ,satmp_request_time t1, satmp_request_block b
WHERE b.req_id=t.req_id and t1.conn_id = b.blocked_on
and
(
( t1.start_time <= b.block_time and b.block_time <= dateadd(ms,t1.millisecs,t1.start_time) )
OR
(t1.start_time <= b.unblock_time and b.unblock_time <= dateadd(ms,t1.millisecs,t1.start_time) )
OR
(t1.start_time > b.block_time and dateadd(ms,t1.millisecs,t1.start_time) < b.unblock_time )
)
order by t.req_id, blocking_req_id
Example :
Connect with dbisql and start logging :
Test your application or simply run you queries :
Stop logging :
Load testing data into temporary tables:
Analyse logging data:
Find out the most expensive statements :
Note: Since the request-level log records all SQL statements that were executed, be aware that <request.log> file may contain sensitive data (personal information ,passwords etc.).