Wednesday, April 19, 2023

Personalised SQL error logging, SELF

Update (January 24, 2023)
I can now use the special values '*ERROR', '*WARN', or '*ALL' rather than having to list all the SQL codes. Read about it here.


Introduced as part of IBM i 7.5 Technology Refresh 1 and IBM i 7.4 TR7, is a mechanism to capture details of SQL errors into a separate log table. I can decide which errors I want to capture in the log, by use of the SQL code. The SQL codes to capture are set at the SQL session level, rather than at the IBM i job level.

This is called the SQL Error Logging Facility, or SELF for short. It consists of several parts, the parts I am going to explain in detail are:

  • SQL_ERROR_LOG:  A View that is used to display the logged errors
  • SELFCODES:  A Global Variable that needs to contain the SQL codes I wish to log
  • VALIDATE_SELF:  A scalar function that validates SQL codes

The other parts I found I will mention when I need to.

The first time I check the global variable SELFCODES:

01  VALUES SYSIBMADM.SELFCODES

It contains its default value, which is:

00001
-----------------
<NULL>

Db2 for i Global Variables are "more" than the variables we are used to using in programs. If I change the value of a Global Variable it will only contain those new values for the current SQL session. All other SQL sessions, and jobs, will see the default value.

I am going to add some SQL codes to SELFCODES using the following SQL statement:

01  SET SYSIBMADM.SELFCODES = '-501, -502, -206'

Notice that the SQL codes are separated by a comma. A negative code denotes an error, while a positive value is a warning. What do these three codes mean?:

  • -206:  One of the columns named in the statement does not exist in the table or view
  • -501:  Fetch or close performed on a cursor that is not open
  • -502:  Cursor is already open

As this Global Variable is defined as VARCHAR(256) it can contain many SQL codes.

Let me confirm that SELFCODES does contain the values I want:

01  VALUES SYSIBMADM.SELFCODES

00001
-----------------
-501, -502, -206

If I am done monitoring for these codes and my SQL session, or job, has not ended, I can reset the SELFCODES back to null:

01  SET SYSIBMADM.SELFCODES = NULL

What happens if I enter an invalid SQL code? This is where the VALIDATE_SELF scalar comes into play. The scalar function ins found in the SYSIBMADM library.

Let me use it to test the SQL codes I want to put in the Global Variable:

01  VALUES SYSIBMADM.VALIDATE_SELF('-501, -502,-206')

This returns the following as all of the SQL codes are valid codes:

00001
----------------
-206, -501, -502

Not all SQL codes can be used with SELFCODES. What happens if I use SQL code '+100’?

01  VALUES SYSIBMADM.VALIDATE_SELF('+100,0,-999')

I get a SQL0443 informing me that '+100’ is not allowed for the variable SELFCODES.

I could also do something like below, I see no reason why I would ever want to do this in real-life:

01  VALUES SYSIBMADM.VALIDATE_SELF(',,,-501')

The commas ( , ) with nothing between them are null values, therefore, my result is:

0001
----------------
-501

-501’ was the only not null value.

How could I use VALIDATE_SELF in a more real-world situation. I could easily insert this into a RPG program and, as this is a test, display either the valid SQL codes or a message to say that they were invalid.

01  **free
02  dcl-s String char(10) ;

03  exec sql SET :String = SYSIBMADM.VALIDATE_SELF(',,,-501') ;
04  if (SQLCOD < 0) ;
05    dsply ('Error in 1') ;
06  else ;
07    dsply ('1: ' + String) ;
08  endif ;

09  exec sql SET :String = SYSIBMADM.VALIDATE_SELF('100') ;
10  if (SQLCOD < 0) ;
11    dsply ('Error in 2') ;
12  else ;
13    dsply ('2: ' + String) ;
14  endif ;

15  *inlr = *on ;

Line 1: In 2023 if is not totally free RPG then it is old code.

Line 2: I am defining a variable to contain the results from the VALIDATE_SELF.

Line 3: As VALIDATE_SELF is a scalar function I can use the SQL SET statement to get the results from it. This is one of the statements I used before, so I know this is valid.

Line 4: If the SQL code, SQLCOD, is less than zero then the statement on line 3 errored.

Line 5: I am using the Display operation code, DSPLY, to display a message that there was an error.

Line 7: If there was not an error I will display the list of valid SQL codes.

Line 9: I know that this statement will error, as it did in one of the statements above.

Line 10: The SQL code will be less than zero.

Line 11: And this message will be displayed.

After compiling this program, when I call it, and then look in the job log I see:

DSPLY  1: -501

User-defined function error on member QSQPTABL.
?
User-defined function error on member QSQPTABL.
?
Trigger program or external routine detected an error.
DSPLY  Error in 2

When errors occur that have the SQL codes I have in my SELFCODES they are written to a SQL Table, SQL_ERRORT. The table should not be accessed directly. I would use the View SQL_ERROR_LOG instead.

If I am the first person to "play" with SELF the View would be empty. Let me go and create some errors. My first RPG program looks like:

01  **free
02  dcl-s KeyIn char(10) ;

03  exec sql SET OPTION CLOSQLCSR = *ENDMOD ;

04  exec sql SET SYSIBMADM.SELFCODES = '-501, -502, -206' ;

05  exec sql DECLARE C0 CURSOR FOR
06             SELECT KEY FROM TESTFILE FOR READ ONLY ;

07  exec sql OPEN C0 ;
08  exec sql CLOSE C0 ;

09  exec sql FETCH NEXT FROM C0 INTO :KeyIn ;

10  *inlr = *on ;

Line 3: I added the SQL SET OPTION to ensure that the cursor would be closed when the program ended.

Line 4: I am updating SELFCODES with the SQL codes I care about in these examples.

Lines 5 and 6: I have defined a SQL cursor.

Line 7: I open the cursor.

Line 8: I close the cursor.

Line 9: I attempt to fetch from the close cursor, which will error.

After the program has completed I can then interrogate SQL_ERROR_LOG to see if it captured the error.

01  SELECT JOB_NAME,LOGGED_TIME,
02         LOGGED_SQLCODE,LOGGED_SQLSTATE,
03         STATEMENT_TEXT,STATEMENT_OPERATION_DETAIL,
04         PROGRAM_LIBRARY,PROGRAM_NAME,MODULE_NAME,PROGRAM_TYPE
05    FROM QSYS2.SQL_ERROR_LOG
06   ORDER BY LOGGED_TIME DESC

Lines 1 - 4: I did not want all the columns from the View, just these. IMHO the column names adequately their contents.

Line 5: SQL_ERROR_LOG View is found in the library QSYS2.

Line 6: Sorting by LOGGED_TIME ensures that the most recent result comes first in the results.

The results look like:

                                                  LOGGED_  LOGGED_
JOB_NAME              LOGGED_TIME                 SQLCODE  SQLSTATE
--------------------  --------------------------  -------  --------
547209/SIMON/SIMON_1  2023-03-21 08:37:01.642000     -501  24501

                             STATEMENT_
                             OPERATION   PROGRAM_  PROGRAM  MODULE   PROGRAM
STATEMENT_TEXT               _DETAIL     LIBRARY   _NAME    _NAME    _TYPE
---------------------------  ----------  --------  -------  -------  -------
FETCH NEXT FROM C0 INTO : H  FETCH       MYLIB     TESTRPG  TESTRPG  *PGM

The results are as I expected, a '-501’ code added to the file. I really like the STATEMENT_TEXT as it gives me the statement that failed.

In the next example the first six lines of the program’s source code is unchanged. The changed lines are:

07  exec sql OPEN C0 ;
08  exec sql OPEN C0 ; // Yes, 2nd open

09  exec sql FETCH NEXT FROM C0 INTO :KeyIn ;

10  exec sql CLOSE C0 ;

11  *inlr = *on ;

Line 8: Will cause an error as I have attempted to open the cursor for a second time.

The results for this program from SQL_ERROR_LOG are:

JOB_NAME              LOGGED_TIME                 SQLCODE  SQLSTATE
--------------------  --------------------------  -------  --------
547209/SIMON/SIMON_1  2023-03-21 11:47:38.047000     -502  24502

                             STATEMENT_
                             OPERATION   PROGRAM_  PROGRAM  MODULE   PROGRAM
STATEMENT_TEXT               _DETAIL     LIBRARY   _NAME    _NAME    _TYPE
---------------------------  ----------  --------  -------  -------  -------
OPEN C0                      OPEN        MYLIB     TESTRPG  TESTRPG  *PGM

My last example is a completely new program that does the equivalent of a RPG CHAIN operation.

01  **free
02  dcl-s KeyIn char(10) ;

03  exec sql SET OPTION CLOSQLCSR = *ENDMOD ;

04  exec sql SELECT KEY INTO :KeyIn FROM TESTTABLE ;

05  *inlr = *on ;

Line 4: This SQL statement fails are there is not a column called KEY in the SQL Table TESTTABLE.

The results for this program in SQL_ERROR_LOG is:

JOB_NAME              LOGGED_TIME                 SQLCODE  SQLSTATE
--------------------  --------------------------  -------  --------
547209/SIMON/SIMON_1  2023-03-21 11:56:51.118000     -206  42703

                                    STATEMENT_
                                    OPERATION
STATEMENT_TEXT                      _DETAIL
----------------------------------  -----------
SELECT KEY INTO : H FROM TESTTABLE  SELECT INTO


PROGRAM_  PROGRAM  MODULE   PROGRAM
LIBRARY   _NAME    _NAME    _TYPE
--------  -------  -------  -------
MYLIB     TESTRPG  TESTRPG  *PGM

With these examples I have only shown one line from the results. The SQL_ERROR_LOG really contains three rows, I just wanted to show one in each scenario to make the results easier to see and understand.

Over time the number of results in SQL_ERROR_LOG is going to increase, or perhaps you do not care for results that are, for example, over three months old. How to clear or remove older results? This is where I am probably going to be admonished by IBM’s Db2 for i team’s members for suggesting this. As I mentioned before SQL_ERROR_LOG is built over the Table SQL_ERRORT. This is not exactly accurate, as the View is built over a Table Function called RETRIEVE_SELF_ENTRIES. There is no mention of this in IBM’s documentation. What I have deduced is that the Table Function is built over SQL Table SQL_ERRORT. Therefore, if I delete data from this table it will not be displayed in the SQL_ERROR_LOG View. For example:

01  DELETE FROM QSYS2.SQL_ERRORT

This deletes all of the data, and there is no results returned by SQL_ERROR_LOG.

Before deleting any data from SQL_ERRORT check with your colleagues to make sure that they are aware you will be deleting their data too.

You can learn more about this from the IBM website:

 

This article was written for IBM i 7.5 TR1 and 7.4 TR7.

5 comments:

  1. I’m working on implementing this now and your article will really help! Thank you!!

    ReplyDelete
  2. Informational 👍🏻

    ReplyDelete
  3. Question: When I do this, the Statement Text shows as "*POINTER" Any idea what I am doing wrong?

    ReplyDelete
    Replies
    1. Time to leave the old behind and move to a modern tooling.
      Stop using STRSQL, and start using Run SQL Scripts.

      Delete
  4. Cheers Simon, always informative and could/ should be useful.

    ReplyDelete

To prevent "comment spam" all comments are moderated.
Learn about this website's comments policy here.

Some people have reported that they cannot post a comment using certain computers and browsers. If this is you feel free to use the Contact Form to send me the comment and I will post it for you, please include the title of the post so I know which one to post the comment to.