I am sure I am not the only person who has received a message, email, or telephone call informing me that there was an error message that happened earlier. When I reply asking for more details it is not uncommon to be told: "I don't know what the error was, I just replied with a C". This, of course, tells me nothing useful to be able to make a diagnosis what and where the error happened. Often it drives me to the History log which I have to search through looking for an error message. Narrowing the possible time frame makes the searching easier, but if the best the message sender can tell me is "earlier this afternoon" or "during the day end run" I am left with a large amount of log data to search through.
IBM has come to my rescue with a DB2 of i (SQL) table function that allows me to search the History log and select the data I want to see. I am not sure if this is part of the IBM i 7.3 TR1 and 7.2 TR5 updates. You can search to see if it is present on your IBM i using the PTF information View, PTF_INFO, to look for relevant PTF:
- IBM i 7.3 SF99703 Level 3
- IBM i 7.2 SF99702 Level 14
The HISTORY_LOG_INFO table function when used in its simplest form gives all the same information that looking at the History log does.
SELECT * FROM TABLE(QSYS2.HISTORY_LOG_INFO()) A
Which in my opinion is overwhelming as the History log output.
I can narrow the date and time range, as I can with the History log by using the Table function's two parameters. The parameters are timestamps.
01 SELECT * FROM TABLE(QSYS2.HISTORY_LOG_INFO(CURRENT TIMESTAMP - 1 DAY)) A 02 SELECT * FROM TABLE(QSYS2.HISTORY_LOG_INFO('2016-11-30-06.00.00.000000', '2016-11-30-12.00.00.000000')) A
Line 1: As only one parameter is used it is assumed that this is the from timestamp. In this case I want to start one day before the current time.
Line 2: I have given two parameters, they must be separated by a comma ( , ).
While this reduces the amount of data I have retrieved I am still left with a lot of log entries I don't care about, for example, successful completion of jobs, etc.
As this is a Table function I can use a SQL Select command to refine the search criteria I use to find the data I want. Before I give examples let me list what I consider to be the useful columns I will be using.
|ORDINAL_POSITION||Unique number of the entry. The older the entry the lower the number.|
|MESSAGE_TYPE||Type of the message. I am not going to list them all here, if you want to know all the possible values see the link provided at the bottom of this post.|
|SEVERITY||Severity of the message.|
|MESSAGE_TIMESTAMP||The timestamp when the message was sent to the History log.|
|FROM_USER||User of the job.|
|FROM_JOB||Full job name.|
|MESSAGE_TEXT||First level message text. This is in a VARGRAPHIC column in CCSID 1200 so I will need to CAST it to make it readable on my IBM i.|
|MESSAGE_SECOND_LEVEL_TEXT||Second level message text. This is in a VARGRAPHIC column in CCSID 1200 so I will need to CAST it to make it readable on my IBM i.|
There are other columns, but as I am not going to use them I will refer you to the link at the bottom of this post.
With these columns I can create a Select statement to list all errors in my desired date range.
01 SELECT MESSAGE_ID, 02 MESSAGE_TYPE AS MESSAGE_TYPE 03 SEVERITY 04 MESSAGE_TIMESTAMP AS TIMESTAMP, 05 FROM_USER, 06 FROM_JOB, 07 CAST(MESSAGE_TEXT AS CHAR(200) CCSSID 37) AS MESSAGE_TEXT, 08 CAST(MESSAGE_SECOND_LEVEL_TEXT AS CHAR(1000) CCSSID 37) AS MESSAGE_TEXT_2 09 FROM TABLE(QSYS2.HISTORY_LOG_INFO('2016-12-03-16.00.00.000000', '2016-12-03-16.15.00.000000')) A 10 WHERE SEVERITY >= 30 11 ORDER BY ORDINAL_POSITION
I am using the AS, on lines 2, 4, 7, and 8 to give the column labels some more meaningful label. For example, "MESSAGE_TYPE" is easier to understand than "MESSA00001".
Lines 7 and 8: I use the CAST to convert these columns into something I can read.
Line 9: I am giving the date and time range I desire as parameters in the Table function.
Line 10: I only want to know about any log entry with a severity of 30 or greater.
Line 11: I want to sort by oldest first.
This gives me (I have broken it out into separate lines just to display it here).
MESSAGE_ID MESSAGE_TYPE SEVERITY TIMESTAMP FROM_USER FROM_JOB RNQ1216 INQUIRY 99 2016-12-03-16.09.54.579968 SIMON 026063/SIMON/TESTRPG RNQ1216 INQUIRY 99 2016-12-03-16.10.02.045824 SIMON 026063/SIMON/TESTRPG - REPLY 99 2016-12-03-16.10.02.099072 SIMON 026052/SIMON/QPADEV0013 MESSAGE_TEXT Error message CPF4131 appeared during OPEN for file TESTDSPF (C S D F). Error message CPF4131 appeared during OPEN for file TESTDSPF (C S D F). C MESSAGE_TEXT_2 &N Cause . . . . . : RPG procedure TESTRPG in program MYLIB/TESTRPG received the message CPF4131 &N Cause . . . . . : RPG procedure TESTRPG in program MYLIB/TESTRPG received the message CPF4131 - while performing an implicit OPEN operation on file TESTDSPF. The actual file is TESTDSPF. while performing an implicit OPEN operation on file TESTDSPF. The actual file is TESTDSPF.
The equivalent using the DSPLOG command is.
DSPLOG PERIOD((161000 120316) (161500 120316)) OUTPUT(*PRINT)
I would then have to search the generated spool file to discover:
MSGID SEV MSG TYPE RNQ1216 99 INQUIRY Error message CPF4131 appeared during OPEN for file TESTDSPF (C S D F). TESTRPG SIMON 026063 QMHSCLVL 0000 16-12-03 16:10:02.913396 SIMON 99 VALID RPY C QPADEV0013 SIMON 026052 QMHSCLVL 0000 16-12-03 16:10:02.913409 SIMON
In my opinion using the HISTORY_LOG_INFO gives me what I want a lot quicker and easier than searching through the output from the DSPLOG command. I for one will be using these Table function the next time I get one of those "There was an error and I don't know when" communications.
You can learn more about the HISTORY_LOG_INFO Table function from the IBM website here.
This article was written for IBM i 7.3 TR1 and should work with 7.2 TR5 too.