The Liberty Web Server on z/OS can produce information on the performance of “transactions”. It may not be as you expect, and it may not be worth collecting it. I started looking into this to see why certain transactions were slow on z/OSMF.
This blog post covers
- How does the web server work?
- How can I see what is going on?
- Access logs
- SMF 120
- WLM
- Do I want to use this in production?
How does it work?
A typical Web Server transaction might use a database to debit your account, and to credit my account. I think of this as a fat transaction because the application does a lot of work,
z/OSMF runs on top of Liberty, and allows you to run SDSF and ISPF within a web brower, and has tools to help automate work. You can also use REST services, so you can send a self contained HTTP request to z/OSMF, for example request information about data sets, or jobs running on the system. Both of these send a request to z/OSMF, which might send a request to a TSO userid, get the response back and pass the response back to the requester. I think of this as a thin transaction because the application running on the web server is mainly acting as a router or broker. What the end user sees as a “transaction” may be many micro services – each of which is a REST requests.
How can I see what is going on?
You can see what “transactions” or requests have been issued from
- the access log – a flat file of requests
- SMF 120 records
- WLM reports.
Access logs
In the <httpEndpoint … accessLoggingRef=”accessLogging”…>, the accessLogging is a reference to an <httpAccessLogging… statement. This creates a flat files containing a record of all inbound HTTP client requests. If you have multiple httpEndpoint statements, you can have multiple accessLogging files. You can control the number and size of the files.
This has information with fields like
- 10.1.0.2 – the IP address the request came in from
- COLIN – the userid
- {16/May/2021:14:47:40 +0000} – the date, time and time zone of the event
- PUT /zosmf/tsoApp/tso/ping/COLIN-69-aabuaaac – the request
- HTTP/1.1 – the type of HTTP request
- 200 – the HTTP return code
- 78 – the number of bytes sent back.
You can have multiple httpEndpoint definitions, for example specifing different IP address and port combinations. These definitions can point to a shared or indivdual httpAccessLogging statement, and so can share (or not) the flat files. This allows you to specify that for one port you will use the accessLogging, and another port does not have access logging.
The SMF 120 records.
The request logging writes a record to SMF for each request.
<server>
<featureManager>
<feature>zosRequestLogging-1.0</feature>
</featureManager>
</server
I have not been able to find a formatter for these records from IBM, so I have written my own, it is available on github.
It produces output like
Server version :2
System :S0W1
Syplex :ADCDPL
Server job id :STC02771
Server job name :IZUSVR1
config dir :/var/zosmf/configuration/servers/zosmfServer/
codelevel :19.0.0.3
Start time :2021/05/16 14:42:33.955288
Stop time :2021/05/16 14:42:34.040698
Duration in secs : 0.085410
WLMTRan :ZCI4
Enclave CPU time : 0.042570
Enclave ZIIP time : 0.042570
WLM Resp time ratio :10.000000
userid long :COLIN
URI :/zosmf/IzuUICommon/externalfiles/sdsf/index.html
CPU Used Total : 0.040111
CPU Used on CP : 0.000000
CPU Delta Z**P : 0.040111
WLM Classify type :URI
WLM Classify by :/zosmf/IzuUICommon/externalfiles/sdsf/index.html
WLM Classify type :Target Host
WLM Classify by :10.1.1.2
WLM Classify type :Target Port
WLM Classify by :10443
Response bytes :7003
Origin port :57706
Origin :10.1.0.2
This has information about
- The Liberty instance, where it is running and configuration information
- Information about the transaction, start time, stop time, duration and CPU time used
- WLM information about the request. It was classified as
- URI:…index.html
- Target Host:10.1.1.2
- Target port:10443
- 7003 bytes were sent to the requester
- the request came from 10.1.0.2 port 57706
The SMF formatter program also summarises the records and this shows there are records for
- /zosmf/IzuUICommon/externalfiles/sdsf/js/ui/theme/images/zosXcfsCommand_enabled_30x30.png
- /zosmf/IzuUICommon/externalfiles/sdsf/js/ui/theme/sdsf.css
- /zosmf/IzuUICommon/externalfiles/sdsf/sdsf.js
- /zosmf/IzuUICommon/externalfiles/sdsf/IzugDojoCommon.js
- /zosmf/IzuUICommon/persistence/user/com.ibm.zos.sdsf/JOBS/JOBS
This shows there is a record for each part of the web page, icons, java scripts and style sheets.
Starting up SDSF within z/OSMF created 150 SMF records! Refreshing the data just created 1 SMF record. The overhead of creating all the SMF records for one “business transaction” may be too high for production use.
As far as I can tell this configuration is server wide. You cannot enable it for a specific IP address and port combination.
WLM reports
Much of the data produced in the records above can be passed to WLM. This can be used to give threads appropriate priorities, and can produce reports.
You enable WLM support using
- <featureManager>
- <feature>zosWlm-1.0 </feature>
- </featureManager>
- <zosWorkloadManager collectionName=”MOPZCET”/>
- <wlmClassification>
- <httpClassification transactionClass=”ZCI6″ resource=”/zosmf/desktop/”/>
- <httpClassification transactionClass=”ZCI1″ resource=”/**/sdsf/**/*”/>
- <httpClassification transactionClass=”ZCI3″ resource=”/zosmf/webispf//”/>
- <httpClassification transactionClass=”ZCI4″ resource=”/**/*”/>
- <httpClassification transactionClass=”ZCI2″ resource=”IZUGHTTP” />
- <httpClassification transactionClass=”ZCI5″ port=”10443″/>
- </wlmClassification>
Where the httpClassification maps a z/OSMF resource to an 8 character transaction class. THe records are process from the top until there is a match. For example port=10443 would not be used because of the generic resource=/**/* definition.
These need to be mapped into the WLM configuration…
WLM configuration
You can configure WLM through the WLM configuration panels.
option 6. Classification rules.
option 3 to modify CB(Component broker)
-------Qualifier-------- -------Class--------
Action Type Name Start Service Report
DEFAULTS: STCMDM TCI2
____ 1 CN MOPZCET ___ ________ THRU
____ 2 TC ZCI1 ___ SCI1 RCI1
____ 2 TC ZCI2 ___ SCI2 RCI2
____ 2 TC ZCI3 ___ SCI3 RCI3
____ 2 TC ZCI4 ___ SCI4 RCI4
____ 2 TC ZCI5 ___ SCI5 RCI5
____ 2 TC ZCI6 ___ SCI6 RCI6
____ 2 TC THRU ___ THRU THRU
For the Type=CN, Name=MOPZCET, this value ties up with the <zosWorkloadManager collectionName=”MOPZCET” above. Type=CN is for CollectionName.
For the subtype 2 TC Name ZCI4, This is for TransactionClass which ties up with a httpClassification transactionClass statement.
The service class SCI* controls the priority of the work, the Report class RCI* allow you to produce a report by this name.
If you make a change to the WLM configuration you can save it from the front page of the WLM configuration panels, Utilities-> 1. Install definition, and activate it using Utilities-> 3. Activate service policy.
If you change the statements in Liberty or z/OSMF I believe you have to restart the server.
How to capture the data
The data is written out to SMF records on a timer, or on the SMF end-of-interval broadcast. If you change the interval, SMF sends an end-of-interval broadcast and writes the records to SMF. For example on my dedicate test system I use the operator command setsmf intval(10) to change the interval to 10 minutes. After the next test, I use setsmf intval(15) etc..
The data is kept in SMF buffers, and you may have to wait for a time, before the data is written out to external storage. It SMF data is being produced on a regular basis, it will be flushed out.
How to report the data
I copy the SMF data to a temporary data
//IBMURMF JOB 1,MSGCLASS=H RESTART=POST
//* DUMP THE SMF DATASETS
// SET SMFPDS=SYS1.S0W1.MAN1
// SET SMFSDS=SYS1.S0W1.MAN2
//*
//SMFDUMP EXEC PGM=IFASMFDP
//DUMPINA DD DSN=&SMFPDS,DISP=SHR,AMP=('BUFSP=65536')
//DUMPINB DD DSN=&SMFSDS,DISP=SHR,AMP=('BUFSP=65536')
//* MPOUT DD DISP=(NEW,PASS),DSN=&RMF,SPACE=(CYL,(1,1))
//DUMPOUT DD DISP=SHR,DSN=IBMUSER.RMF SPACE=(CYL,(1,1))
//SYSPRINT DD SYSOUT=*
//SYSIN DD *
INDD(DUMPINA,OPTIONS(DUMP))
INDD(DUMPINB,OPTIONS(DUMP))
OUTDD(DUMPOUT,TYPE(70:79))
DATE(2020316,2021284)
START(1539)
END(2359)
/*
and display the report classes
//POST EXEC PGM=ERBRMFPP //* PINPUT DD DISP=SHR,DSN=*.SMFDUMP.DUMPOUT //MFPINPUT DD DISP=SHR,DSN=IBMUSER.RMF //SYSIN DD * SYSRPTS(WLMGL(RCPER)) /*
The output in //PPXSRPTS was
REPORT CLASS=RCI4
-TRANSACTIONS-- TRANS-TIME HHH.MM.SS.FFFFFF
AVG 0.01 ACTUAL 69449
MPL 0.01 EXECUTION 68780
ENDED 160 QUEUED 668
END/S 0.13 R/S AFFIN 0
#SWAPS 0 INELIGIBLE 0
EXCTD 0 CONVERSION 0
STD DEV 270428
----SERVICE---- SERVICE TIME ---APPL %---
IOC 0 CPU 2.977 CP 0.05
CPU 2551 SRB 0.000 IIPCP 0.05
MSO 0 RCT 0.000 IIP 0.19
SRB 0 IIT 0.000 AAPCP 0.00
TOT 2551 HST 0.000 AAP N/A
/SEC 2 IIP 2.338
ABSRPTN 232 AAP N/A
TRX SERV 232
There were 160 “transactions” within the time period or 0.13 per second, The average response time was 69449 microseconds, with a standard deviation of 270428. This is a very wide standard deviation, so there was a mixture of long, and short response times.
The total CPU for this report class was 2.977 seconds of CPU, or 0.019 seconds per “transaction”.
Do I want to use this in production?
I think that the amount of data produced is managable for a low usage system. For a production environment where there is a lot of activity then the amount of data produced, and the cost of producing the data may be excessive. This could be an example of the cost of collecting the data is much larger than the cost of running the workload.
As z/OSMF acts as a broker, passing requests between end points you may wish just to use your existing reporting structures.
I used z/OSMF to display SDSF data, and set up and ISPF session within the web browse. This created two TSO tasks for my userid. If you include my traditional TSO session and the two from z/OSMF this is three TSO sessions in total running on the LPAR.
ColinPaice 