I’m sorry I haven’t a clue…

As well as being a very popular British comedy, it is how I sometimes feel about what is happening inside the Liberty Web servers, and products like z/OSMF, z/OS Connect and MQWEB. It feels like a spacecraft in cartoons – there are usually only two controls – start and stop.

One reason for this is that the developers often do not have to use the product in production, and have not sat there, head in hand saying “what is going on ?”.

In this post I’ll cover

What data values to expose

As a concept, if you give someone a lever to pull – you need to give them a way of showing the effect of pulling the level.

If you give someone a tuning parameter, they need to know the impact of using the tuning parameter. For example

  • you implement a pool of blocks of storage.
  • you can configure the number of maximum number of blocks
  • if a thread needs some storage, and there is a free block in the pool, then assign the block to the thread. When the thread has finished with it, the thread goes back into the pool.
  • if all the blocks in the pool are in-use, allocate a block. When the thread has finished with the block – free it.
  • if you specify a very large number of blocks it could cause a storage shortage

The big questions with this example is “how big do you make the pool”?

To be able to specify the correct pool size you need to know information like

  • What was the maximum number of blocks used – in total
  • How many times were additional blocks allocated (and freed)
  • What was the total number of blocks requested.

You might decide that the pool is big enough if less than1% of requests had to allocate a block.

If you find that the maximum value used was 1% of the size of the pool, you can make the pool much smaller.

If you find that 99% of the requests were allocated/freed, this indicates the pool is much to small and you need to increase the size.

For other areas you could display

  • The number of authentication requests that were userid+ password, or were from a certificate.
  • The number of authentication requests which failed.
  • The list of userid names in the userid cache.
  • How many times each application was invoked.
  • The number of times a thread had to wait for a resource.
  • The elapsed time waiting for a resource, and what the resource was.

What attributes to expose

You look at the data to ask

  • Do I have a problem now?
  • Will I have a problem in the future? You need to collect information over time and look at trends.
  • When we had a problem yesterday, did this component contribute to it? You need to have historical data.

It is not obvious what data attributes you should display.

  • The “value now” is is easy to understand.
  • The “average value” is harder. Is this from the start of the application (6 months ago), or a weighted average (99 * previous average + current value)/100. With this weighted average, a change since the previous value indicates the trend.
  • The maximum value is hard – from when? There may have been a peak at startup, and small peaks since then will not show up. Having a “reset command” can be useful, or have it reset on a timer – such as display and reset every 10 minutes.
  • If you “reset” the values and display the value before any activity, what do you display? “0”s for all of the values, or the values when the reset command was issued.

Resetting values can make it easier to understand the data. Comparing two 8 digit numbers is much harder than comparing two 2 digit numbers.

How to expose data

Java has a Java Management eXtension (JMX) for reporting management information. It looks very well designed, is easy to use, and very compact! There is an extensive document from Oracle here.

I found Basic Introduction to JMX by Baeldung , was an excellent article with code samples on GitHub. I got these working in Eclipse within an hour!

The principal behind JMX is …

For each field you want to expose you have a get… method.

You define an interface with name class| |”MBean” which defines all of the methods for displaying the data.

public interface myClassMBean {
public String getOwner();
public int getMaxSize();
}

You define the class and the methods to expose the data.

public class myClass implements myClassMBean{

// and the methods to expose the data

public String getOwner() {
return fileOwner;
}

public int getMaxSize() {
return fileSize;
}

}

And you tell JMX to implement it

myClass myClassInstance = new myClass(); // create the instance of myClass

MBeanServer server = ManagementFactory.getPlatformMBeanServer();
ObjectName objectName =….
server.registerMBean(myClassInstance, objectName);

Where myClassInstance is a class instance. The JMX code extracts the name of the class from the object, and can the identify all the methods defined in the class||”MBean” interface. Tools like jconsole can then query these methods, and invoke them.

ObjectName is an object like

ObjectName objectName = new ObjectName(“ColinJava:type=files,name=onefile”);

Where “ColinJava” is a high level element, “type” is a category, and “name” is the description of the instance .

That’s it.

When you use jconsole ( or other tools) to display it you get

You could have

MBeanServer server = ManagementFactory.getPlatformMBeanServer();

ObjectName bigPoolName = new ObjectName(“ColinJava:type=threadpool,name=BigPool”);
server.registerMBean(bigpoolInstance, bigPoolName);

ObjectName medPoolName = new ObjectName(“ColinJava:type=threadpool,name=MedPool”);
server.registerMBean(medpoolInstance, medPoolname);

ObjectName smPoolName = new ObjectName(“ColinJava:type=threadpool,name=SmallPool”);
server.registerMBean(smallpoolInstance,smPoolName);

This would display the stats data for three pools

  • ColinJava
    • threadpool
      • Bigpool..
      • MedPool….
      • SmallPool…

And so build up a tree like

  • ColinJava
    • threadpool
      • Bigpool..
      • MedPool….
      • SmallPool…
    • Userids
      • Userid+password
      • Certificate
    • Applications
      • Application 1
      • Application 2
    • Errors
      • Applications
      • Authentication

You can also have set…() methods to set values, but you need to be more careful; checking authorities, and possibly synchronising updates with other concurrent activity.

You can also have methods like resetStats() which show up within jconsole as Operations.

How do I build up the list of what is needed?

It is easy to expose data values which have little value. I remember MQ had a field in the statistics “Number of times the hash table changed”. I never found a use for this. Other times I thought “If only we had a count of ……”

You can collect information from problems reported to you. “It was hard to diagnose because… if we had the count of … the end user could have fixed it without calling us”.

Your performance team is another good source of candidates fields. Part of the performance team’s job is to identify statistics to make it easier to tune the system, and reduce the resources used. It is not just about identifying hot spots.

Before you implement the collection of data, you could present to your team on how the data will be used, and produce some typical graphs. You should get some good feedback, even if it is “I dont understand it”.

What can I use to display the data

There are several ways of displaying the data.

  • jconsole – which comes as part of Java can display the data in a window
  • python – you can issue a query can capture the data. I have this set up to capture the data every 10 seconds
  • other tools using the standard interfaces.

Have a good REST and save a fortune in CPU with Python

Following on from Have a good REST and save a fortune in CPU. The post gives some guidance on reducing the costs of using Liberty based servers from a Python program.

Certificate set up

I used certificate authentication from Linux to z/OS. I used

  • A certificate defined on Linux using Openssl.
  • I sent the Linux CA certificate to z/OS and imported it to the TRUST keyring.
  • I created a certificate on z/OS and installed it into the KEY keyring.
  • I exported the z/OS CA, sent it to Linux, and created a file called tempca.pem.

Python set up

Define the names of the user certificate private key, and certificate

cf=”colinpaicesECp256r1.pem”
kf=”colinpaicesECp256r1.key.pem”
cpcert=(cf,kf)

Define the name of the certificate for validating the server’s certificate

v=’tempca.pem’

Set up a cookie jar to hold the cookies sent down from the server

jar = requests.cookies.RequestsCookieJar()

Define the URL and request

geturl =”https://10.1.1.2:9443/ibmmq/rest/v1/admin/qmgr/

Define the headers

import base64
useridPassword = base64.b64encode(b’colin:passworm’)
my_header = {
‘Content-Type’: ‘application/json’,
‘Authorization’: useridPassword,
‘ibm-mq-rest-csrf-token’ : ‘ ‘
}

An example flow of two requests, using two connections

For example using python

s = requests
response1 = s.get(geturl,headers=my_header,verify=v,cookies=jar,cert=cpcert)
response2 = s.get(geturl,headers=my_header,verify=v,cookies=jar,cert=cpcert)

creates two session, each has a TLS handshake, issue a request, get a response and end.

An example of two requests using one session

For example using python

s = requests.Session()
response1 = s.get(geturl,headers=my_header,verify=v,cookies=jar,cert=cpcert1)
response2 = s.get(geturl,headers=my_header,verify=v,cookies=jar,cert=cpcert2)

The initial request has one expensive TLS handshake, the second request reuses the session.

Reusing this session means there was only one expensive Client Hello,Server Hello exchange for the whole conversation.

Even though the second request specified a different set of certificates, the certificates from when the session was established, using cpcert1 were used. (No surprise here as the certificates are only used when the session is established).

For the authentication, in both cases the first requests received a cookie with the LtpaToken2 cookie in it.

When this was passed up on successive requests, the userid information from the first request was used.

What is the difference?

I ran a workload of a single thread doing 200 requests. The ratios are important, not the absolute values.

Shared sessionOne session per requests
TCP flows to server1 11
CPU cost1 5
Elapsed time16

Have a good REST and save a fortune in CPU

The REST protocol is a common programming model with the internet. It is basically a one shot model, which scales and has high availability, but can have a very high CPU cost. There are things you can do to reduce the CPU cost. Also, the MQWeb server, has implemented some changes to reduce the cost. See here for the MQ documentation.

The post gives some guidance on reducing the costs, for Liberty based servers.

The traditional model and the REST model

The traditional application model may have a client and a flow to the server

  • Connect to the server and authenticate
  • Debit my account by £500 within syncpoint
  • Credit your account by £500 within syncpoint
  • Commit the transaction
  • Do the next transaction etc
  • At the end of the day, disconnect from the server.

The REST model would be

  • Connect to the server and authenticate and do (Debit my account by £500, credit your account by £500), disconnect

This model has the advantage that it scales. When you initiate a transaction it can go to any one of the available back-end servers. This spreads the load and improves availability.

With the traditional model, the clients connects any available server at the start of day stays connected all day. If a new server becomes available during the day, it may get no workload.

The downside of the REST model is the cost. Establishing a connection and authenticating can be very expensive. I could not find much useful documentation on how to reduce these costs.

There are two parts of getting a REST connection.

  • Establishing the connection
  • Authentication

Establishing the connection

You can have each REST request use a new session for every REST request each of which which involves a full TLS handshake. Two requests could go to different servers, or go to the same server.

You can issue multiple REST request over the same session, to the same backend server.

On my little z/OS, using z/OSMF it takes

  • about 1 second to create a new connection and issue a request and terminate
  • about 0.1 seconds to use the shared session, per REST request.

Establishing the TLS session is expensive, as there is a lot of computation to generate the keys.

For MQWEB, the results are very similar.

Authentication

Once the session has been established each REST request requires authentication.

If you are using userid and password, the values are checked with z/OS.

If you are using client certificate authentication the Subject DN is looked up in the security manager, and if there is a DN to userid mapping, the userid is returned.

Once you have a valid userid, the userid’s access can be obtained from the security manager.

All of these values can be cached in the Liberty web server. So the first time a certificate or userid is used, it will take a longer than successive times.

Information about authentication is then encrypted and passed back in the REST response as the LtpaToken2 cookie.

If a REST request passes the cookie back to the server, then the information in the cookie is used by the server, and fewer checks need to be done.

This cookie can expire, and when it does expire the userid and password, or the certificate DN is checked as before, and the cookie will be updated.

If you do not send the LtpaToken2 cookie, this will cause the passed authentication information to be revalidated. If you want to change userid, do not send the the cookie.

Is any of this documented?

There is not a lot of documentation. There is information Configuring the authentication cache in Liberty.

There is a parameter javax.net.ssl.sessionCacheSize. If this is not set the default is 20480.

I cut the CPU cost of doing nothing.

I was running z/OSMF and saw that the CPU costs where high when it was sitting there doing nothing. I managed to reduce the CPU costs by more than half. This would apply to other Liberty based web servers, such as MQWEB, and z/OS Connect.

I could see from the MVS system trace there was a lot of activity creating a thread, and deleting a thread, a lot of costs associated with these activities, such as allocating and freeing storage.

I increased the number of threads so that this allocating a thread and delete a thread activity disappeared.

In the xml configuration file (based from server.xml) was the default

<executor name=”LargeThreadPool” id=”default” coreThreads=”100″
maxThreads=”0″ keepAlive=”60s” stealPolicy=”STRICT”
rejectedWorkPolicy=”CALLER_RUNS” />

I changed this to

<executor name=”LargeThreadPool” id=”default”
coreThreads=”300″ maxThreads=”600″ keepAlive=”60s”
stealPolicy=”STRICT” rejectedWorkPolicy=”CALLER_RUNS” />

and restarted the server.

The options are documented here. There is an option keepAlive which defaults to 60 seconds. If a thread has been idle for this time, the thread is a candidate to be freed to reduce the pool back to corethreads size.

I was alerted to this problem when I looked at an MVS system trace. This is described here.

There is a discussion how sun thread pools work in this post. It is not obvious. This may or may not be how this executor works.

What value should you use?

This is a hard question, as Liberty does not provide this information directly.

I used the Health Checker connects from Eclipse to the JVM and extracts information about the JVM and applications.

This shows that at rest there was a lot of activity. I increased it to 250 threads and restarted the server and got

So better … but still some activity. I increased it to 300 threads, and the graph was flat.

I set up USER.Z24A.PROCLIB(CEEOPT) with

RPTSTG(ON),
RPTOPTS(ON)

in my z/OSMF job I had

//CEEOPTS DD DISP=SHR,DSN=USER.Z24A.PROCLIB(CEEOPT)

This printed out a lot of useful information about the stack and heap usage. It the bottom it said

Largest number of threads concurrently active: 397

The number of threads includes threads from the pool I had specified, plus other threads that z/OSMF creates. The health check showed there were 372 threads, event though coreThreads was set to “300”.

I also used jconsole to display information about the highest thread usage. The URL was service:jmx:rest://10.1.1.2:10443/IBMJMXConnectorREST. It displays peak threads and live threads.

Security

I found the security of both jconsole, and health check, was weak (userid and password). I was unable to successfully set up a TLS certificate logon to the server.

The information from rptstg was only available at shutdown.

Why does increasing the number of threads reduce the CPU when idle?

The thread pool has logic to remove unused threads and shrink it to the coreThreads size. If the pool size is too small it has to create threads and delete threads according to the load. See here. The keepAlive mentioned at the top is how long a thread can be idle for, before it can be considered a candidate for deletion.

Summary

Monitor the CPU used when idle and see if increasing the threadpool to 300 helps.

The best way to save money, is not to spend it. The same is true for CPU.

I was trying to understand why a z/OSMF address space, using the Liberty web server (written in Java) was using a lot of CPU – when it was doing no work. I looked into the MVS system trace and saw some interesting behaviour. If you are trying to investigate a high CPU usage in a z/OS Job, I hope the following may help you with where you need to start looking.

If you are looking at a Java program, knowing there is a problem does not help you with what is causing the problem. There is Java, which uses C code, which uses USS services, which uses MVS services which is what you see in the system trace. The symptom is a long way from the source code. You might be able to correlate the time stamp in the system trace with the Java trace.

The ‘interesting’ behaviour…

  • Getmain/freemain storage requests. These are heavy weight requests for getting and freeing storage. Once warmed up, I would expect no storage requests.
  • “Storage Obtain”/”Storage Release” requests. These are medium weight requests for getting and freeing storage. Once warmed up, I would expect no storage requests.
  • Attach task and detach tasks, or pthread_create(). I would have expected tasks would have been attached at start up, and there would be no need for more tasks. I can see that under load more tasks may be required until the system stabilises.
  • Many timer pops a second. There were 50 time pops every second (one every 20 milliseconds). Is this efficient? No! It may be more efficient to have the duration between timer pops increase if there is no load, so a timer pop 10 times a second may be acceptable when the system is idle – and reset it to a short interval when the system is busy, or change the programming model to be wait-post rather than spinning the wheels.

I’ll discuss these in more detail below.

Storage requests, GETMAINs, FREEMAINs, STORAGE requests.

For a non trivial application such as a web server, MQ, DB2 etc, I would not expect to see any storage requests in the system trace once the system has warmed up. When I worked for MQ development, we went through the system trace, and every time we found a GETMAIN or STORAGE OBTAIN, we worked to eliminate it, until there were non left.

Use a stack

Instead of each subroutine using GETMAIN or “Storage request” to get a block of storage for its variables, I would expect a program stack to be used. For example the top level program for the thread allocates a 1MB block of storage and uses this as a stack. The top level program uses the first 2KB from this buffer. The first subroutine uses this buffer from 2KB for 3KB. If this subroutine calls another subroutine, the lower level subroutine uses this buffer from 5KB for 2KB. This is a very efficient way of managing storage and each subroutine needs only 10’s of instructions to get and release storage from the stack.

A problem can occur if the stack is not big enough, and there is logic like “If no space in the stack – then GETMAIN a block of storage”. If this happens the request quickly becomes expensive.

C (Language Environment) programs on z/OS can set the stack size, and when the system is shutdown, print out statistics on the stack usage.

Use the heap

A subroutine may need some “external storage”, which exist outside of the subroutine, for example store entries in a table for the life of the job. A heap (or heappool) is a very efficient way of managing the storage. If your program gets some storage, it does not return it, when the block has been finished with, the program “adds it to the heap” so it can be reused.

A simple heap example.

This might be an array of 3 pointers;

  • storage[0] is a chain of free 1KB blocks,
  • storage[1] is a chain of free blocks from 1K+1 bytes to 10KB,
  • storage[2] is a chain of free blocks from 10K+1 bytes to 50KB.

If your program needs a 512 byte block – it looks to see if there is a free block chained from storage[0], if not allocate a 1KB block (not 512 byte). When it has finished with the block, put it onto the storage[0] chain.
Over time the number of elements on each chain is sufficient to run the workload, and there should be no more storage requests. An increase in throughput may increase the demand for storage, and so during this “warm up” period, there may be more storage requests.

C run time statistics

For C programs on z/OS you can get the C runtime component to print out statistics on the stack and heap usage, and gives recommendations on the best size to specify.

In the //CEEOPTS data set you can specify the following

You may want to use HEAPPOOLS64(ALIGN…) and HEAPPOOLS(ALIGN…) when there are multiple threads so the blocks are hardware cache friendly, and you do not have two CPUs fighting for the same hardware cache data.

Ive blogged One Minute MVS – tuning stack and heap pools.

Smart programs

MVS can call exit programs, for example when an asynchronous event has happened, such as a timer has expired. These programs are expected to allocate storage for their variables ,do some work, give back the storage, and return. This can be very expensive – you have the cost of getting and freeing a block of storage just to set a few bits.

You may be able to write your exit program so it only uses registers, and does not need any virtual storage for variables. If this is not possible then consider passing a block of storage into the called program. For example the RACF Admin function

CALL IRRSEQ00 (Work_area,… )

Work_area: The name of a 1024-byte work area for SAF and RACF usage. The work area must be in the primary address space.

Example exit program

You could use the assembler macro STIMERM (Set TIMER). You specify the time interval, the address of the exit, and a user parameter. This user parameter is passed to the exit program when it gets control.

  • This could be a pointer to a WAIT ECB block,
  • or a pointer to a structure, one element in the structure is the WAIT ECB block, another element is the address of a block of storage the exit can use.

Attach task and detach task.

It is expensive to attach and detach tasks, so it is important to do it as little as possible. From a USS perspective the attach is from pthread_create.

A common design template to eliminate the attach/detach model is to have a pool of threads to do work.

  • A work request comes in, the dispatcher task gets a worker thread from the pool, and gives the work request to it. When the worker has finished it puts itself back in the pool.
  • If there was no worker thread available, check the configuration for the maximum number of threads, If this limit has not been reached, create a new worker thread.
  • If the was no worker thread available and the number of threads was at the limit, then wait until a worker thread is free.
  • Some thread pools have logic to shrink the pool if it gets too big. Without this logic a thread pool could be very large because it hit a peak usage weeks ago, and the pool has only been little used since.

Having a pool means that some of the expensive set up is done only once per thread, for example connect to DB2 or connect to MQ. You also avoid the expensive create (attach) of a thread, and delete (detach) of the thread. The application has logic like

  • Dispatching application attaches a new thread.
  • start thread
    • perform the expensive set up – for example connect to DB2 or connect to MQ
    • add task to the thread pool
    • do until told to shutdown
      • wait for work
      • do the work
    • end do
    • disconnect from DB2 or MQ
    • thread returns and is detached
Problems with the thread pool

One problem with using a thread pool is if the minimum pool size is too small. Smart thread pools have options like

  • lowest number of threads in thread pool
  • maximum number of thread thread pool
  • maximum idle time of a thread. If there are more threads than the lowest number of threads, and a thread has been idle for longer than this time then free the thread.

You can get the”thrashing” on a low usage system

  • The lowest number of threads is specified as 10 threads.
  • The main program needs 50 threads – it uses 10 from the pool, and allocates 40 new threads. These are added to the pool when the work has finished.
  • The clean-up process periodically checks the pool. If there are more threads than the lowest number, then purge ones which have been idle for more than the specified idle-time. 40 threads are purged
  • Repeat:
  • The main program needs 50 threads- it uses 10 from the pool, and allocates 40 new threads. These are added to the pool when the work has finished.
  • The clean-up process periodically checks the pool. If there are more threads than the lowest number, then purge ones which have been idle for more than the specified idle-time. 40 threads are purged

In this case there is a lot of attach/purge activity.

Making the pool size 50, or the maximum idle time very large will prevent this thrashing…

  • The lowest number of threads is specified as 50 threads.
  • The main program needs 50 threads – it uses 50 from the pool.
  • The clean-up process periodically checks the pool. The pool size is OK – do nothing.
  • Repeat:
  • The main program needs 50 threads- it uses 50 from the pool.
  • The clean-up process periodically checks the pool. The pool size is OK – do nothing

In this case the number of threads stays constant and you do not get the create/delete (attach/purge) of threads.

In one test this reduced the CPU time used when idling by more than 50 %.

Many timer pops a second

In my system trace I can see a task wakes up, it sets a timer for 20 milliseconds later, and suspends itself. This is very inefficient. This should be a wait-post model instead of an application in a loop, sleeping and checking something.

When investigating this you need to think about the speed of your box. Consider an application which just does

  • setting a timer to wake up in 10 milliseconds
  • it wakes up a thread which does nothing – but set a timer for 10 ms later (or 100 times a second)

On my slow box this could take me 1 ms of CPU to do this once, – or 100 ms of CPU for 100 times a second. One engine would be busy 10% of the time.

If I had a box which was 10 times faster and only took 0.1 ms of CPU to do the same work. For 100 iterations this would be 10 ms of CPU or 1% of an engine. To some people this is at the “noise level” and not worth looking at.

To you 1% CPU per second is “noise level”, to me the noise level of 10% CPU per second is a flashing red light, a loud klaxon and people in body armour running past.

Some of the mysteries of Java shared classes

When Java executes a program it read in the jar file, breaks it into the individual classes, converts the byte codes into instructions, and when executing it may replace instructions with more efficient instructions (Jitting). It can also convert the byte codes into instructions ahead of time, so called Ahead Of Time (AOT) compilation.

With shared classes, the converted byte codes, any Jitted code, and any AOT code can be saved in a data space.

  • When the java program runs a second time, it can reuse the data in the dataspace, avoid the overhead of the reading the jar file from the file system, and coverting the byte codes into instructions.
  • The data space can be hardened to a file, and restored to a data space, so can be used across system IPLs.

Using this, it reduced the start-up time of my program by over 20 seconds on my slow zPDT system. The default size of the cache is 16MB – one of my applications needed 100 MB, so most of the benefits of he shared classes could not be exploited if the defaults were used.

This blog post describes more information about this, and what tuning you can do.

Issuing commands to manage the shared classes cache

Commands to manage the shared classes cache are issued like

java -Xshareclasses:cacheDir=/tmp,name=client6,printStats

which can be done using JCL

// SET V=’listAllCaches’
// SET V=’printStats’
// SET C=’/tmp’
// SET N=’client6′
//S1 EXEC PGM=BPXBATCH,REGION=0M,
// PARM=’SH java -Xshareclasses:cacheDir=&C,name=&N,verbose,&V’
//STDERR DD SYSOUT=*
//STDOUT DD SYSOUT=*

Enabling share classes

You specify -Xsharedclasses information as a parameter to the program, for example in the command line or in a jvm properties file.

To use the shared classes capability you have to specify all of the parameters on one line, like

-Xshareclasses:verbose,name=client6,cacheDirPerm=0777,cacheDir=/tmp

Having it like

-Xshareclasses:name=client6,,cacheDirPerm=0777,cacheDir=/tmp
-Xshareclass:verbose

means the name, etc all take their defaults. Only shareclass:verbose would be used.

Changing share classes parameters

You can have more than one cache; you specify a name. You specify a directory were an image is stored when the cache is hardened to disk.

Some of the options like name= and cacheDir= are picked up when the JVM starts, Other parameters like cacheDirPerm are only used when the cache is (re-)created.

You can delete the cache in two ways.

Delete the cache from your your Java program

When you are playing around, you can add reset to the end of the -Xshareclasses string to caused the cache to be deleted and recreated.This gives output like

JVMSHRC010I Shared cache “client6” is destroyed
JVMSHRC158I Created shared class cache “client6”
JVMSHRC166I Attached to cache “client6”, size=20971328 bytes

This was especially useful when tuning the storage allocations.

Delete the cache independently

java -Xshareclasses:cacheDir=/tmp,name=client6,destroy

How to allocate the size of the cache

You specify the storage allocations using -Xsc.. (where sc stands for shareclasses)

If you have -Xsharedcache:verbose… specified then when the JVM shuts down you get

JVMSHRC168I Total shared class bytes read=11660. Total bytes stored=5815522
JVMSHRC818I Total unstored bytes due to the setting of shared cache soft max is 0.
Unstored AOT bytes due to the setting of -Xscmaxaot is 1139078.
Unstored JIT bytes due to the setting of -Xscmaxjitdata is 131832.

This shows the values of maxaot and maxjitdata are too small they were

-Xscmx20m
-Xscmaxaot2k
-Xscmaxjitdata2k

Whem the values were big enough I got

JVMSHRC168I Total shared class bytes read=12960204. Total bytes stored=8885038
JVMSHRC818I Total unstored bytes due to the setting of shared cache soft max is 0.
Unstored AOT bytes due to the setting of -Xscmaxaot is 0.
Unstored JIT bytes due to the setting of -Xscmaxjitdata is 0.

How big a cache do I need?

If you use -Xshareclasses:verbose… it will display messages

for example

JVMSHRC166I Attached to cache “client6”, size=2096960 bytes
JVMSHRC269I The system does not support memory page protection

JVMSHRC096I Shared cache “client6” is full. Use -Xscmx to set cache size.
JVMSHRC168I Total shared class bytes read=77208. Total bytes stored=2038042

Message JVMSHRC096I Shared cache “client6” is full. Use -Xscmx to set cache size, tells you the cache is full – but no information about how big it needs to be.

You can use

java -Xshareclasses:cacheDir=/tmp,name=client6,printStats

to display statistics like

-Xshareclasses persistent cache disabled]                                         
[-Xshareclasses verbose output enabled]                                            
JVMSHRC159I Opened shared class cache "client6"                                    
JVMSHRC166I Attached to cache "client6", size=2096960 bytes                        
JVMSHRC269I The system does not support memory page protection                     
JVMSHRC096I Shared cache "client6" is full. Use -Xscmx to set cache size.          
                                                                                   
Current statistics for cache "client6": 
cache size                           = 2096592                       
softmx bytes                         = 2096592                       
free bytes                           = 0                             
ROMClass bytes                       = 766804                        
AOT bytes                            = 6992                          
Reserved space for AOT bytes         = -1                            
Maximum space for AOT bytes          = 1048576                       
JIT data bytes                       = 212                           
Reserved space for JIT data bytes    = -1                            
Maximum space for JIT data bytes     = 1048576                       
Zip cache bytes                      = 1131864                       
Startup hint bytes                   = 0                             
Data bytes                           = 13904                         
Metadata bytes                       = 12976                         
Metadata % used                      = 0%                            
Class debug area size                = 163840                        
Class debug area used bytes          = 119194                        
Class debug area % used              = 72%

Cache is 100% full  
                                                                             

This show the cache is 100% full, and how much space is used for AOT and JIT. The default value of -Xscmx I had was almost 16MB. I made it 200MB and this was large enough.

I could not find a way of getting my program to issue printStats.

How do I harden the cache?

You can use use the

java -Xshareclasses:cacheDir=/tmp,name=zosmf,verbose,snapshotCache

command to create the cache on disk. Afterwards the listAllCaches command gave

Cache name level        cache-type     feature 
client6    Java8 64-bit non-persistent cr
client6    Java8 64-bit snapshot       cr

Showing the non persistent data space, and the snapshot file.

You can use the restoreFromSnapshot to restore from the file to the data cache; before you start your Java program. You would typically do this after an IPL.

How can I tell what is going on and if shared classes is being used?

The java options “-verbose:dynload,class

reports on the

  • dynamic loading of the files, and processing them,
  • what classes are being processed.

For example

<Loaded java/lang/reflect/AnnotatedElement from /Z24A/usr/lpp/java/J8.0_64/lib/rt.jar>
< Class size 3416; ROM size 2672; debug size 0>
< Read time 1196 usec; Load time 330 usec; Translate time 1541 usec>
class load: java/lang/reflect/AnnotatedElement from: /Z24A/usr/lpp/java/J8.0_64/lib/rt.jar
class load: java/lang/reflect/GenericDeclaration from: /Z24A/usr/lpp/java/J8.0_64/lib/rt.jar

dynload gave

<Loaded java/lang/reflect/AnnotatedElement from /Z24A/usr/lpp/java/J8.0_64/lib/rt.jar>
< Class size 3416; ROM size 2672; debug size 0>
< Read time 1196 usec; Load time 330 usec; Translate time 1541 usec>

this tells you a jar file was read from the file system, and how long it took to process it.

class gave

class load: java/lang/reflect/AnnotatedElement from: /Z24A/usr/lpp/java/J8.0_64/lib/rt.jar
class load: java/lang/reflect/GenericDeclaration from: /Z24A/usr/lpp/java/J8.0_64/lib/rt.jar

This shows two classe were extracted from the jar file.

In a perfect system you will get the class load entries, but not <Loaded….

Even when I had a very large cache size, I still got dynload entries. These tended to be loading class files rather than jar files.

For example there was a dynload entry for com/ibm/tcp/ipsec/CaApplicationProperties. This was file /usr/lpp/zosmf./installableApps/izuCA.ear/izuCA.war/WEB-INF/classes/com/ibm/tcp/ipsec/CaApplicationProperties.class

If you can make these into a .jar file you may get better performance. (But you may not get better performance, as it may take more time to load a large jar file).

I also noticed that there was dynload for com/ibm/xml/crypto/IBMXMLCryptoProvider which is in /Z24A/usr/lpp/java/J8.0_64/lib/ext/ibmxmlcrypto.jar, so shared classes has some deeper mysteries!

What happens if the .jar file changes?

As part of the class load, it checks the signature of the file on disk, matches the signature on the data space. If they are different the data space will be updated.

“Why were the options I passed to Java ignored” – or “how to tell what options were passed to my Java?”

I was struggling to understand a problem with shared classes in Java and I found the options being used by my program were not as I expected.

I thought it would be a very simple task to display at start up options used. It may be, but I could not find how to do it. If anyone knows the simple answer please tell me.

I found one way – take a dump! This seems a little extreme, but it was all I could find. With Liberty you can take a javacore dump (F IZUSVR1,JAVACORE) and display it, or you can take a dump at start up.

In the jvm.options I specified

-Xdump:java:events=vmstart

This gave me in //STDERR

JVMDUMP039I Processing dump event “vmstart”, detail “” at 2021/05/20 13:19:06 – please wait.
JVMDUMP032I JVM requested Java dump using ‘/S0W1/var/…/javacore.20210520.131906.65569.0001.txt’
JVMDUMP010I Java dump written to /S0W1/var…/javacore.20210520.131906.65569.0001.txt
JVMDUMP013I Processed dump event “vmstart”, detail “”.

In this file was list of all the options passed to the JVM

1CIUSERARGS UserArgs:
2CIUSERARG -Xoptionsfile=/usr/lpp/java/J8.0_64/lib/s390x/compressedrefs/options.default
2CIUSERARG -Xlockword:mode=default,noLockword=java/lang/String,noLockword=java/util/Ma
2CIUSERARG -Xjcl:jclse29
2CIUSERARG -Djava.home=/usr/lpp/java/J8.0_64
2CIUSERARG -Djava.ext.dirs=/usr/lpp/java/J8.0_64/lib/ext
2CIUSERARG -Xthr:tw=HEAVY
2CIUSERARG -Xshareclasses:name=liberty-%u,nonfatal,cacheDirPerm=1000,cacheDir=…
2CIUSERARG -XX:ShareClassesEnableBCI
2CIUSERARG -Xscmx60m
2CIUSERARG -Xscmaxaot4m
2CIUSERARG -Xdump:java:events=vmstart
2CIUSERARG -Xscminjitdata5m
2CIUSERARG -Xshareclasses:nonFatal
2CIUSERARG -Xshareclasses:groupAccess
2CIUSERARG -Xshareclasses:cacheDirPerm=0777
2CIUSERARG -Xshareclasses:cacheDir=/tmp,name=zosmf2
2CIUSERARG -Xshareclasses:verbose
2CIUSERARG -Xscmx100m

the storage limits

1CIUSERLIMITS User Limits (in bytes except for NOFILE and NPROC)
NULL ------------------------------------------------------------------------
NULL         type            soft limit  hard limit
2CIUSERLIMIT RLIMIT_AS       1831837696   unlimited
2CIUSERLIMIT RLIMIT_CORE        4194304     4194304
2CIUSERLIMIT RLIMIT_CPU       unlimited   unlimited
2CIUSERLIMIT RLIMIT_DATA      unlimited   unlimited
2CIUSERLIMIT RLIMIT_FSIZE     unlimited   unlimited
2CIUSERLIMIT RLIMIT_NOFILE        10000       10000
2CIUSERLIMIT RLIMIT_STACK     unlimited   unlimited
2CIUSERLIMIT RLIMIT_MEMLIMIT 4294967296  4294967296

and environment variables used.

1CIENVVARS Environment Variables
2CIENVVAR LOGNAME=IZUSVR
2CIENVVAR _CEE_ENVFILE_S=DD:STDENV
2CIENVVAR _EDC_ADD_ERRNO2=1
2CIENVVAR _EDC_PTHREAD_YIELD=-2
2CIENVVAR WLP_SKIP_MAXPERMSIZE=true
2CIENVVAR _BPX_SHAREAS=NO
2CIENVVAR JAVA_HOME=/usr/lpp/java/J8.0_64

All interesting stuff including the -X.. parameters. I could see that the parameters I had specified were not being picked up because they were specified higher up! Another face palm moment.

There was a lot more interesting stuff in the file, but this was not relevant to my little problems.

Once z/OSMF was active I took a dump using the f izusvr1,javacore command and looked at the information on the shared classes cache

1SCLTEXTCMST Cache Memory Status
1SCLTEXTCNTD Cache Name      Cache path
2SCLTEXTCMDT sharedcc_IZUSVR /tmp/javasharedresources/..._IZUSVR_G37
2SCLTEXTCPF Cache is 85% full
2SCLTEXTCSZ Cache size = 104857040
2SCLTEXTSMB Softmx bytes = 104857040
2SCLTEXTFRB Free bytes = 14936416

This is where I found the shared cache was not what I was expecting! I originally spotted that the cache was too small – and made it bigger.

Afterwards…

Remember to delete the javacore files.

I removed the -Xdump:java:events=vmstart statement, because I found it more convenient to use the f izusvr1,javacore command to take a dump when needed.

Looking at the performance of Liberty products and what you can do with the information

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.

Connect to Liberty, the clever way, to give different qualities of service.

While I was investigating two TCP/IP stacks I discovered you can set up Liberty Web Server to support different classes of service depending on TCP Host name, and port number.

You can configure <httpEndpoint…> with a host and port number, and point to other set up parameters and so configure

  • the host name
  • the httpsPort number
  • the maximum number of active connections for this definition
  • which keyring to use as the trust store
  • which keyring to use as the key store
  • which certificate the server should use in the key store
  • which TLS protocols for example TLS 1.2 or 1.3
  • what logging you want done: date,time, userid, url, response time
  • which file you want the access logging information to be written to
  • which sites can/cannot use this, the addressExcludeList and addressIncludeList.

How do you set up another http address and port ? It is really easy – just define another set of definitions!

Why would you want to do this?

You may want to restrict people’s access to the server. For example external people are told to access the server using a specified port, and you can specify which cipher specification should be used, and what trust store is used to validate a client authentication request.

You may want want to restrict the number of connections into a port, and have a port for administrators so they can always logon.

How do I do this?

You need to define another httpEndpoint. This in turn points to

I set up a file called colin.xml and included it in the server.xml file.

<server> 
 <httpEndpoint id="colinstHttpEndpoint" 
   host="10.1.1.2" 
   accessLoggingRef="colinaccessLogging" 
   sslOptionsRef="colinSSLRefOptions"
   httpsPort="29443"> 

   <tcpOption   
     addressIncludeList="10.1.*.*" 
     maxOpenConnections="3" /> 
 </httpEndpoint> 
 
 <sslOptions 
   id="colinSSLRefOptions" 
   sslRef="colinSSLOptions" 
 /> 

 <httpAccessLogging id="colinaccessLogging" enabled="true"/> 

 <ssl clientAuthentication="true" 
   clientAuthenticationSupported="true" 
   id="colinSSLOptions" 
   keyStoreRef="racfKeyStore" 
   trustStoreRef="racfTrustStore"                                                                             
   serverKeyAlias="ZZZZ" 
   sslProtocol="TLSv1.2" /> 
                                                                                
 <keyStore filebased="false" id="racfKeyStore" 
   location="safkeyring://START1/KEY" 
   password="password" readOnly="true" type="JCERACFKS"/> 
                                                                                                   
 <keyStore filebased="false" id="racfTrustStore" 
   location="safkeyring://START1/TRUST" 
   password="password" readOnly="true" type="JCERACFKS"/> 

</server> 

Certificate logon to MQWEB on z/OS, the hard way.

I described here different ways of logging on to the MQ Web Server on z/OS. This post describes how to use a digital certificate to logon. There is a lot of description, but the RACF statements needed are listed at the bottom.

I had set up my keystore and could logon to MQWEB on z/OS using certificates. I just wanted to not be prompted for a password.

Once it is set up it works well. I thought I would deliberately try to get as many things wrong, so I could document the symptoms and the cure. Despite this, I often had my head in the hands, asking “Why! – it worked yesterday”.

Can I use CHLAUTH ? No – because that is for the CHINIT, and you do not need to have the CHINIT running to run the web server.

Within one MQ Web Server, you can use both “certificate only” logon as well as using “certificate, userid and password” logon.

When using the SAF interface you specify parameters in the mqwebuser.xml file, such as keyrings, and what level of certificate checking you want.

Enable SAF messages.

If you use <safCredentials suppressAuthFailureMessage=”false” …> in the mqwebuser.xml then if a SAF request fails, there will be a message on the z/OS console. You would normally have this value set to “true” because when the browser (or REST client) reauthenticates (it could be every 10 seconds) you will get a message saying a userid does not have access to an APPL, or EJBROLE profile. If you change this (or make any change the mqwebuser.xnml file), issue the command

f CSQ9WEB,refresh,config

To pick up the changes.

Configure the server name

In the mqwebuser.xml file is <safCredentials profilePrefix=”MQWEB“…> there MQWEB identifies the server, and is used in the security profiles (see below).

SSL parameters

In the mqwebuser.xml file you specify

  • <ssl …
  • clientAuthenticationSupported=”true”|”false. The doc says The server requests that a client sends a certificate. The client’s certificate is optional
  • clientAuthentication=”true”|”false” if true, then client must send a certificate.
  • ssslProtocol=”TLSV1.2″
  • keyStoreRef=”…”
  • trustStoreRef=”…”
  • id=”…”
  • <sslDefault … sslRef=”…” this points to a particular <ssl id=…> definition. It allows you to have more than one <ssl definition, and pick one.

I think it would have been clearer if the parameters were clientAuthentication=”yes”|”no”|”optional”. See my interpretation of what these mean here.

Client authentication

The client certificate maps to a userid on z/OS, and this userid is used for access control.

The TLS handshake: You have a certificate on your client machine. There is a handshake with the server, where the certificate from the server is sent to the client, and the client verifies it. With TLS client authentication the client sends a certificate to the server. The server validates it.

If any of the following are false, it drops through to Connecting with a client certificate, and authenticate with userid and password below.

Find the z/OS userid for the certificate

The certificate is looked up in a RACDCERT MAP to get a userid for the certificate (see below for example statements). It could be a one to one mapping, or depending on say OU=TEST or C=GB, it can check on part of the DN. If this fails you get

ICH408I USER(START1 ) GROUP(SYS1 ) NAME(####################)
DIGITAL CERTIFICATE IS NOT DEFINED. CERTIFICATE SERIAL NUMBER(0194)
SUBJECT(CN=ADCDC.O=cpwebuser.C=GB) ISSUER(CN=SSCARSA1024.OU=CA.O=SSS.
C=GB).

Check the userid against the APPL class.

The userid is checked against the MQWEB profiles in the APPL class. (Where MQWEB is the name you configured in the web server configuration files). If this fails you get

ICH408I USER(ADCDE ) GROUP(TEST ) NAME(ADCDE ) MQWEB CL(APPL )
WARNING: INSUFFICIENT AUTHORITY ACCESS INTENT(READ ) ACCESS ALLOWED(NONE )

Pick the EJBROLE for the userid

There are several profiles in the EJBROLES class. If the userid has read access to the class, it userid gets the attribute. For example for the profile MQWEB.com.ibm.mq.console.MQWebAdmin, if the userid has at least READ access to the profile, it gets MQWEBADMIN privileges.
If these fail you get messages in the MQWEB message logs(s).

To suppress the RACF messages use option suppressAuthFailureMessage=”false” described above.

The userid needs access to at least one profile to be able to use the MQ Web server.

Use the right URL

The URL is like https://10.1.1.2:9443/ibmmq/console/

No password is needed to logon. If you get this far, displaying the userid information (click on the ⓘ icon) gives you Principal:ADCDE – Read-Only Administrator (Client Certificate Authentication) where ADCDE is the userid from the RACDDEF MAP mapping.

Connecting with a client certificate, and authenticate with userid and password.

The handshake as described above is done as above. If clientAuthentication=”true” is specified, and the handshake fails, then the client gets This site can’t be reached or similar message.

If the site can be reached, and a URL like https://10.1.1.2:9443/ibmmq/console/login.html is used, this displays a userid and password panel.

The password is verified, and if successful the specified userid is looked up in the APPL and EJBROLES profiles as described above.

If you get this far, and have logged on, displaying the userid information (click on the ⓘ icon) gives you Principal:colin – Read-Only Administrator (Client Certificate Authentication) where colin is the userid I entered.

The short solution to implement certificate authentication

If you already have TLS certificates for connecting to the MQ Web Server, you may be able to use a URL like https://10.1.1.2:9443/ibmmq/console/ to do the logon. If you use an invalid URL, it will substitute it with https://10.1.1.2:9443/ibmmq/console/login.html .

My set up.

I set up a certificate on Linux with a DN of C=GB,O=cpwebuser,CN=ADCDC and signed by C=GB,O=SSS,OU=CA,CN=SSCARSA1024. The Linux CA had been added to the trust store on z/OS.

Associate a certificate with a z/OS userid

I set up a RACF MAP of certificate to userid. It is sensible to run these using JCL, and to save the JCL for each definition.

 /*RACDCERT DELMAP( LABEL('ADCDZXX'  )) ID(ADCDE  ) 
 /*RACDCERT DELMAP( LABEL('CA'  )) ID(ADCDZ  )   
RACDCERT MAP ID(ADCDE  )  - 
    SDNFILTER('CN=ADCDC.O=cpwebuser.C=GB') - 
    WITHLABEL('ADCDZXX') 
                                                 
 RACDCERT MAP ID(ADCDZ  )  - 
    IDNFILTER('CN=SSCARSA1024.OU=CA.O=SSS.C=GB') 
    WITHLABEL('CA       ') 
                                                 
 RACDCERT LISTMAP ID(ADCDE) 
 RACDCERT LISTMAP ID(ADCDZ) 
 SETROPTS RACLIST(DIGTNMAP, DIGTCRIT) REFRESH 

This mapped the certificate CN=ADCDC.OU=cpwebuser.C=GB to userid ADCDE. Note the “.” between the parts, and the order has changed from least significant to most significant. For other certificates coming in with the Issuer CA of CN=SSCARSA1024.OU=CA.O=SSS.C=GB they will get a userid of ADCDZ.

You do not need to refresh anything as this change becomes visible when the SETROPTS RACLIST REFESH is issued.

First logon attempt

I stopped and restarted my Chrome browser, and used the URL https://10.1.1.2:9443/ibmmq/console. I was prompted for a list of valid certificates. I chose “Subject:ADCD: Issuer:SSCARSA1024 Serial:0194”.

Sometimes it gave me a blank screen, other times it gave me the logon screen with username and Password fields. It had a URL of https://10.1.1.2:9443/ibmmq/console/login.html.

On the z/OS console I got

ICH408I USER(ADCDE ) GROUP(TEST ) NAME(ADCDE ) MQWEB CL(APPL )
WARNING: INSUFFICIENT AUTHORITY ACCESS INTENT(READ ) ACCESS ALLOWED(NONE )

I could see the the userid(ADCDE) from the RACDCERT MAP was being used (as expected). To give the userid access to the MQWEB resource, I issued the commands

 /* RDEFINE APPL MQWEB UACC(NONE)
PERMIT MQWEB CLASS(APPL) ACCESS(READ) ID(ADCDE)
SETROPTS RACLIST(APPL) REFRESH

And tried again. The web screen remained blank (even with the correct URL). There were no messages on the MQWEB job log. Within the MQWEB stdout (and /u/mqweb/servers/mqweb/logs/messages.log) were messages like

[AUDIT ] CWWKS9104A: Authorization failed for user ADCDE while invoking com.ibm.mq.console on
/ui/userregistry/userinfo. The user is not granted access to any of the required roles: [MQWebAdmin, MQWebAdminRO, MQWebUser].

Give the userid access to the EJBroles

In my mqwebuser.xml I have <safCredentials profilePrefix=”MQWEB”. The MQWEB is the prefix of the EJBROLE resource name. I had set up a group MQPA Web Readonly Admin (MQPAWRA) to make the administration easier. Give the group permission, and connect the userid to the group.

 /* RDEFINE EJBROLE MQWEB.com.ibm.mq.console.MQWebAdminRO  UACC(NONE) 
PERMIT MQWEB.com.ibm.mq.console.MQWebAdminRO CLASS(EJBROLE) - 
  ACCESS(READ) ID(MQPAWRA) 
CONNECT ADCDE group(MQPAWRA)
SETROPTS RACLIST(EJBROLE) REFRESH

Once the security change has been made, it is visible immediately to the MQWEB server. I clicked the browser’s refresh button and successfully got the IBM MQ welcome page (without having to enter a userid or password). When I clicked on the ⓘ icon it said

Principal:ADCDE – Read-Only Administrator (Client Certificate Authentication)

Logoff doesn’t

If you click the logoff icon, you get logged off – but immediately get logged on again – that’s what certificate authorisation does for you. You need to go to a different web site. If you come back to the ibmmq/console web site, it will use the same certificate as you used before.