Using the IBM System Logger with Virtel

With the latest release of Virtel, currently Release 4.55, Virtel has the ability to write all of its log records to IBM’s System Logger.

To use this feature code LOG=LOGGER in the TCT and compile using a supporting maclib. This should be the distributed Virtel MACLIB HLQ.VIRTEL.MACLIB. A compatible VIR0000 in the VIRTEL load library must be used to avoid TCT mismatch message. The version in HLQ.VIRTEL.LOADLIB is compatible with the VIRTEM MACLIB in HLQ.VIRTEL.MACLIB(VIRTERM) member.

When you start Virtel it will attempt to connect to the predefined Virtel logstream. If the logstream doesn’t exists one will be created automatically. The following messages will appear in the log:-

VIR0024I ATTACHING SUBTASKS
IXC582I STRUCTURE VIRTEL\_LOG\_1 ALLOCATED BY SIZE/RATIOS. 596
PHYSICAL STRUCTURE VERSION: CFF8ABE4 1865AA81
STRUCTURE TYPE: LIST
CFNAME: ZACF1
ALLOCATION SIZE: 9 M
POLICY SIZE: 9 M
POLICY INITSIZE: 9 M
POLICY MINSIZE: 0 K
IXLCONN STRSIZE: 0 K
ENTRY COUNT: 1274
ELEMENT COUNT: 1179
ENTRY:ELEMENT RATIO: 1 : 1
ALLOCATION SIZE IS WITHIN CFRM POLICY DEFINITIONS
IXL014I IXLCONN REQUEST FOR STRUCTURE VIRTEL\_LOG\_1 597
WAS SUCCESSFUL. JOBNAME: IXGLOGR ASID: 0016
CONNECTOR NAME: IXGLOGR\_ZAMVS1 CFNAME: ZACF1
IXL015I STRUCTURE ALLOCATION INFORMATION FOR 598
STRUCTURE VIRTEL\_LOG\_1, CONNECTOR NAME IXGLOGR\_ZAMVS1,
CONNECTIVITY=DEFAULT
CFNAME ALLOCATION STATUS/FAILURE REASON
-------- ----------------------------------------
ZACF1 STRUCTURE ALLOCATED AC001800
ZACF2 PREFERRED CF ALREADY SELECTED AC001800
PREFERRED CF HIGHER IN PREFLIST
LOGGER CONNECTED

After this point all messages will be written to the logger, even responses to commands. Each Virtel that has LOG=LOGGER will connect to the structure. The last message you will see is:

VIR0000I SMTP Date: Wed, 09 Dec 2015 22:34:57 +0100

Fortunately there is a print program that can be used to format and print off the log records. This is VIR00002B. When the logstream reaches a particular threshold is spools off a dataset. The following messages will appear in the log:-

IEF196I IGD100I 0AA8 ALLOCATED TO DDNAME SYS00008 DATACLAS ( )
IXG283I OFFLOAD DATASET IXGLOGR.LOGGER.VIRTEL.A0000005 897
ALLOCATED NEW FOR LOGSTREAM LOGGER.VIRTEL
CISIZE=4K, SIZE=147456
IXG251I IDCAMS SYSTEM SERVICES
TIME: 22:49:21 12/09/15 PAGE 1
IXG251I ALTER IXGLOGR.LOGGER.VIRTEL.A0000005.DATA -
IXG251I SHR(3,3)
IXG251I IDC0531I ENTRY IXGLOGR.LOGGER.VIRTEL.A0000005.DATA ALTERED
IXG251I IDC0001I FUNCTION COMPLETED, HIGHEST CONDITION CODE WAS 0
IXG251I IDC0002I IDCAMS PROCESSING COMPLETE. MAXIMUM CONDITION CODE WAS 0
IXG282I OFFLOAD DATASET IXGLOGR.LOGGER.VIRTEL.A0000005 904
WAS ALTERED FOR LOGSTREAM LOGGER.VIRTEL
UPDATED ATTRIBUTE VSAM SHAREOPTIONS

To list the logstream, structure and its associated offload datasets, use the following JCL:-

//SPTHOLTL JOB CLASS=A,MSGCLASS=X,MSGLEVEL=(1,1),NOTIFY=&SYSUID
//STEP1 EXEC PGM=IXCMIAPU,REGION=4M
//SYSPRINT DD SYSOUT=*
DATA TYPE(LOGR) REPORT(NO)
LIST STRUCTURE NAME(VIRTEL\_LOG\_1) DETAIL(YES)
LIST LOGSTREAM NAME(LOGGER.VIRTEL) DETAIL(YES)

The output will look something like this:-

Ext. <SEQ#> Lowest Blockid / Highest GMT / Highest Local / Status Highest Blockid Highest RBA System Name
----- -------- ---------------- ----------------- ------------------------

A0000001 0000000000023F64 12/03/14 19:32:35 12/03/14 20:32:35 0000000000047E76 00023F98 ZAMVS1
A0000002 0000000000047EFC 12/03/14 21:49:42 12/03/14 22:49:42 000000000006BE2C 00023FA1 ZAMVS1
A0000003 000000000006BE9D 12/03/14 22:15:12 12/03/14 23:15:12 000000000008FDEB 00023FB4 ZAMVS1
A0000004 000000000008FE51 12/09/15 20:55:39 12/09/15 21:55:39 00000000000B3D5B 00023F90 ZAMVS2
A0000005 00000000000B3DE1 12/09/15 21:49:20 12/09/15 22:49:20 CURRENT 00000000000CCBC7 00018E5F ZAMVS2
NUMBER OF DATA SETS IN LOG STREAM: 5

To delete the structure, run the following job:-

//SPTHOLTC JOB CLASS=A,MSGCLASS=X,MSGLEVEL=(1,1),NOTIFY=&SYSUID
//STEP1 EXEC PGM=IXCMIAPU,REGION=4M
//SYSPRINT DD SYSOUT=*
DATA TYPE(LOGR) REPORT(NO)
DELETE LOGSTREAM NAME(LOGGER.VIRTEL)
LIST LOGSTREAM NAME(LOGGER.VIRTEL) DETAIL(YES)

Reverting back to the console

To revert back to console logging, the normal logging behaviour for Virtel, issue the following command:-

F VIRTEL,LOG=CONSOLE

After this all Virtel messages will be written to the console.

Example:-

F SPVIR1A,LOG=CONSOLE
VIR0238I VIRTEL LOG RECORDING TO CONSOLE
F SPVIR1A,LINES
VIR0200I LINES
VIR0201I VIRTEL 4.55 APPLID=VIRTEL1A LINES
VIR0202I INT.NAME EXT.NAME TYPE ACB OR IP
VIR0202I -------- -------- ----- ---------
VIR0202I C-HTTP HTTP-CLI TCP1 192.168.170.15:41002
VIR0202I W-HTTP HTTP-W2H TCP1 :41015
VIR0202I ---END OF LIST---

The VIR0002B Logger print program.

This program currently resides in SPTHOLT.VIRTEL.DEV.LOADLIB

Example JCL:-

//*
//* DESCRIPTION
//*
//LOGGER PROC P=
//S01 EXEC PGM=VIR0002B,PARM='&P'
//STEPLIB DD DSN=SP000.SPTHOLT.DEV.LOADLIB,DISP=SHR
//SYSUDUMP DD SYSOUT=*
//SYSOUT DD SYSOUT=*
//VIRLOG DD SYSOUT=*,DCB=BLKSIZE=13200
// PEND
//S01 EXEC LOGGER,P='COPY'
//*02 EXEC LOGGER,P='COPY(>000)'
//*03 EXEC LOGGER,P='COPY(2014336,2014336)'
//*04 EXEC LOGGER,P='DELETE(2014336)'
//*05 EXEC LOGGER,P='DELETE(>000)'

The parameters are as follows:-

COPY([start_date][,end_date]), DELETE(date)
         (>nnn)                  (>nnn)

COPY

Records are to be copied to the SYSLOG-format file. If COPY is not specified, no records are copied.

start_date,end_date

The starting and ending dates of the time span, both in the format YYYYDDD. start_date must not be later than end_date. end_date must not be later than today, the day the program runs. The default for start_date is the date of the oldest record in the log stream, and for end_date is yesterday, the day before the program runs. If both start_date and end_date are allowed to default, the parentheses after COPY may be omitted. If you specify a start date of today, you must also specify the end date of today, otherwise the program will assume an end date of yesterday and abend.

nnn

Indicates that records dated more than nnn days before today are to be copied. The time span will

start with the date of the oldest record in the log stream and end nnn+1 days before today (that is,

records dated more than nnn days before today will be copied. nnn is a number between zero and 999.

For example, if the program is run on May 25, specifying “COPY(>3)” will copy records dated up to and including May 21. Note that >0 corresponds to yesterday. To copy today’s records, you must use the “[start_date][,end_date]” form and specify today as the end date.

DELETE

Records are to be deleted. If DELETE is not specified, no records are deleted.

date

The date of the newest record to be deleted from the log stream. All records dated on or before that date will be deleted. The date must not be later than today. If the date specified is today, all records in the log stream will be deleted.

>nnn

Indicates that records dated more than nnn days before today are to be deleted. nnn is a number between zero and 999. For example, if the program is run on July 15, specifying “DELETE(>5)” will delete records dated up to and including July 9. Note that >0 corresponds to yesterday. To delete today’s records, you must use the “date” form and specify today as the date. If DELETE is specified, either the date or “>nnn” must be given.

You may specify either COPY or DELETE or both. If you specify both they must be separated by a comma and may appear in either order. However, regardless of the order in which the parameters are specified, the copy operation will always occur before the delete.

Notes:-

When copying records, this program detects the end of a day’s records when it either reads the first record for the next day or attempts to read past the newest record in the log stream. This means that, if end_date is today and the log stream is being written at the time this program runs, the records that are copied may not be predictable. In particular, if both COPY with an ending date of today and DELETE with a date of today are specified, there may be more records deleted than copied.

When the “>nnn” form of the COPY or DELETE parameter is specified, program converts it to a date by subtracting nnn days from the date the program is run. The calculation is done once, at the beginning of the program. If the program is run shortly before midnight, so that the calculation occurs before midnight and the actual copying or deletion of records occurs after midnight, the records copied or deleted will not reflect the number of days specified. To prevent this, you should avoid running the program close to midnight with the “>nnn” form.

If the program is run regularly after midnight with the parameter “COPY(>0),DELETE(>1)”, it will copy records from the previous day and earlier, and will delete from the records from two days ago, leaving something over 24 hours’ worth of records in the log each time.