Motivation

You might need to write informational, error, and debug messages to a log file for a number of reasons:

  • To test, analyze and validate business logic.
  • To track and review detailed error messages.
  • To fix business logic bugs encountered in production environment by dynamically switching detailed logging or or off.
  • To pinpoint performance problems in the stored procedures by examining execution times of the logging statements.

You can use this logging framework for stored procedures to fulfill the following requirements:

  1. Dynamically turn on or off global or selective logging in the production environment.
  2. Archive log files to maintain the current log file at a manageable size.
  3. Identify logging statements for each stored procedure and each DB2 agent.
  4. Split or combine log files for each DB2 agent.
  5. Insure that logging itself is not resource intensive.

DB2 itself has its own logging methods to dump messages to the db2diag.log file. DB2 also provides facilities to capture and dump detailed traces, so that the DB2 developers can isolate and fix the reported issues. The logging framework presented in this article provides capabilities to capture the informational and debug messages to a file for analysis, so that the stored procedure developers can isolate and fix the problem.

Since DB2 stored procedures can be executed concurrently by different DB2 agents, it is necessary for each instance of the logging stored procedure to read and share all logging control information with other procedures. For this purpose, we use shared memory that is accessible to each instance of the logging procedure.

How to configure logging

To configure logging for a stored procedure, use the procedure DB2.UPDATE_SP_CONFIG. You can use this procedure to start, stop, and control logging, and to set parameters in shared memory so that all executing procedures can use the same logging control information.

In order to enable or disable logging for each stored procedure, or for all stored procedures simultaneously, save the information in a configuration file and load it in shared memory at the first invocation of the logging stored procedure. When modifications to the logging configuration parameters are made, the information is updated in shared memory and is also saved in the configuration file. (Note: This is very similar to the update of DB2 configuration parameters, where changes in some parameters take effect immediately, and some are deferred to the instance or database restart. In the case of this logging framework, any change in stored procedure logging parameters takes effect immediately).

One goal of the logging framework is to be conservative with system resources so that the logging procedure calls are not expensive, or do not incur much overhead. The framework is designed to handle logging by thousands of stored procedures without impacting much performance.

For each logging call, we need to determine whether or not the message is to be sent to the log file. We look up a hash table with linked list based upon the hash key for the logging token name. For names sharing the same hash key, we maintain a linked-list at that same key-level to look up the configuration parameters for that specific logging token name. The use of the hash table with linked list provides the quickest lookup.

The log files themselves can grow very fast if you enable full logging on all the stored procedures. Archiving the log files allows you to move the log files to another location for analysis, storage, or deletion purposes.

How to initiate logging

To initiate logging from a DB2 stored procedure, first call DB2.OPEN_LOG with two parameters. The first parameter is a logging token name, and the second is a handle. To keep things simple, you can use the name of the stored procedure as the logging token name. You can also use a common logging token for a group of stored procedures for a particular business function. For example, if you have a nested procedure calling another six DB2 stored procedures to Get Best Rate Quote, you can use a token name GBQR for all seven DB2 stored procedures. The second parameter in DB2.OPEN_LOG is a handle of CHAR(72) bytes. This handle consists of the name of the SP being logged and the original and previous timestamp of the logger statement. We use these timestamps to calculate final and elapsed time between logger statements.

struct _handle 
{
        char spName[NAMESIZE+DBSIZE];
        struct timeb startTime; /* Pass starttime to know total elapsed time */
        struct timeb prevTime; /* Pass previous time to know elapsed time 
                                  since previous logger step */
};

Please note: The length of the handle could be different on different Linux/Unix platforms. Please see testsp.sql file that is generated after you compile the source. This is one potential area when you may not get proper elapsed time between logger calls if the size is different than 72. I tested this on Linux and Aix and the size of the handle comes out to be 72 and it is likely that it could be different on Solaris. I have not tested this on Solaris.

How to log messages

The logging framework provides two stored procedures for logging messages: DB2.LOGINFO and DB2.LOGGER. Each stored procedure requires two parameters. The first is the logging handle obtained from DB2.OPEN_LOG, and the second is the message to be logged. DB2.LOGINFO logs an informational message if the logging token exists in the shared memory. DB2.LOGGER logs a debug message if the debug parameter is set to Y and a logging token exists in the shared memory.

Generally, you will use LOGINFO to log detailed error and other informational messages. You will use LOGGER to capture your debug messages to the log file. When you do not want to log debug messages to the log file, turn them off by setting the debug parameter to N for the logging token. To set this parameter, use the stored procedure DB2.UPDATE_SP_CONFIG, which is used for logging administration. If you want to turn off LOGINFO messages entirely, remove the logging token from the shared memory by setting debug parameter to R to remove the token permanently.

How to close logging

At the end of your stored procedure, you can close logging by calling DB2.CLOSE_LOG. The CLOSE_LOG procedure requires the logging handle as the input parameter. The CLOSE_LOG writes the last message with the elapsed time from start of the logging to the end of the logging. The CLOSE_LOG call is useful to determine the total elapsed execution time.