Since their inclusion in DB2 UDB V7, SQL procedures have quickly become powerful tools for application development. In addition the SQL Procedural Language (SQL PL) is the natural target language for applications migrated or ported to DB2 UDB from Oracle PL/SQL, Microsoft® SQL Server/Sybase T-SQL, or IBM® Informix® SPL.
While the SQL/PSM standard, and with it SQL PL, provides sophisticated condition handling, this language feature does not provide a way to detect what led up to a particular condition. Furthermore, condition handlers can only be of help if they are coded in all the right places. Also migration from a DBMS, which does not support condition handlers using automated tools such as the migration tool kit (MTK), naturally leaves big gaps in error coverage.
So how do you, as a developer, deal with a
SQL0445W Value "100000" has been truncated. SQLSTATE=01004
warning, which you received from your nested billing procedure? Well, you can read through all the procedure code, following the nested calls and hope the problem just jumps out at you. Or you can start the statement event monitor, search for the SQLCA and back-track from there to the SQL procedure source code. To find the path how your procedure got to the warning condition you will need to repeat this step backwards in time. Alternatively you can read through the rest of this article, download the files and just trace the billing procedure.
We will start with the fun part for the impatient reader. This is the SQL procedure tracing API as used by an application developer. Then, for the more curious, I will explain DB2âs underlying, low-level API, which you can use to build upon my efforts.
To install the trace API, you have two options. The first applies if you use one of the platforms for which this article has pre-prepared executables. The second option requires you to compile the API yourself using a C-compiler:
- You are on a Windows®32-bit system or Linux Intel 32-bit:
- download the respective zip file and extract it
- copy the sqpltrc executable into sqllib\function\unfenced
- connect to the database where you plan to trace, e.g.,
db2 connect to sample
- Bind the sqlpltrc.bnd file to the database:
db2 bind sqlpltrc.bnd
- Run the DDL script to register the procedures:
db2 âtvf sqlpltrc.db2
You can repeat steps 4 and 5 against as many databases as you wish.
- For any other platform supported by DB2 UDB,
- Download and extract sqlpltrc_source.zip
sqlpltrc.exp(on UNIX/Linux) or
sqlpltrc.def(on Windows) to
bldtraceand add the
db2psmdlibrary to the link step of
bldtraceand modify the final
sqllib/function/unfenced. Note that on Windows the files need to end with
.bat, while on UNIX or Linux they need to be marked as executable scripts.
On Windows the new lines will look like this:
:link_step rem Link the program. link -debug -out:%1.dll -dll %1.obj db2api.lib db2psmd.lib -def:%1.def rem Copy the routine DLL to the ' function\unfenced&' directory copy %1.dll "%DB2PATH%\function\unfenced" @echo on
On AIX ® the changedparts of
# Link the program using the export file $1.exp, xlc_r $EXTRA_CFLAG -qmkshrobj -o $1 $1.o -ldb2 -ldb2psmd -L$DB2PATH/$LIB -bE:$1.exp # Copy the shared library to the sqllib/function/unfenced subdirectory. # Note: the user must have write permission to this directory. rm -f $DB2PATH/function/unfenced/$1 cp $1 $DB2PATH/function/unfenced
- Prep, bind, and deploy the library against the desired database, e.g.,
bldtrace sqlpltrc sample
- Run the DDL script to register the procedures:
db2 âtvf sqlpltrc.db2
Once you have compiled on your development machine, you can deploy on other, compatible platforms, in the same way as described above for Linux and Windows. So you only need a C-compiler once to produce the executable.
SQL procedure tracing API
The API can be grouped into three groups:
- Trace management
- Trace reporting
- Trace entries
Letâs walk through these interfaces in order.
- Trace Management
As trace management, label the tooling needed to actually do a trace and clean up afterwards.
TRACE.SQLPROC_TRACE_ON (IN USERTEMPSPACE VARCHAR(128))
This procedure turns tracing on for the current session.
The user temporary table space DB2 should use to store the trace information. For best performance when tracing in DB2 with DPF the chosen table space should be only on the database partition number of the sessionâs coordinator. This will also avoid the risk of skew in timestamps if the trace is stored in a database partitioned table space which may confuse the trace reports. If NULL is provided the table space will be chosen as described in the SQL Reference manual for global temporary tables.
This procedure turns tracing off for the current session. All trace data collected so far will be lost. The consumed space in the user temporary table space will be freed.
This procedure deletes the trace data collected so far if tracing is on. The procedure does not switch trace off. The consumed space in the user temporary table space will be freed.
This procedure dumps all the collected trace data into a result set which it returns to the caller. This procedure is included here as a layer of abstraction from the lower level APIâs implementation. If you really need the dump data it may be more efficient to write SQL against the API as described later in this article.
Column name Column type Nullable Description
no This is the timestamp when the trace event was written.
ROUTINEIDis the ID of the procedure logging the event as used in
SYSCAT.ROUTINES. The ID can be used to find the corresponding
no For message trace entries this column contains the approximate line-number of the error or warning in the SQL Procedure. The line number is approximate because DB2âs PSM Virtual Machine (PVM) does some rewriting of SQL PL. For example, it may combine series of SET statements.
no The event type is an encoding of
DATA. The encoding can be translated from the table
no This column holds the SQLCODE when the trace entry was written.
no This column holds the SQLSTATE at the time the trace entry was written
no This column contains a user provided text in case of a trace data entry. In case of a non-zero SQLCODE the DATA column contains the message tokens from the SQLCA.
- Trace reporting
Two procedures are currently in this class, but they are the centerpieces of the API.
This procedure analyzes the trace collected so far and produces a readable trace flow report. There are only two columns in the report: A sequential numbering and the formatted trace entry for each event.
This procedure sums up the collected trace and lists how often a given stored procedure was called and how much time passed for all calls. This report can be useful to quickly find bottlenecks within the application. However, the elapsed time must be viewed with caution since the values are skewed by the tracing itself. The more complex and long-running stored procedures are, the more reliable this information will be.
- Trace entries
In addition to transparent tracing for SQL procedures, this API also provides for explicit tracing. This feature can be used to enrich the SQL Procedure tracing with explicit trace points, or to add tracing to procedures written in other languages, such as C. Note that, in contrast to transparent tracing of SQL procedures, these trace procedures need to be explicitly invoked. Therefore, even if tracing is disabled an overhead will occur. The procedures are mainly provided for debugging purposes. In high-performance code they should be removed
TRACE.SQLPROC_TRACE_PID() RETURNS INTEGER
This scalar function tests whether tracing is on and returns the current ROUTINEID if tracing is ON. If tracing is OFF the ROUTINEID is NULL. This function should be invoked at the beginning of the SQL Procedure if
TRACE.SQLPROC_TRACE_DATAwill be called in the procedures body.
TRACE.SQLPROC_TRACE_ENTRY (IN SCHEMANAME VARCHAR(128), IN SPECIFICNAME VARCHAR(128), OUT ROUTINEID INT)
This procedure traces the entry to procedure. It should be called at the very beginning of the procedural logic, right after the variable declarations.
The schema name of the routine that this code describes.
The name specified as
SPECIFIC NAMEin the
CREATE FUNCTIONstatement. Note that it is always good to specify a specific name. Specific names make references to routines a lot easier and they are used extensively by DB2âs error reporting facilities.
This value is DB2âs internal ID for the routine. It will be used as input argument for the subsequently described procedures.
TRACE.SQLPROC_TRACE_DATA (IN ROUTINEID INT, IN DATA VARCHAR(2000))
The purpose of this procedure is to trace arbitrary data. This can be an error-condition, a simple âI was here" message or the content of some host variables. To save codepath when tracing is OFF it is recommended to test whether ROUTINEID is NULL before calling the procedure.
The routine id received from
An arbitrary string, which will be printed as-is in the formatted trace
TRACE.SQLPROC_TRACE_EXIT (IN ROUTINEID INT)
This procedure is the counterpart of
TRACE.SQLPROC_TRACE_ENTRY(). It should be called at the very end of the procedural logic of the routine to inform the tracer that the routine is finished. The omission of
TRACE.SQLPROC_TRACE_ENTRY()was specified will cause wrong results from the trace reporting procedures. To save codepath when tracing is OFF it is recommended to test whether ROUTINEID is NULL before calling the procedure.
The routine id received from
A usage example
Having explained the external API for tracing, now we will walk through a simple example in form of the â3a+1" algorithm.
a 1 : User input
a n+1 ::= if a n is even then a n /2 else 3a n +1
We are interested in the number of divisions, multiplications, and total number of steps until a reaches 1 .
DROP PROCEDURE max_three_a_plus_one DROP PROCEDURE compute_three_a_plus_one DROP PROCEDURE three_a_plus_one DROP PROCEDURE a_div_2 1 CREATE PROCEDURE a_div_2(INOUT a SMALLINT) 2 SET a = a / 2 1 CREATE PROCEDURE three_a_plus_one(INOUT a INTEGER) 2 SET a = 3 * a + 1 1 CREATE PROCEDURE compute_three_a_plus_one 2 (IN a INTEGER, 3 OUT div SMALLINT, 4 OUT mult SMALLINT, 5 OUT steps SMALLINT) 6 BEGIN 7 VALUES(0, 0, 0) INTO div, mult, steps; 8 WHILE a <> 1 DO 9 IF (a / 2) * 2 = a THEN 10 CALL a_div_2(a); 11 SET div = div + 1; 12 ELSE 13 CALL three_a_plus_one(a); 14 SET mult = mult + 1; 15 END IF; 16 SET steps = steps + 1; 17 END WHILE; 18 END 1 CREATE PROCEDURE max_three_a_plus_one 2 (IN start INTEGER, 3 IN stop INTEGER, 4 OUT maxdiv SMALLINT, 5 OUT maxmult SMALLINT, 6 OUT maxsteps SMALLINT) 7 BEGIN 8 DECLARE rtn_id INTEGER; 9 DECLARE a INTEGER; 10 DECLARE div SMALLINT; 11 DECLARE mult SMALLINT; 12 DECLARE steps SMALLINT; 13 SET rtn_id = TRACE.SQLPROC_TRACE_PID(); 14 VALUES (0, 0, 0, start) 15 INTO maxdiv, maxmult, maxsteps, a; 16 WHILE a <= stop DO 17 CALL compute_three_a_plus_one 18 (a, div, mult, steps); 19 IF rtn_id IS NOT NULL THEN 20 CALL TRACE.SQLPROC_TRACE_DATA 21 (rtn_id, 10, 'A: ' || CHAR(a) || 'Steps: ' || CHAR(steps)); 22 END IF; 23 SELECT MAX(d), MAX(m), MAX(s), a + 1 24 INTO maxdiv, maxmult, maxsteps, a 25 FROM TABLE(VALUES (maxdiv, maxmult, maxsteps), 26 (div, mult, steps)) 27 AS T(d, m, s); 28 END WHILE; 29 END
You can define these procedures with:
db2 âtd@ -vf trace_sample.db2
From a tracing point of view procedure
max_three_a_plus_one() is noteworthy.
While none of the other procedures is instrumented in any way for tracing this one contains explicit tracing code.
At the very beginning of the stored procedure (line 13) the
SQLPROC_TRACE_PID() UDF is invoked.
It returns the ROUTINEID of the
max_three_a_plus_one() procedure if and only if tracing is on.
If tracing is off the function sets the
rtn_id variable to NULL.
In line 19 the procedure can now very cheaply test whether tracing is on and write additional trace information by calling
SQLPROC_TRACE_DATA in line 20. In this case the procedure traces how many steps were necessary for
the given "A" to converge to the number one. The procedure could have an arbitrary number of explicit tracepoints without
occuring any significant cost while tracing is off.
In practice this technique is very effective to dump input values at the beginning and output values at the end of a procedure.
Major decision points within a procedure can also be tracked easily.
But now we must test that the procedure works:
Database Connection Information Database server = DB2/NT 8.2.0 SQL authorization ID = SRIELAU Local database alias = DBMTECH C:\docs\ibm\Tracing>db2 call max_three_a_plus_one(1, 400, ?, ?, ?) Value of output parameters -------------------------- Parameter Name : MAXDIV Parameter Value : 91 Parameter Name : MAXMULT Parameter Value : 52 Parameter Name : MAXSTEPS Parameter Value : 143 Return Status = 0 C:\docs\ibm\Tracing>
So far, so good. Now we will ârandomly" pick another range of values:
C:\docs\ibm\Tracing>db2 call max_three_a_plus_one(430, 450, ?, ?, ?) SQL0413N Overflow occurred during numeric data type conversion. SQLSTATE=22003 C:\docs\ibm\Tracing>
As you can see, that wasnât all that great. DB2 UDB ran into a math overflow error. But it was neither able to tell us in which procedure the error occurred, nor which variables may have been involved. Note that proper exception handling in SQL PL dictates that each procedure has an error handler that could easily enough have told us the failing procedure. Certainly for this small set of procedures it is easy to guess where the problem lies, but the reason for this example is to showcase tracing. So letâs do that now:
C:\docs\ibm\Tracing>db2 set path = current path, trace DB20000I The SQL command completed successfully. C:\docs\ibm\Tracing>db2 call sqlproc_trace_on(NULL) Return Status = 0 C:\docs\ibm\Tracing>db2 call max_three_a_plus_one(430, 450, ?, ?, ?) SQL0413N Overflow occurred during numeric data type conversion. SQLSTATE=22003 C:\docs\ibm\Tracing>db2 call sqlproc_trace_format() > trace.fmt C:\docs\ibm\Tracing>
For convenience, we start by adding the âTRACE" schema to our PATH. This way we donât have to spell the schema name out for each routine invocation. We then turn tracing on using the default user temporary table space provided by the friendly DBA. After calling the failing routine we then retrieve a formatted trace output. Since the result set contains a lengthy VARCHAR column, it is advisable to redirect the output to a file. In this case we call it
2445 |<'SRIELAU.COMPUTE_THREE_A_PLUS_ONE (4) 2446 | DAT Tracepoint 10 A: 446 Steps: 71 2447 |->SRIELAU.COMPUTE_THREE_A_PLUS_ONE (4) 2448 | |->SRIELAU.THREE_A_PLUS_ONE (1) ... 2545 | |<'SRIELAU.THREE_A_PLUS_ONE (1) 2546 | |->SRIELAU.A_DIV_2 (1) 2547 | |<'SRIELAU.A_DIV_2 (1) 2548 | |->SRIELAU.THREE_A_PLUS_ONE (1) 2549 | |<'SRIELAU.THREE_A_PLUS_ONE (1) 2550 | |->SRIELAU.A_DIV_2 (1) 2551 | |<'SRIELAU.A_DIV_2 (1) 2552 | |->SRIELAU.THREE_A_PLUS_ONE (1) 2553 | |<'SRIELAU.THREE_A_PLUS_ONE (1) 2554 | | ERR Line 10 SQL0413N Overflow occurred during numeric data type conversion. SQLSTATE=22003 2555 |<'SRIELAU.COMPUTE_THREE_A_PLUS_ONE (4) SQL0413N Overflow occurred during numeric data type conversion. SQLSTATE=22003 2556 | ERR Line 14 SQL0413N Overflow occurred during numeric data type conversion. SQLSTATE=22003 2557 <'SRIELAU.MAX_THREE_A_PLUS_ONE (5) SQL0413N Overflow occurred during numeric data type conversion. SQLSTATE=22003 2557 record(s) selected. Return Status = 0
As you can easily see, the source of the error seems to be Line 10 in
The (4) indicates that the procedure takes 4 arguments in case there are other procedures of that name in schema âSRIELAU".
10 CALL a_div_2(a);
Since the trace never reached âA_DIV_2" itself the failure must have been during binding in of âA" and a quick lookup reveals that A_DIV_2 takes a SMALLINT while âA" is defined as an INTEGER. So letâs fix that:
C:\docs\ibm\Tracing>db2 drop procedure a_div_2 DB20000I The SQL command completed successfully. C:\docs\ibm\Tracing>db2 create procedure a_div_2(inout a integer) set a = a / 2 DB20000I The SQL command completed successfully. C:\docs\ibm\Tracing>
We now clean out the trace and run again:
C:\docs\ibm\Tracing>db2 call sqlproc_trace_clear() Return Status = 0 C:\docs\ibm\Tracing>db2 call max_three_a_plus_one(430, 450, ?, ?, ?) Value of output parameters -------------------------- Parameter Name : MAXDIV Parameter Value : 74 Parameter Name : MAXMULT Parameter Value : 41 Parameter Name : MAXSTEPS Parameter Value : 115 Return Status = 0 C:\docs\ibm\Tracing>db2 call sqlproc_trace_report() > trace.rpt C:\docs\ibm\Tracing>
Now it worked and we got a report:
Result set 1 -------------- NUMCALLS ELAPSED NAME -------- ------------ -------------------------------------- 1 0.3284 SRIELAU.MAX_THREE_A_PLUS_ONE (5) 21 0.3257 SRIELAU.COMPUTE_THREE_A_PLUS_ONE (4) 983 0.0549 SRIELAU.A_DIV_2 (1) 501 0.0292 SRIELAU.THREE_A_PLUS_ONE (1) 4 record(s) selected. Return Status = 0
The report can tell us at a glance a few important things. First, we now know which procedures get in fact executed. We know how often they execute and, at least roughly, how much time is spent within them. For more detailed analysis of what goes on within SQL procedures, I recommend taking a look at the SQL PL Profiler, which can be downloaded from DeveloperWorks/DB2 as well.
This section described the low-level API, which the trace-utility uses. DB2 UDB V8.2 has gotten three small, but crucial extensions that are exploited here:
- A session-level toggle, which is used to turn tracing on or off.
The toggle is prototyped in db2psmd.h and available through the db2psmd library.
#define PSMD_TRACE_MODE_OFF 0 #define PSMD_TRACE_MODE_BASIC 1 int DB2API pda_SetTraceMode( int TraceMode); int DB2API pda_GetTraceMode();
A general extension to global temporary tables, which allows temporary tables that are not logged to be completely taken out of transaction control. This extension is required to allow tracing across ROLLBACK statements without losing what has been traced so far.
DECLARE GLOBAL TEMPORARY TABLE SESSION.TEMP (c1 INTEGER) NOT LOGGED ON ROLLBACK PRESERVE ROWS
Awareness of the Procedural Virtual Machine (PVM) to the trace mode.
If the trace mode is not set to OFF (which is the default), then each entry, exit and non-zero SQL code will be logged in a global temp table with the following name and format:
DECLARE GLOBAL TEMPORARY TABLE SESSION.SQLPROC_TRACE (EVENTTIME TIMESTAMP NOT NULL , ROUTINEID INTEGER NOT NULL , LINE INTEGER NOT NULL , EVENTTYPE INTEGER NOT NULL , SQLCODE INTEGER NOT NULL , SQLSTATE CHAR(5) NOT NULL , DATA VARCHAR(2000) NOT NULL) ON COMMIT PRESERVE ROWS NOT LOGGED ON ROLLBACK PRESERVE ROWS
EVENTTYPEis mapped as such:
EVENTTYPE Description 1 Procedure entry 2 Procedure exit 3 Message (SQLCODE <> 0) 4 User provided data entry
These interfaces are supported by IBM in DB2 UDB V8.2 for LUW. However, the API may evolve or be entirely replaced in future releases, so upward compatibility may not be present. If you choose to exploit this API and you want to be notified of changes, please contact the author of this article.
Conclusion and outlook
A simple, yet powerful API is available in DB2 UDB V8.2 for LUW to allow tracing of SQL Procedures. This article provides an example exploitation of this API using an procedure interface. Looking forward there are various areas which could be improved, some of which I want to list here without committing to a timeline:
- While the API provides for a way to do explicit tracing of variables and parameters, it would be more elegant to have tehse capabilities built in. One of the challenges that must be overcome on this path however is security. Certainly not everyone who can execute a stored procedure should be allowed to trace possibly confidential data across the procedure's internal workings. However, in a development environment, you would not want to make every person a DBA.
- The usage of a temporary table limits tracing to procedures of the class MODIFIES SQL DATA. This happens to be the default, so in most cases there is no problem. Nonetheless, there will be procedures that cannot be traced for that reason. Maybe another interface is more appropriate.
- The presented high-level API supports only simple reporting. A much more sophisticated analysis can be made. For example, a stack-trace back could be derived easily from the trace. Aggregating such a trace back yields a quantified call-chain. Which procedure is called by whom and how often? I invite you as a curious reader to extend upon what has been presented here as a seed.
- Having an SQL interface to the trace output provides powerful mining capabilities. In addition to the traceback discussed above one can easily write routines which filter the trace for specific procedures or even trace points.
|Code sample||sqlpltrc_Lintel32.zip ( HTTP | FTP )||18 KB|
|Code sample||sqlpltrc_Wintel32.zip ( HTTP | FTP )||5 KB|
|Code sample||sqlpltrc_Source.zip ( HTTP | FTP )||6 KB|