Category: Liberty

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.

You have to use the same level of Java to display information, as used by the program. For example

export PATH="/usr/lpp/java/new/J8.0_64/bin:$PATH"
/usr/lpp/java/new/J8.0_64/bin/java -Xshareclasses:cacheDir=/tmp,printStats,cache=rseapi

If the levels are different it may just report JVMSHRC005I No shared class caches available.

Issuing commands to manage the shared classes cache

What commands are there ?

The command 

/usr/lpp/java/J17.0_64/bin/java -Xshareclasses:help

gives 100 lines of help including the syntax.

This help text includes

Related command line options: 
                                                                                                                         
  -Xscmx<x>       set size (or soft max size if option -XX:SharedCacheHardLimit= is present) 
                  of new shared class cache to <x> 
  -Xscdmx<x>      set size of shared class cache debug attribute area to <x> 
  -Xscminaot<x>   set minimum shared classes cache space reserved for AOT data to <x> 
  -Xscmaxaot<x>   set maximum shared classes cache space allowed for AOT data to <x> 
  -Xscminjitdata<x>   set minimum shared classes cache space reserved for JIT data to <x> 
  -Xscmaxjitdata<x>   set maximum shared classes cache space allowed for JIT data to <x> 
  -Xzero:nosharebootzip   do not share bootstrap jar entry caches in the shared class cache 
  -XX:SharedCacheHardLimit=<x>   set size of new shared class cache to <x> 
  -XX:ShareClassesEnableBCI   create shared class cache with support for byte-code instrumentation 
  -XX:ShareClassesDisableBCI   create shared class cache without support for byte-code instrumentation 
  -XX:+ShareAnonymousClasses   enable storing and finding anonymous classes in the shared class cache 
  -XX:-ShareAnonymousClasses   disable storing and finding anonymous classes in the shared class cache 
  -XX:+ShareUnsafeClasses   enable storing and finding non-anonymous unsafe classes in the shared class cache 
  -XX:-ShareUnsafeClasses   disable storing and finding non-anonymous unsafe classes in the shared class cache 
  -XX:+UseGCStartupHints   enable storing and finding GC startup hints in the shared class cache 
  -XX:-UseGCStartupHints   disable storing and finding GC startup hints in the shared class 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

When 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

    • <feature>zosWlm-1.0 </feature>
  • </featureManager>
  • <zosWorkloadManager collectionName=”MOPZCET”/>
    • <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.

Ways of logging on to MQWEB on z/OS.

There are different ways of connecting to the MQ Web Server on z/OS (this is based on the z/OS Liberty Web server). Some ways use the SAF interface. This is an interface to the z/OS security manager. IBM provides RACF, there are other security managers such as TOP SECRET, and ACF2. Userid information is stored in the security manager database.

The ways of connecting to the MQ Web server on z/OS.

  • No security. Use no_security.xml to set up the MQ Web Server.
  • Hard coded userids and passwords in a file. Using the basic_registry.xml. This defines userid information like <user name=”mqadmin” password=”mqadmin”> . This is suitable only for a sandbox. The password can be obscured or left in plain text.
  • Logon by z/OS userid and password. Use zos_saf_registry.xml. Logon is by userid and password and checked by a SAF call to the z/OS security manager. The userid is checked for access to a resource like MQWEB.com.ibm.mq.console.MQWebAdmin in class(EJBROLE) and MQWEB in class(APPL).
  • Connect with a client certificate, and authenticate using userid and password. This uses zos_saf_registry.xml plus additional configuration. The userid, password and access to the EJBROLE and APPL resources is checked by the SAF interface. The certificate id is not used to check access, it is just used to do the TLS handshake.
  • Certificate authentication, a password is not required. Connecting use a client certificate. This uses zos_saf_registry.xml plus additional configuration. Using the SAF interface, the certificate maps to a z/OS userid; this ID is used for checking access to the EJBROLE and APPL resource.

The configuration for using TLS is not clear.

I found the documentation for the TLS configuration to be unclear. Two parameters are <ssl clientAuthentication clientAuthenticationSupported…/> The documentation says

  • If you specify clientAuthentication="true", the server requests that a client sends a certificate. However, if the client does not have a certificate, or the certificate is not trusted by the server, the handshake does not succeed.
  • If you specify clientAuthenticationSupported="true", the server requests that a client sends a certificate. However, if the client does not have a certificate, or the certificate is not trusted by the server, the handshake might still succeed.
  • If you do not specify either clientAuthentication or clientAuthenticationSupported, or you specify clientAuthentication="false" or clientAuthenticationSupported="false", the server does not request that a client send a certificate during the handshake.

I experimented with the different options and the results are below.

  1. I used a web browser with several possible certificates that could be used for authentication. I was given a pop up which listed them. Chrome remembers the choice. With Firefox, you can click an option “set as default“. If this is unticked you get prompted every time.
  2. I used a browser with no certificates for authentication.

When a session was not allowed, I got (from Firefox) Secure Connection Failed. An error occurred during a connection to 10.1.1.2:9443. PR_END_OF_FILE_ERROR

Client AuthenticationClient Authentication SupportedBrowser with certificatesBrowser without certificates
trueignoredPick certificate, userid and password NOT requiredPR_END_OF_FILE_ERROR
falsetruePick certificate, userid and password NOT requiredA variety of results. One of
  1. PR_END_OF_FILE_ERROR,
  2. Blank screen
  3. Userid and password required
falsefalseUserid and password requiredUserid and password required

When using certificates, you can chose to specify userid and password instead of client authentication, by using the appropriate URL with https://10.1.1.2:9443/ibmmq/console/login.html, instead of https://10.1.1.2:9443/ibmmq/console .

Note well.

The server caches credential information. If you change the configuration and refresh the server, the change may not be picked up immediately.

Once you have logged on successfully, a cookie is stored in your browser. This may be used to authenticate, until the token has expired. To be sure of clearing this token I restarted my browser.

Why do they ship java products on z/OS with the handbrake on? And how to take the brake off.

I noticed that it takes seconds to start MQ on my little z/OS machine, but minutes (feels like days) to start anything with Liberty Web server.  This include the MQWEB, z/OSMF,  and Z/OSConnect.  I mentioned this to an IBM colleague who asked if I was using Java Shared classes.  These get loaded into z/OS shared pages.

When I implemented it, my Liberty server came up in half the time!

I found this blog post which was very helpful, and showed me where to look for more information.  I subsequently found this document (from 2006!)

The kinder garden overview of how Java works.

  • You start with a program written in the Java language.
  • When you run this, Java converts it into byte codes
  • These byte codes get converted to native instructions  – so a byte code “push onto the stack” may become 8  390 assembler instructions.
  • This code can be optimised, for example code which is executed frequently can have the assembler instructions rewritten to go faster.  It might put code inline instead of out in a subroutine.
  • If you are using Java shared classes, this code can be written out and reused by other applications, or if you restart the server, it can reused what it created before.  Reusing the shared classes means that programs benefit because the byte codes have already been converted into native code, and optimisations have been done on the hot code.

What happens on z/OS?

By default, z/OS writes the code to virtual memory and does not save anything to disk.  If you restart your Java application within the same IPL, it can exploit the shared classes which have been converted to native code, and optimised – great- good design.   I found the second time I started the web server it took half the time.  However I IPL once a day, and start my web server once a day. I do not benefit from having it start faster a second time – as I only started it once per session. By default when you re-ipl, the shared classes code is discarded, and so next time you need the code, it has to be to convert to native instructions again, and it loses any optimisation which had been done.

What is the solution?

It is two easy steps:!

  1. Tell Java to write the information from memory to disk – to take a snaphot.
  2. After IPL tell Java to load memory from the disk image – to restore a snapshot.

It is as simple as that.

Background.

It is all to do with the java -Xshareclasses.

With your application you tell Java where to store information about the shared classed.  It defaults to Cache=/tmp/ name=javasharedresources.

In my jvm.options I overrode the defaults and specified

-Xshareclasses:nonFatal 
-Xshareclasses:groupAccess 
-Xshareclasses:cacheDirPerm=0777 
-Xshareclasses:cacheDir=/tmp,name=mqweb

If you give each application a name (such as mqweb)  you can isolate the cache to an application and not disrupt another JVM if you change the cache.  For example if you restore from a snapshot, only users of that “name” will be affected.

List what is in the cache

You can use the USS command,

java -Xshareclasses:cacheDir=/tmp/,listAllCaches

I used a batch job to do the same thing.

//IBMJAVA  JOB  1 
// SET V='listAllCaches' 
// SET C='/tmp/' 
//S1       EXEC PGM=BPXBATCH,REGION=0M, 
// PARM='SH java -Xshareclasses:cacheDir=&C,&V' 
//STDERR   DD   SYSOUT=* 
//STDOUT   DD   SYSOUT=*

The output below, shows the cache name is mqweb.  Once you have created a snapshot it has an entry for it.

Listing all caches in cacheDir /tmp/                                                                          
                                                                                                              
Cache name       level         cache-type      feature         OS shmid       OS semid 
mqweb            Java8 64-bit  non-persistent  cr              8197           4101

For a different product I got

Incompatible shared caches                                     
rseapi                  Java8 32-bit  non-persistent  default

The Incompatible shared caches looks like it means you are using 64 bit Java – but there is a cache using 32 bit Java.

For MQWEB the default parameters are -Xshareclasses:cacheDir=/u/mqweb/servers/.classCache,name=liberty-%u” where /u/mqweb is the WLP parameter, where my parameter are defined, and %u is the userid the server is running under, so in my case liberty=START1.

When I had /u/mqweb/servers/.classCache, then the total command line was too long for BPXBATCH.   (Putting it into STDPARM gave me IEC020I 001-4 on the instream STDPARM because the resolved line wa greater than 80 characters.   I resolved this by adding -Xshareclasses:cacheDir=/u/mqweb,name=cache to the jvm.options file.

To take a snapshot


//IBMJAVA  JOB  1 
// SET C='/tmp/' 
// SET N='mqweb' 
// SET V='restoreFromSnapshot' 
// SET V='listAllCaches'
// SET V='snapshotCache'
//S1       EXEC PGM=BPXBATCH,REGION=0M, 
// PARM='SH java -Xshareclasses:cacheDir=&C,name=&N,&V' 
//STDERR   DD   SYSOUT=* 
//STDOUT   DD   SYSOUT=* 
//

This job took a few seconds to run.

I believe you have to take the snapshot while your Java application is executing – but I do not know for definite.

Restore a snapshot

To restore a snapshot just use restoreFromSnapshot in the above JCL. This took a few seconds to run. 

How to use it.

If you put the restoreFromSnaphot JCL at the start of the web server, it will preload it whenever you use your server.

If you take a snapshot every day before shutting down your server, you will get a copy with the latest optimisations.  If you do not take a new snapshot it continues to use the old one.

If you want to not use the shared cache you can get rid of it using the command destroySnapshot.

Is my cache big enough?

If you use the printStats request you get information like

Current statistics for cache "mqweb":                                                
...                                                                                     
cache size                           = 104857040                                     
softmx bytes                         = 104857040                                     
free bytes                           = 70294788 
...
Cache is 32% full                                     
                                                      
Cache is accessible to current user = true

The documentation says

When you specify -Xshareclasses without any parameters and without specifying either the -Xscmx or -XX:SharedCacheHardLimit options, a shared classes cache is created with a default size, as follows:

  • For 64-bit platforms, the default size is 300 MB, with a “soft” maximum limit for the initial size of the cache (-Xscmx) of 64MB, …

I had specified -Xscmx100m  which matches the value reported.

What is in the cache?

You can use the printAllStats command.  This displays information like

Classpath

1: 0x00000200259F279C CLASSPATH
/usr/lpp/java/J8.0_64/lib/s390x/compressedrefs/jclSC180/vm.jar
/usr/lpp/java/J8.0_64/lib/se-service.jar
/usr/lpp/java/J8.0_64/lib/math.jar

Methods for a class
  • 0x00000200259F24A4 ROMCLASS: java/util/HashMap at 0x000002001FF7AEB8.
  • ROMMETHOD: size Signature: ()I Address: 0x000002001FF7BA88
  • ROMMETHOD: put Signature: (Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; Address: 0x000002001FF7BC50

This shows

  • there is a class HashMap. 
  • It has a method size() with no parameters returning an Int.  It is at…. in memory
  • There is another method put(Object o1, Object o2)  returning an Object.  It is at … in memory
Other stuff

There are sections with JITHINTS and other performance related data.

Do not restart with the fire hose set to maximum.

There is an article in The Register, about an outage at the Tokyo stock exchange.  One of the problems was that they did not have a process for restarting the environment.  The impact of restarting a system is often overlooked, and in the panic of “get it started as quickly as possible” things can go wrong.   The fire brigade slowly increases the pressure in a fire hose to stop the fire crew from being knocked down with the sudden flow.

TCP/IP is good because it has a “slow start” protocol.  Once a connection has been established, and is working well, the exchange can use bigger buffers, and send more buffers before waiting for the acknowledgement.   This boosts the throughput.  If the back-end is slow to process the data, TCP  slows down the traffic, and then increases the throughput again if the connection can handle it.  If the connection stops and restarts, the rate starts slowly and builds up, rather than use the rate just before the outage.

You cannot expect WAS/CICS/DB2/MQ/IMS to restart at maximum speed; it has to work up to it.  Transactions may have to warm up. There can be many reasons:

  1. Data many need to be read from page-sets into buffers, for example read hot Db/2 data into memory.
  2. Java code needs to warm up to become more efficient (JITed).
  3. The systems need to establish a working set, for example making a buffer pool larger.
  4. Establishing connections may have some serialisation delays.

Restarting faster than a system can cope can cause a domino effect.  A transaction server is restarted and the fire hose of data is turned on.   The transaction server is still warming up, and cannot cope with the volume of requests.    Work for this system is then routed to another transaction server which could handle the workload if the volume gradually increases,  If it gets this additional work  all at once, this instance slows down, and the work is routed to another transaction server etc.

MQ can be seen as the bad guy here.  When you restart MQ, it can go to fire hose mode immediately.   You should start the output channels first to start draining messages, then gradually start the input channels.   If you start the input channels before the output channels, you may get queues and page sets filling up, before the output channels can process the messages.

If you have a policy that all client connects must disconnect and reconnect a random time between15 minutes and 45 minutes this should help spread the load, and gradually you should get a balanced environment.