Logging server requests

For isolating some types of problems, especially problems with queries, logging server requests is helpful. You can enable request-level logging in two ways:

Server requests are logged in the server log file *.srvlog. The -zr server startup option enables request-level logging of operations and sets the type of requests to log (ALL, NONE, or SQL). The -zo option redirects request-level logging information to a file separate from the regular log file and -zs limits the size of this file.

NoteIf the size of the query text being written to the log exceeds the specified limit, the query text is not truncated and is logged in its entirety. See “Starting the database server” in Chapter 1, “Running the Database Server” of Utility Guide.

You can enable and disable request-level logging without restarting the Sybase IQ server using the sa_server_option stored procedure. The following commands enable request-level logging of a limited set of requests and redirect the output to the file sqllog.txt:

call sa_server_option('request_level_logging','SQL');
call sa_server_option('request_level_log_file',
                       'sqllog.txt');

The following command disables request-level logging:

call sa_server_option('request_level_log_file','');

To view the current settings for the SQL log file and logging level, execute the following statement:

select property('RequestLogFile'),        property('RequestLogging');

To match .iqmsg log and the -zr server request log (.srvlog) entries using connection information, see “Correlating connection information”.

In Sybase IQ version 15.1, the request log was modified. Instead of fixed-format line prefixes, common information is recorded as comma-delimited text. Where possible, times are recorded as “=” (meaning the same as the previous line) or +nnn (meaning nnn milliseconds after the previous line). Request logs are much smaller now than in versions earlier than Sybase IQ 15.1.

In addition, more information is recorded in the request log. For queries, the information recorded is isolation level, number of rows fetched, and cursor type. For INSERT, UPDATE, and DELETE statements, the information recorded is number of rows affected and number of triggers fired.

Optionally, you can also choose to log statements executed within procedures and triggers.

You can select to record the short form of query plans in the request log. If procedure logging is enabled, plans for procedure statements are also recorded.

The following output shows an excerpt from the request log, when the server is started with the -zr all option. In this example, the user connects to the iqdemo database and executes the command sp_iqstatus.

There are several comma-separated fields in each line, and the first field indicates the time. Periodically, a full timestamp is output in the form:

MMdd hhmmss.sss
0523 095954.807,[,1000000001,sp_iq_mpx_init,16,iq utilities status 1

For lines after this line, for example, “+13,C,1,UID=DBA”, the offset is from the previous line. In this case, “+13” means that about 13 milliseconds have passed since the last line. In some cases, “=” means approximately 0 milliseconds have elapsed since the last line.

Here is the excerpt from the request log:

0523 095954.807,[,1000000001,sp_iq_mpx_init,16,iq
utilities status 1
+2,],1000000001,sp_iq_mpx_init,16
+1,[,1000000001,sp_iq_mpx_init,62,message STRING('IQ
Server ',@@servername,'.') to console
+2,],1000000001,sp_iq_mpx_init,62
taj% pg iqdemo.sqllog
0523 095954.807,[,1000000001,sp_iq_mpx_init,16,iq
utilities status 1
+2,],1000000001,sp_iq_mpx_init,16
+1,[,1000000001,sp_iq_mpx_init,62,message STRING('IQ
Server ',@@servername,'.') to console
+2,],1000000001,sp_iq_mpx_init,62
0523 100510.344,<,1,CONNECT
+13,C,1,UID=DBA
+83,>,1,CONNECT,1
+1,<,1,PREPARE,SELECT @@version, if 'A'<>'a' then 1
else 0 endif, isnull(property('IsIQ'),'NO'),
isnull(connection_property('odbc_distinguish_char_and_
varchar'),'Off'),
isnull(connection_property('odbc_describe_binary_as_va
rbinary'),'Off'), connection_property('charset'),
db_property('charset')
+1,>,1,PREPARE,65536
=,<,1,EXEC,65536
+79,P,1,[S]DUMMY<seq>
=,>,1,EXEC
+1,<,1,DROP_STMT,65536
=,>,1,DROP_STMT
=,<,1,PREPARE,SET TEMPORARY OPTION time_format =
'hh:nn:ss';SET TEMPORARY OPTION timestamp_format =
'yyyy-mm-dd hh:nn:ss.ssssss';SET TEMPORARY OPTION
date_format = 'yyyy-mm-dd';SET TEMPORARY OPTION
date_order = 'ymd';SET TEMPORARY OPTION isolation_level
= 0;
+1,>,1,PREPARE,65537
+1,<,1,EXEC,65537
=,[,1,*batch*,1,set temporary option time_format =
'hh:nn:ss'
+11,],1,*batch*,1
=,[,1,*batch*,1,set temporary option timestamp_format =
'yyyy-mm-dd hh:nn:ss.ssssss'
+11,],1,*batch*,1
+1,[,1,*batch*,1,set temporary option date_format =
'yyyy-mm-dd'
+11,],1,*batch*,1
=,[,1,*batch*,1,set temporary option date_order = 'ymd'+11,],1,*batch*,1
=,[,1,*batch*,1,set temporary option isolation_level = 0
+11,],1,*batch*,1
=,>,1,EXEC

Request log file analysis

The format of the output in the request log file (generated by setting the -zr server startup switch) changed in Sybase IQ 15.1. Use the stored procedures sa_get_request_profile and sa_get_request_times to read the -zr log file and summarize the results.

sa_get_request_profile analyzes the request log to determine the execution times of similar statements and summarizes the results in the global temporary table satmp_request_profile. For example:

call sa_get_request_profile('/sys1/users/jones/iqreqs1_zr.log');
select * from satmp_request_profile;

sa_get_request_times also analyzes the request log to determine statement execution times and summarizes the results in the global temporary table satmp_request_time. For example:

call sa_get_request_times('/sys1/users/jones/iqreqs1_zr.log');
select * from satmp_request_time;

For more information about request-level logging, see the -zo switch in “start_iq server options” in Chapter 1, “Running the Database Server” of the Utility Guide, “sa_server_option system procedure” in Chapter 7, “System Procedures”of Reference: Building Blocks, Tables, and Procedures, and “Request logging” in SQL Anywhere Server – SQL Usage > Monitoring and Improving Database Performance > Improving database performance > Other diagnostic tools and techniques.