Introduction
If you have ever done any development in the .NET or JAVA you may have been exposed to a logging utility from a company called Apache called log4net™, for more information there is a link at the end of this article. This is an open source logging utility which can be used to create very extensive logging from within an application. When we were developing COBOL or PLI External Stored Procedures we were able to use the DISPLAY option in those languages.
However, within SQLPL we no longer have the ability to use something like a DISPLAY command and get information from within the execution of our new DB2 Native SQL stored procedures.
What this article is written to describe is how logging can be implemented into DB2 Native SQL stored procedures. It will also describe some of the concepts that are included in the overall design. These concepts were incorporated into the DB2 Native SQL stored procedures from my own experience in using the log4net utility with several C# applications which I have written. My logging examples consist of 3 basic components, and an example on how to add the logging to a DB2 Native SQL stored procedure. The diagram below, shown as Figure 1, identifies the components and how they interact within the scheme of creating a log entry.
This article will walk you through how you can implement a similar logging methodology from within your DB2 Native SQL stored procedure. There is one drawback to this process. It will only work if you are on DB2 11 for z/OS New Function Mode, or DB2 9.7 for LUW. That is because it requires the ability to use the new Autonomous stored procedure feature.
Task One
Create 2 DB2 tables which will be used to accept and control log entries from your stored procedures. Figure 1 shows a DB2 for z/OS example table that could be used to store log entries from your stored procedures, and a table which allows you to control the level of logging for a program. Figure 2 shows a sample table.
CREATE TABLE “schema”.STORE_PROC_LOG
(
Id INTEGER GENERATED ALWAYS AS IDENTITY PRIMARY KEY NOT NULL
,Date TIMESTAMP (6) WITHOUT TIME ZONE NOT NULL
,Application VARCHAR(50) NOT NULL
,Level VARCHAR(50) NOT NULL
,Logger VARCHAR(255) NOT NULL
,Message VARCHAR(4000) NOT NULL
,Exception VARCHAR(2000) NULL
,NDC VARCHAR(255) NOT NULL
)
IN database.tablespace
APPEND NO
NOT VOLATILE CARDINALITY
DATA CAPTURE CHANGES
AUDIT NONE
CCSID EBCDIC;
Figure 2 –Example Log table definition
CREATE TABLE “schema”.STORE_PROC_LOG_CNTL
(
Id INTEGER GENERATED ALWAYS AS IDENTITY PRIMARY KEY NOT NULL
,Application VARCHAR(50) NOT NULL
,ProgramName VARCHAR(50) NOT NULL
,LogFlag SMALLINT NOT NULL
)
IN database.tablespace
APPEND NO
NOT VOLATILE CARDINALITY
DATA CAPTURE CHANGES
AUDIT NONE
CCSID EBCDIC;
Figure 3 –Example Log Control table definition
Task Two
Create an Autonomous DB2 Native SQL stored procedure which will create the log entry in the STORE_PROC_LOG table. The example below, shown as Figure 3, uses individual parameters as input and can serve as a basis for you to use to create your own stored procedure.
CREATE PROCEDURE SP_LOGGER(IN p_Application VARCHAR(50)
,IN p_StorProc VARCHAR(128)
,IN p_Level VARCHAR(50)
,IN p_Logger VARCHAR(255)
,IN p_Message VARCHAR(4000)
,IN p_Exception VARCHAR(2000)
,IN p_NDC VARCHAR(255))
VERSION V1
ISOLATION LEVEL CS
RESULT SETS 0
LANGUAGE SQL
AUTONOMOUS
QUALIFIER “schema”
P1: BEGIN
SELECT LogFlag
INTO v_LogFlag
FROM STORE_PROC_LOG_CNTL
WHERE Application = p_Application
AND ProgramName = p_StorProc
IF v_LogFlag = 4 THEN
BEGIN
INSERT INTO STORE_PROC_LOG
(Date
,Application
,Level
,Logger
,Message
,Exception
,NDC)
VALUES
(CURRENT DATE
,p_Application
,p_Level
,p_Logger
,p_Message
,p_Exception
,p_NDC);
END;
ELSE
BEGIN
IF p_Level <> ‘DEBUG’ THEN
INSERT INTO STORE_PROC_LOG
(Date
,Application
,Level
,Logger
,Message
,Exception
,NDC)
VALUES
(CURRENT DATE
,p_Application
,p_Level
,p_Logger
,p_Message
,p_Exception
,p_NDC);
END IF;
END;
END IF;
END P1
Figure 4 – DB2 Native SQL Stored procedure to insert logging entries.
Task Three
Implement the code to invoke the new logging stored procedure and to pass it the information that you want to use to create a log entry. In the LOG4NET utility, there are four basic log entries. They are INFO, DEBUG, WARN, and ERROR. There are a couple of additional types; however they would require a lot more logic in your stored procedure to implement them. The basic four will give you more than enough options to satisfy your requirements. The example below, shown as Figure 4, shows how to call your logging stored procedure using individual parameters instead of a XML Document to insert a log entry.
CREATE PROCEDURE SP_LOG_EXAMPLE(IN p_LocNbr INTEGER,
IN p_DeptNbr SMALLINT,
IN p_VndNumericDesc SMALLINT,
IN p_Pid CHAR(20),
OUT p_SqlCode INTEGER,
OUT p_RtrnCd SMALLINT,
OUT p_MessageText CHAR(132))
ASUTIME LIMIT 3332200
LANGUAGE SQL
ISOLATION LEVEL CS
PACKAGE OWNER ADADC
WITH EXPLAIN
RESULT SETS 1
QUALIFIER “schema”
P1: BEGIN
DECLARE SQLCODE INTEGER;
DECLARE V_PROCESSNAME CHAR(30) DEFAULT 'Start of Procedure';
DECLARE V_MESSAGETEXT CHAR(132);
DECLARE v_XMLdoc XML;
DECLARE v_APPID VARCHAR(50);
DECLARE v_APPNAME VARCHAR(50);
DECLARE v_ERRORLEVEL VARCHAR(50);
DECLARE v_Logger VARCHAR(255);
DECLARE v_Message VARCHAR(4000);
DECLARE v_ERRORMSG VARCHAR(2000);
DECLARE v_NDC VARCHAR(255);
DECLARE v_PROCESSTEXT VARCHAR(3000);
DECLARE v_StartTime TIMESTAMP;
DECLARE v_ElapsedTime INTEGER;
DECLARE v_Ident VARCHAR(50);
DECLARE v_IntValue INTEGER;
------------------------------------------------------------------------
-- Declare common condition handlers in case of an exception
------------------------------------------------------------------------
--Declare SQL exception handler
------------------------------------------------------------------------
DECLARE EXIT HANDLER FOR SQLEXCEPTION
BEGIN
GET DIAGNOSTICS CONDITION 1
p_MessageText = MESSAGE_TEXT;
SET v_ERRORLEVEL = 'ERROR';
SET v_Ident = 'E1';
SET v_Logger = v_APPNAME || '/' || v_Ident;
SET v_PROCESSTEXT = ' ';
SET v_Message = v_APPNAME || ' - ' || v_PROCESSTEXT;
SET v_ERRORMSG = p_MessageText;
CALL SP_LOGGER(RTRIM(v_APPID),
RTRIM(v_APPNAME),
RTRIM(v_ERRORLEVEL),
RTRIM(v_Logger),
RTRIM(v_Message),
RTRIM(v_ERRORMSG),
RTRIM(v_NDC));
SET v_ERRORLEVEL = 'INFO';
SET v_Ident = 'P1/A1';
SET v_Logger = v_APPNAME || '/' || v_Ident;
SET v_PROCESSTEXT = ' - Finished.';
SET v_Message = v_APPNAME || ' - ' || v_PROCESSTEXT;
SET v_ERRORMSG = '';
CALL SP_LOGGER(RTRIM(v_APPID),
RTRIM(v_APPNAME),
RTRIM(v_ERRORLEVEL),
RTRIM(v_Logger),
RTRIM(v_Message),
RTRIM(v_ERRORMSG),
RTRIM(v_NDC));
END;
------------------------------------------------------------------------
-- Declare Not Found condition handler
------------------------------------------------------------------------
DECLARE CONTINUE HANDLER FOR NOT FOUND
BEGIN
SET p_SqlCode = SQLCODE;
SET p_RtrnCd = 7;
SET v_ERRORLEVEL = 'WARN';
SET v_Ident = 'W1';
SET v_Logger = v_APPNAME || '/' || v_Ident;
SET v_PROCESSTEXT = ' ';
SET v_Message = v_APPNAME ||
' - ' ||
p_SqlCode || ‘ – ‘ ||
v_PROCESSTEXT;
SET v_ERRORMSG = '';
CALL SP_LOGGER(RTRIM(v_APPID),
RTRIM(v_APPNAME),
RTRIM(v_ERRORLEVEL),
RTRIM(v_Logger),
RTRIM(v_Message),
RTRIM(v_ERRORMSG),
RTRIM(v_NDC));
END;
------------------------------------------------------------------------
-- Declare processing logic
------------------------------------------------------------------------
A1: BEGIN
SET v_APPID = 'TST';
SET v_APPNAME = 'SP_LOG_EXAMPLE';
SET v_NDC = CHAR(p_LocNbr) || ‘~’ || CHAR(p_DeptNbr) || ‘~’ ||
CHAR(p_VndNumericDesc) || ‘~’ || p_Pid ;
SET v_ERRORLEVEL = 'INFO';
SET v_Ident = 'P1/A1';
SET v_Logger = v_APPNAME || '/' || v_Ident;
SET v_PROCESSTEXT = ' - Begin';
SET v_Message = v_APPNAME || ' - ' || v_PROCESSTEXT;
SET v_ERRORMSG = '';
CALL SP_LOGGER(RTRIM(v_APPID),
RTRIM(v_APPNAME),
RTRIM(v_ERRORLEVEL),
RTRIM(v_Logger),
RTRIM(v_Message),
RTRIM(v_ERRORMSG),
RTRIM(v_NDC));
SET v_ERRORLEVEL = 'DEBUG';
SET v_Ident = 'P1/A1';
SET v_Logger = v_APPNAME || '/' || v_Ident;
SET v_PROCESSTEXT = ' - Divide b into a';
SET v_Message = v_APPNAME || ' - ' || v_PROCESSTEXT;
SET v_ERRORMSG = '';
CALL SP_LOGGER(RTRIM(v_APPID),
RTRIM(v_APPNAME),
RTRIM(v_ERRORLEVEL),
RTRIM(v_Logger),
RTRIM(v_Message),
RTRIM(v_ERRORMSG),
RTRIM(v_NDC));
SET v_IntValue = 5 / 0;
SET v_ERRORLEVEL = 'INFO';
SET v_Ident = 'P1/A1';
SET v_Logger = v_APPNAME || '/' || v_Ident;
SET v_PROCESSTEXT = ' - Finished.';
SET v_Message = v_APPNAME || ' - ' || v_PROCESSTEXT;
SET v_ERRORMSG = '';
CALL SP_LOGGER(RTRIM(v_APPID),
RTRIM(v_APPNAME),
RTRIM(v_ERRORLEVEL),
RTRIM(v_Logger),
RTRIM(v_Message),
RTRIM(v_ERRORMSG),
RTRIM(v_NDC));
END A1;
END P1
Figure 5 - DB2 Native SQL Stored procedure to demonstrate how to use logging with parameters.
Log Results
The example below, shown as Figure 8, shows what the log information would look like when you query the log table.
As can be seen by the example output from the Log table, this execution of the sample stored procedure shows that the stored procedure encountered a -802 SQL code due to a divide by zero error.
Conclusion
As you may have noted, I used all four of the log entries to display different types of information. The difference is in how and where I used them. As you may have noticed, I used the ‘INFO’ log type at the beginning and end of the stored procedure. Then within the stored procedure at various points during the execution path, I used the ‘DEBUG’ log type and provided additional information so that the stored procedure execution path can be studied whenever there is a problem with the execution of the stored procedure. I used the ‘WARN’ log type whenever a CONTINUE HANDLER was invoked within the stored procedure indicating that something occurred that was not what was expected, but was not severe enough to warrant termination of the stored procedure execution. Finally, I used the ‘ERROR’ log type whenever an EXIT HANLDER was invoked to terminate the stored procedure execution. By using these four log types in various combinations, you can create some very sophisticated logging for your DB2 Native SQL stored procedures.
The amount of logging which can be added to a native SQL stored procedure is only limited by the requirements of your organization. The more that you add the more insight you will have into the functioning of your stored procedures. Some additional things that can be done to limit the amount of log entries is to add an input parameter to your stored procedure which will allow you to selectively determine if you want to insert ‘DEBUG’ entries. Therefore, those debugging messages are issued only when you are actively testing your stored procedures, and during normal execution all that will be inserted will be ‘INFO’, ‘ERROR’, and ‘WARN’ level log entries.
In addition, the NDC column can be created with anything that you want to add to help you decipher what entered into the log. When I have used the LOG4NET utility in non-DB2 applications I have placed parameter values into that column delimited by a tilde (‘~’) character. This has allowed me to take the output from the log table into a Microsoft Excel spreadsheet, and gave me the ability to slice and dice the information to fit my needs.
The first thing that most people might say is that it will take too much time to implement logging in a stored procedure. That is the same complaint that is given when a developer is tasked to add documentation to an application. However, the time spent in doing both of these tasks are very often recovered the first time that a production issue in a DB2 Native SQL stored procedure requires some research to debug.
I hope that this article will provide an insight into how beneficial it can be to implement a logging methodology into your organizations DB2 Native SQL stored procedures.
For more information on the Apache log4net utility click on this link
Elwin Harrison
Elwin.Harrison@macys.com