What options can I specify for Java on z/OS?

You can use the following command to list them all.

java -X -help 

On Java 8 SR 8 this gave me

The following options are non-standard and subject to change without notice. 
                                                                                                       
  -Xbootclasspath:<path>    set bootstrap classpath to <path> 
  -Xbootclasspath/p:<path>  prepend <path> to bootstrap classpath 
  -Xbootclasspath/a:<path>  append <path> to bootstrap classpath 
                                                                                                       
  -Xrun<library>[:options]  load native agent library 
                            (deprecated in favor of -agentlib) 
                                                                                                       
  -Xshareclasses[:options]  Enable class data sharing (use help for details) 
                                                                                                       
  -Xint           run interpreted only (equivalent to -Xnojit -Xnoaot) 
  -Xnojit         disable the JIT 
  -Xnoaot         do not run precompiled code 
  -Xquickstart    improve startup time by delaying optimizations 
  -Xfuture        enable strictest checks, anticipating future default
  -verbose[:(class|gcterse|gc|dynload|sizes|stack|debug)] 
                                                                                                       
  -Xtrace[:option,...]  control tracing use -Xtrace:help for more details 
                                                                                                       
  -Xcheck[:option[:...]]  control checking use -Xcheck:help for more details 
                                                                                                       
  -Xhealthcenter  enable the Health Center agent 
                                                                                                       
  -Xdiagnosticscollector enable the Diagnotics Collector 
                                                                                                       
  -XshowSettings                show all settings and continue 
  -XshowSettings:system 
                      (Linux Only) show host system or container 
                      configuration and continue 
  -XshowSettings:all            show all settings and continue 
  -XshowSettings:vm             show all vm related settings and continue 
  -XshowSettings:properties     show all property settings and continue 
  -XshowSettings:locale         show all locale related settings and continue 
                                                                                                         
Arguments to the following options are expressed in bytes. 
Values suffixed with "k" (kilo) or "m" (mega) will be factored accordingly. 
                                                                                                         
  -Xmca<x>        set RAM class segment increment to <x> 
  -Xmco<x>        set ROM class segment increment to <x> 
  -Xmn<x>         set initial/maximum new space size to <x> 
  -Xmns<x>        set initial new space size to <x> 
  -Xmnx<x>        set maximum new space size to <x> 
  -Xmo<x>         set initial/maximum old space size to <x> 
  -Xmos<x>        set initial old space size to <x> 
  -Xmox<x>        set maximum old space size to <x> 
  -Xmoi<x>        set old space increment to <x> 
  -Xms<x>         set initial memory size to <x> 
  -Xmx<x>         set memory maximum to <x> 
  -Xmr<x>         set remembered set size to <x> 
  -Xmrx<x>        set maximum size of remembered set to <x> 
  -Xmso<x>        set OS thread stack size to <x> 
  -Xiss<x>        set initial java thread stack size to <x> 
  -Xssi<x>        set java thread stack increment to <x> 
  -Xss<x>         set maximum java thread stack size to <x> 
  -Xscmx<x>       set size (or soft max size if option -XX:SharedCacheHardLimit= is 
                  present) of new shared class cache 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> 
   -Xmine<x>       set minimum size for heap expansion to <x> 
   -Xmaxe<x>       set maximum size for heap expansion to <x> 
                                                                                                        
 Arguments to the following options are expressed as a decimal from 0 to 1. 
 A value of 0.3 represents a request of 30% 
                                                                                                        
   -Xminf<x>       minimum percentage of heap free after GC 
   -Xmaxf<x>       maximum percentage of heap free after GC

 Arguments to the following options are expressed a decimal numbers. 
                                                                                                                
   -Xgcthreads<x>                set number of GC threads 
   -Xnoclassgc                   disable dynamic class unloading 
   -Xclassgc                     enable dynamic class unloading 
   -Xalwaysclassgc               enable dynamic class unloading on every GC 
   -Xnocompactexplicitgc         disable compaction on a system GC 
   -Xcompactexplicitgc           enable compaction on every system GC 
   -Xcompactgc                   enable compaction 
   -Xnocompactgc                 disable compaction 
   -Xlp                          enable large page support 
   -Xrunjdwp:<options>           enable debug, JDWP standard options 
   -Xjni:<options>               set JNI options 
                                                                                                                  

I noticed that some products using Java have the nice option

-Xoptionsfile=/var/xxxf/configuration/colin_override.cfg

Where the file has a list of JVM options one on each line.

This option is not generally available.

Passing parameters to Java programs

There is a quote by Alexander Pope

A little learning is a dangerous thing.
Drink deep, or taste not the Pierian Spring;
There shallow draughts intoxicate the brain,
and drinking largely sobers us again.”

I was having problems passing parameters to Java. I had a little knowledge about Java web servers on z/OS, so I was confident I knew how to configure a web browser; unfortunately I did not have enough knowledge.

I was trying to get keyrings working with a web server on z/OS, but what I specified was not being picked up. In this post I’ll focus on keyrings, but it applies to other parameters are well.

Setting the default values

You can give Java a default keyring name

-Djavax.net.ssl.keyStore=safkeyring://START1/MQRING

Which says, if the user does not specify a keystore then use this value. If the user does not create a keystore, then a default keystore is created using these parameters.

Specify the value yourself

You can create your own keystore, passing keystore name and keystore type. You could use you own option, such as -DCOLINKEYRINGNAME=safkeyring://START1/MQRING and use that when configuring the keystore to Java. In this case the -Djavax.net.ssl.keyStore=safkeyring://START1/MQRING is not used. This is the same for other parameters.

Web server configuation

The Apache web server, and IBM Liberty web servers, are configured using server.xml files, and the web server creates the keystores etc using the information in the file.

For example a web server may have content like

<Connector port="${port.http}" protocol="${http.protocol}" 
     SSLEnabled="true" 
     maxThreads="550" scheme="https" secure="true" 
     clientAuth="false" sslProtocol="TLS" 
     keystoreFile="${keystoreFile}" 
     keystorePass="${keystorePass}" 
     keystoreType="${keystoreType}" 
     sslEnabledProtocols="${ssl.enabled.protocols}" /> 

where the ${…} is an environment variable. ${keystoreFile} would use the environment variable keystoreFile or option -DkeystoreFile=”safkeyring//START1/MYRING”

You can have multiple <Connector..> each with different parameters, so using -Djavax.net.ssl.keyStore etc would not work.

You need to know which options to use, because setting the Java defaults using -Djavax.net.ssl.keyStore… may be overridden.

You also need to know which server.xml file to use! I was getting frustrated when the changes I made to the server.xml was not the server.xml being used!

TLS 1.3, Java and z/OS

I was failing to get this working with Java 8 – despite it being supported in Java 8.

I eventually found a support statement which says

Enables TLS v1.3 protocol (defined by RFC 8446) in SR6 FP25

however java -version gave me

Java -version gives build 8.0.6.16 – pmz6480sr6fp16-20200902_01(SR6 FP16))

I had Fix Pack 16 and the support is in Fix Pack 25 (from 2020)

Download a more up to date version

The IBM Support page Java SDK Products on z/OS lists the supported version of Java. There is a link to IBM Semeru Runtime Certified Edition for z/OS (Semeru is free production-ready binaries built with the OpenJDK class libraries and the Eclipse OpenJ9 JVM).

When I tried to download V8 SR8, I got a window saying “You cannot download this due to export restrictions”. Next day, I tried again and it worked, the droids working in the background much have found I was a good guy.

Check your java.security file

When I used my own copy of the java.security file it did not work.

I had

security.provider.1=com.ibm.crypto.provider.IBMJCE 
security.provider.2=com.ibm.crypto.plus.provider.IBMJCEPlus 

The latest fix pack Java had

security.provider.1=com.ibm.jsse2.IBMJSSEProvider2 
security.provider.2=com.ibm.crypto.provider.IBMJCE 
security.provider.3=com.ibm.crypto.plus.provider.IBMJCEPlus 

The error messages I got were

SEVERE org.apache.catalina.util.LifecycleBase.handleSubClassException
Failed to initialize component Connector HTTP/1.1-6800

org.apache.catalina.LifecycleException: Protocol handler initialization failed Caused by: java.lang.IllegalArgumentException: None of the protocols specified are supported by the SSL engine : TLSv1.3

As the support for TLSv1.3 was in JSSE, it is clear (with hindsight) that I needed to specific the provider com.ibm.jsse2.IBMJSSEProvider2!

Follow the instructions to install Java on z/OS and screw up production.

I downloaded an update to Java on z/OS, and noticed that the instructions would cause problems!

Java is in a directory like

/usr/lpp/java/J7.1        
/usr/lpp/java/J7.1_64     
/usr/lpp/java/J8.0        
/usr/lpp/java/J8.0_64     

I have Java V7 and V8 and 31 and 64 versions

The installation instruction say

cd to /usr/lpp/java and unpax the uploaded SDK8_64bit_SR8_FP6.PAX.Z file.

This will unpack the file into

/usr/lpp/java/J8.0_64

Overwriting your production system with the new version, so it goes live without any testing, and for a few minutes you have a mixture of files from different fixpacks!

What I would suggest is

  • Unzip the file gzip -l -d ibm-semeru-open-jre_x64_linux_11.0.20_8_openj9-0.40.0.tar.gz this upacks the file into a .tar – and delete the .gz
  • FTP it to z/OS in binary
  • Create a ZFS for the new Java.
  • mkdir  /usr/lpp/java/new
  • mount the ZFS in /usr/lpp/java/new
  • cd /usr/lpp/java/new
  • pax -ppx -rvzf SDK8_64bit_SR8_FP6.PAX.Z

This will create files under

/usr/lpp/java/new/J8.0_64

Test this by setting

export JAVA_HOME="/usr/lpp/java/new/J8.0_64"

and using it.

When you have finished your testing, you can mount the new ZFS on /usr/lpp/java/J8.0_64 .

You may want to do this as part of an IPL, because an unmount of a ZFS will terminate any thing using the file system – such as z/OSMF.

You could set up /usr/lpp/java/old/J8.0_64 and /usr/lpp/java/new/J8.0_64 and use /usr/lpp/java/J8.0_64 as an alias to one or the other.

How to change the java.security file on a read only file system.

I had a problem getting Java to read a keyring, and one suggestion was to change the security providers in the /usr/lpp/java/current_64/lib/security/java.security. This is the system wide default definition file for Java.

Unfortunately this is on a read only file system.

I had the choice of changing this file – not a good idea or overriding it.

Overriding which file to use

In the file, there are comments about overriding the file

  • -Djava.security.properties=url (one equals), to append to the system java.security file
  • -Djava.security.properties== url (two equals), to replace the system.security file used.

In my Java program startup I used the over-ride to replace the default file –

-Djava.security.properties==/etc/zexpl/java.security"

and copied /usr/lpp/java/current_64/lib/security/java.security to /etc/zexpl/java.security. I could edit this as I pleased, as any changes only affect this application.

Updating the production file system.

I’m lucky I work on a single user z/OS system. I do not have to worry about change control and disrupting other users.

I used the df command to display which file system the file was on, then I unmounted and remounted the file system.

df -P /usr/lpp/java/current_64/lib/security/java.security to /etc/zexpl/java.security.
unmount filesystem('ABC100.ZFS') Immediate 
mount filesystem('ABC100.ZFS') mode(RDWR)type(HFS) mountpoint('/usr/lpp/IBM/abcdef')

so children of all ages – do not do this at home or at the office!

Which came first, the chicken or the checksum.

The ability to sign Java jar files, or z/OS modules, has been around for many years. Using this the loader checks the digital signature in the object. This digital signature is a checksum of the object, and this checksum is encrypted and stored with the object. At load time, the loader calculates the checksum, and decrypts the checksum in the object and checks they match.

MQ now supports this for some of its objects; downloadable .zip, .tar and .gz files.

For some of these you need to download the public key to use. This raises the problem that an evil person may have taken the object, removed the official signing information, and added their own stuff. You then download their public certificate – see it works, it must be official.

To prevent this you can do the checksum on the public certificate, and make that available along with the official public key. (This is the chicken and egg problem. You need the certificate to be able to check the main code, and how to you check the certificate, without a certificate to check?)

On Linux you can calculate the checksum of a file using

sha256sum 9.2.4.0-IBM-MQ-Sigs-Certs.tar.gz

this gives 53c34cd374d7b08522423533ef2019b4aa0109a595fbaeab8ee6f927cb6c93ad, which is the same as the value on the IBM site. So this matches.

The IBM MQ code signatures page says IBM MQ public certificates, checksums, and .sig files are available from https://ibm.biz/mq92signatures. On this signatures page it says

release level: 9.2.4.0-IBM-MQ-Sigs-Certs 
Continuous Delivery: 9.2.4 IBM MQ file signatures, checksums and certificates

Platforms:  AIX 64-bit, pSeries, Linux 64-bit,x86_64, Linux 64-bit,zSeries, Linux PPC64LE, Windows 64-bit, x86, z/OS

This page is an httpS page, with the certificate issued by a proper Certificate Authority, and trusted third party. If you trust this CA, you can trust the IBM page.

When you click download, it downloads

  • 9.2.4.0-IBM-MQ-Sigs-Certs.tar.gz.sha256sum – this file content has 53c34cd374d7b08522423533ef2019b4aa0109a595fbaeab8ee6f927cb6c93ad
  • 9.2.4.0-IBM-MQ-Sigs-Certs.tar.gz

The value in the sha256sum file matches the value of the sha256sum 9.2.4.0-IBM-MQ-Sigs-Certs.tar.gz command.

As you can trust the security chain from the web page, through to the downloads, you can trust the .gz file.

Jar signing

Java has had the capability to sign a jar for at least 10 years.

The jarsigner command takes a jar file, a keystore with private key and calculates the checksum. It then encrypts it, and creates some files in the jar. For example

jarsigner -keystore trust.jks -storepass zpassword checkTLS.jar signer

This uses

  • the keystore called trust.jks,
  • with password zpassword
  • the checkTLS.jar file
  • and uses the certificate with alias name signer. This certificate must have extendedKeyUsage with codeSigning.

The jar file now has some additional files which can be seen using jar -tvf checkTLS.jar command.

  • META-INF/SIGNER.SF . This is the Signature File.
  • META-INF/SIGNER.EC .This is the public key to be used.

Where SIGNER is the name of the alias of the private key in the keystore, used to sign the jar file. The jar file can be signed many times by different private keys.

To verify the signature you can use

  • jarsigner -verify checkTLS.jar
  • jarsigner -verbose -certs -verify checkTLS.jar

The jarsigner -verbose -certs -verify checkTLS.jar gave me

- Signed by "CN=signer, O=cpwebuser, C=GB"
    Digest algorithm: SHA-256
    Signature algorithm: SHA256withECDSA, 256-bit key

jar verified.

Warning: 
This jar contains entries whose certificate chain is invalid. Reason: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target
This jar contains signatures that do not include a timestamp. Without a timestamp, users may not be able to validate this jar after any of the signer certificates expire (as early as 2024-11-03).

The signer certificate will expire on 2024-11-03.

This shows that the jar file is consistent with the checksumming, but the certificate cannot be validated.

I can tell it which keystore to use to validate the certificate, using

jarsigner –keystore trust.jks -certs -verify checkTLS.jar

With the -verbose option you also get (with some of the output rearranged for clarity). The “s” or “sm” at the front of an object entry is s=signature verified, and m=entry listed in the manifest.

s = signature was verified 
m = entry is listed in manifest
k = at least one certificate was found in keystore
i = at least one certificate was found in identity scope


s 1402 Wed Dec 22 14:27:52 GMT 2021 META-INF/MANIFEST.MF

  >>> Signer
  X.509, CN=signer, O=cpwebuser, C=GB
  [certificate is valid from 22/12/21 14:51 to 30/01/25 16:46]
  X.509, CN=SSCA256, OU=CA, O=SSS, C=GB
  [certificate is valid from 04/11/21 15:48 to 03/11/24 15:48]

  [Invalid certificate chain: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target]

        1579 Wed Dec 22 16:12:04 GMT 2021 META-INF/SIGNER.SF
        1373 Wed Dec 22 16:12:04 GMT 2021 META-INF/SIGNER.EC

sm  54 Sat Jan 30 14:48:52 GMT 2021 checkTLS/checkTLS.manifest

  >>> Signer
  X.509, CN=signer, O=cpwebuser, C=GB
  [certificate is valid from 22/12/21 14:51 to 30/01/25 16:46]
  X.509, CN=SSCA256, OU=CA, O=SSS, C=GB
  [certificate is valid from 04/11/21 15:48 to 03/11/24 15:48]

  [Invalid certificate chain: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target]

When I downloaded the MQ 9.2.4 client and ran the jarsigner …. -verbose command the output included

sm 642 Thu Nov 04 16:01:46 GMT 2021 wlp/lib/extract/IFixUtils$ParsedIFix.class

[entry was signed on 04/11/21 17:58]
>>> Signer
X.509, CN=International Business Machines Corporation, OU=IBM CCSS, O=International Business Machines Corporation, L=Armonk, ST=New York, C=US
[certificate is valid from 25/08/21 01:00 to 26/08/23 00:59]
X.509, CN=DigiCert Trusted G4 Code Signing RSA4096 SHA384 2021 CA1, O="DigiCert, Inc.", C=US
[certificate is valid from 29/04/21 01:00 to 29/04/36 00:59]
      X.509, CN=DigiCert Trusted Root G4, OU=www.digicert.com, O=DigiCert Inc, C=US
[trusted certificate]
... 

This shows that the certificate used to sign the component of the jar file was signed by CN=International Business Machines Corporation, which was in turn signed by CN=DigiCert Trusted G4 Code Signing RSA4096 SHA384 2021 CA1. The jarsigner program was able to use its public certificate to validate the CA, and so validate the IBM certficiate, and so validate the checksum.

One Minute MVS – tuning stack and heap pools

These days many applications use a stack and heap to manage storage used by an application. For C and Cobol programs on z/OS these use the C run time facilities. As Java uses the C run time facilities, it also uses the stack and heap.

If the stack and heap are not configured appropriately it can lead to an increase in CPU. With the introduction of 64 bit storage, tuning the heap pools and stack is no longer critical. You used to have to carefully manage the stack and heap pool sizes so you didn’t run out of storage.

The 5 second information on what to check, is the number of segments freed for the stack and heap should be zero. If the value is large then a lot of CPU is being used to manage the storage.

The topics are

Kinder garden background to stack.

When a C (main) program starts, it needs storage for the variables uses in the program. For example

int i;
for (ii=0;ii<3:ii++)
{}

char * p = malloc(1024);

The variables ii and p are variables within the function, and will be on the functions stack. p is a pointer.

The block of storage from the malloc(1024) will be obtained from the heap, and its address stored in p.

When the main program calls a function the function needs storage for the variables it uses. This can be done in several ways

  1. Each function uses a z/OS GETMAIN request on entry, to allocate storage, and a z/OS FREEMAIN request on exit. These storage requests are expensive.
  2. The main program has a block of storage which functions can use. For the main program uses bytes 0 to 1500 of this block, and the first function needs 500 bytes, so uses bytes 1501 to 2000. If this function calls another function, the lower level function uses storage from 2001 on wards. This is what usually happens, it is very efficient, and is known as a “stack”.

Intermediate level for stack

It starts to get interesting when initial block of storage allocated in the main program is not big enough.

There are several approaches to take when this occurs

  1. Each function does a storage GETMAIN on entry, and FREEMAIN on exit. This is expensive.
  2. Allocate another big block of storage, so successive functions now use this block, just like in the kinder garden case. When functions return to the one that caused a new block to be allocated,
    1. this new block is freed. This is not as expensive as the previous case.
    2. this block is retained, and stored for future requests. This is the cheapest case. However a large block has been allocated, and may never be used again.

How big a block should it allocate?

When using a stack, the size of the block to allocate is the larger of the user specified size, and the size required for the function. If the specified secondary size was 16KB, and a function needs 20KB of storage, then it will allocate at least 20KB.

How do I get the statistics?

For your C programs you can specify options in the #PRAGMA statement or, the easier way, is to specify it through JCL. You specify C run time options through //CEEOPTS … For example

//CEEOPTS DD *
STACK(2K,12K,ANYWHERE,FREE,2K,2K)
RPTSTG(ON)

Where

  • STACK(…) is the size of the stack
  • RPTSTG(ON) says collect and display statistics.

There is a small overhead in collecting the data.

The output is like:

STACK statistics:                                                
  Initial size:                                2048     
  Increment size:                             12288     
  Maximum used by all concurrent threads:  16218808     
  Largest used by any thread:              16218808     
  Number of segments allocated:                2004     
  Number of segments freed:                    2002     

Interpreting the stack statistics

From the above data

  • This shows the initial stack size was 2KB and an increment of 12KB.
  • The stack was extended 2004 times.
  • Because the statement had STACK(2K,12K,ANYWHERE,FREE,2K,2K), when the secondary extension became free it was FREEMAINed back to z/OS.

When KEEP was used instead of FREE, the storage was not returned back to z/OS.

The statistics looked like

STACK statistics:                                                
  Initial size:                               2048     
  Increment size:                            12288     
  Maximum used by all concurrent thread:  16218808     
  Largest used by any thread:             16218808     
  Number of segments allocated:               1003     
  Number of segments freed:                      0     

What to check for and what to set

For most systems, the key setting is KEEP, so that freed blocks are not released. You can see this a) from the definition b) Number of segments freed is 0.

If a request to allocate a new segment fails, then the C run time can try releasing segments that are not in use. If this happens the “”segments freed” will be incremented.

Check that the “segments freed” is zero, and if not, investigate why not.

When a program is running for a long time, a small number of “segments allocated” is not a problem.

Make the initial size larger, closer to the “Largest used of any thread” may improve the storage utilisation. With smaller segments there is likely to be unused space, which was too small for a functions request, causing the next segment to be used. So a better definition would be

STACK(16M,12K,ANYWHERE,KEEP,2K,2K)

Which gave

STACK statistics:                                                          
  Initial size:                                     16777216               
  Increment size:                                      12288               
  Maximum used by all concurrent threads:           16193752               
  Largest used by any thread:                       16193752               
  Number of segments allocated:                            1               
  Number of segments freed:                                0               

Which shows that just one segment was allocated.


Kinder garden background to heap

When there is a malloc() request in C, or a new … in Java, the storage may exist outside of the function. The storage is obtained from the heap.

The heap has blocks of storage which can be reused. The blocks may all be of the same size, or or different sizes. It uses CPU time to scan free blocks looking for the best one to reuse. With more blocks it can use increasing amounts of CPU.

There are heap pools which avoids the costs of searching for the “right” block. It uses a pools of blocks. For example:

  1. there is a heap pool with 1KB fixed size blocks
  2. there is another heap pool with 16KB blocks
  3. there is another heap pool with 256 KB blocks.

If there is a malloc request for 600 bytes, a block will be taken from the 1KB heap pool.

If there is a malloc request for 32KB, a block would be used from the 256KB pool.

If there is a malloc request for 512KB, it will issue a GETMAIN request.

Intermediate level for heap

If there is a request for a block of heap storage, and there is no free storage, a large segment of storage can be obtained, and divided up into blocks for the stack. If the heap has 1KB blocks, and a request for another block fails, it may issue a GETMAIN request for 100 * 1KB and then add 100 blocks of 1KB to the heap. As storage is freed, the blocks are added to the free list in the heap pool.

There is the same logic as for the stack, about returning storage.

  1. If KEEP is specified, then any storage that is released, stays in the thread pool. This is the cheapest solution.
  2. If FREE is specified, then when all the blocks in an additional segment have been freed, then free the segment back to the z/OS. This is more expensive than KEEP, as you may get frequent GETMAIN and FREEMAIN requests.

How many heap pools do I need and of what size blocks?

There is usually a range of block sizes used in a heap. The C run time supports up to 12 cell sizes. Using a Liberty Web server, there was a range of storage requests, from under 8 bytes to 64KB.

With most requests there will frequently be space wasted. If you want a block which is 16 bytes long, but the pool with the smallest block size is 1KB – most of the storage is wasted.
The C run time gives you suggestions on the configuration of the heap pools, the initial size of the pool and the size of the blocks in the pool.

Defining a heap pool

How to define a heap pool is defined here.

You specify the size of overall size of storage in the heap using the HEAP statement. For example for a 16MB total heap size.

HEAP(16M,32768,ANYWHERE,FREE,8192,4096)

You then specify the pool sizes


HEAPPOOL(ON,32,1,64,2,128,4,256,1,1024,7,4096,1,0)

The figures in bold are the size of the blocks in the pool.

  • 32,1 says maximum size of blocks in the pool is 32 bytes, allocate 1% of the heap size to this pool
  • 64,2 says maximum size of blocks in the pool is 64 bytes, allocate 2% of the heap size to this pool
  • 128,4 says maximum size of blocks in the pool is 128 bytes, allocate 4% of the heap size to this pool
  • 256,1 says maximum size of blocks in the pool is 256 bytes, allocate 1% of the heap size to this pool
  • 1024,7 says maximum size of blocks in the pool is 1024 bytes, allocate 7% of the heap size to this pool
  • 4096,1 says maximum size of blocks in the pool is 4096 bytes, allocate 1% of the heap size to this pool
  • 0 says end of definition.

Note, the percentages do not have to add up to 100%.

For example, with the CEEOPTS

HEAP(16M,32768,ANYWHERE,FREE,8192,4096)
HEAPPOOLS(ON,32,50,64,1,128,1,256,1,1024,7,4096,1,0)

After running my application, the data in //SYSOUT is


HEAPPOOLS Summary:                                                         
  Specified Element   Extent   Cells Per  Extents    Maximum      Cells In 
  Cell Size Size      Percent  Extent     Allocated  Cells Used   Use      
  ------------------------------------------------------------------------ 
       32        40    50      209715           0           0           0 
       64        72      1        2330           1        1002           2 
      128       136      1        1233           0           0           0 
      256       264      1         635           0           0           0 
     1024      1032      7        1137           1           2           0 
     4096      4104      1          40           1           1           1 
  ------------------------------------------------------------------------ 

For the cell size of 32, 50% of the pool was allocated to it,

Each block has a header, and the total size of the 32 byte block is 40 bytes. The number of 40 bytes units in 50% of 16 MB is 8MB/40 = 209715, so these figures match up.

(Note with 64 bit heap pools, you just specify the absolute number you want – not a percentage of anything).

Within the program there was a loop doing malloc(50). This uses cell pool with size 64 bytes. 1002 blocks(cells) were used.

The output also has

Suggested Percentages for current Cell Sizes:
HEAPP(ON,32,1,64,1,128,1,256,1,1024,1,4096,1,0)


Suggested Cell Sizes:
HEAPP(ON,56,,280,,848,,2080,,4096,,0)

I found this confusing and not well documented. It is another of the topics that once you understand it it make sense.

Suggested Percentages for current Cell Sizes

The first “suggested… ” values are the suggestions for the size of the pools if you do not change the size of the cells.

I had specified 50% for the 32 byte cell pool. As this cell pool was not used ( 0 allocated cells) then it suggests making this as 1%, so the suggestion is HEAPP(ON,32,1

You could cut and paste this into you //CEEOPTS statement.

Suggested Cell Sizes

The C run times has a profile of all the sizes of blocks used, and has suggested some better cell sizes. For example as I had no requests for storage less than 32 bytes, making it bigger makes sense. For optimum storage usage, it suggests of using sizes of 56, 280,848,2080,4096 bytes.

Note it does not give suggested number of blocks. I think this is poor design. Because it knows the profile it could have an attempt at specifying the numbers.

If you want to try this definition, you need to add some values such as

HEAPP(ON,56,1,280,1,848,1,2080,1,4096,1,0)

Then rerun your program, and see what percentage figures it recommends, update the figures, and test again. Not the easiest way of working.

What to check for and what to set

There can be two heap pools. One for 64 bit storage ( HEAPPOOL64) the other for 31 bit storage (HEAPPOOL).

The default configuration should be “KEEP”, so any storage obtained is kept and not freed. This saves the cost of expensive GETMAINS and FREEMAINs.

If the address space is constrained for storage, the C run time can go round each heap pool and free up segments which are in use.

The value “Number of segments freed” for each heap should be 0. If not, find out why (has the pool been specified incorrectly, or was there a storage shortage).

You can specify how big each pool is

  • for HEAPPOOL the HEAP size, and the percentage to be allocated to each pool – so two numbers to change
  • for HEAPPOOL64 you specify the size of each pool directly.

The sizes you specify are not that sensitive, as the pools will grow to meet the demand. Allocating one large block is cheaper that allocating 50 smaller blocks – but for a server, this different can be ignored.

With a 4MB heap specified

HEAP(4M,32768,ANYWHERE,FREE,8192,4096)
HEAPP(ON,56,1,280,1,848,1,2080,1,4096,1,0)

the heap report was

 HEAPPOOLS Summary: 
   Specified Element   Extent   Cells Per  Extents    Maximum      Cells In 
   Cell Size Size      Percent  Extent     Allocated  Cells Used   Use 
   ------------------------------------------------------------------------ 
        56        64      1         655           2        1002           2 
       280       288      1         145           1           1           0 
       848       856      1          48           1           1           0 
      2080      2088      1          20           1           1           1 
      4096      4104      1          10           0           0           0 
   ------------------------------------------------------------------------ 
   Suggested Percentages for current Cell Sizes: 
     HEAPP(ON,56,2,280,1,848,1,2080,1,4096,1,0) 

With a small(16KB) heap specified

HEAP(16K,32768,ANYWHERE,FREE,8192,4096)
HEAPP(ON,56,1,280,1,848,1,2080,1,4096,1,0)

The output was

HEAPPOOLS Summary:                                                            
  Specified Element   Extent   Cells Per  Extents    Maximum      Cells In    
  Cell Size Size      Percent  Extent     Allocated  Cells Used   Use         
  ------------------------------------------------------------------------    
       56        64      1           4         251        1002           2    
      280       288      1           4           1           1           0    
      848       856      1           4           1           1           0    
     2080      2088      1           4           1           1           1    
     4096      4104      1           4           0           0           0    
  ------------------------------------------------------------------------    
  Suggested Percentages for current Cell Sizes:                               
    HEAPP(ON,56,90,280,2,848,6,2080,13,4096,1,0)                             

and we can see it had to allocate 251 extents for all the request.

Once the system has “warmed up” there should not be a major difference in performance. I would allocate the heap to be big enough to start with, and avoid extensions.

With the C run time there are heaps as well as heap pools. My C run time report gave

64bit User HEAP statistics:
31bit User HEAP statistics:
24bit User HEAP statistics:
64bit Library HEAP statistics:
31bit Library HEAP statistics:
24bit Library HEAP statistics:
64bit I/O HEAP statistics:
31bit I/O HEAP statistics:
24bit I/O HEAP statistics:

You should check all of these and make the initial size the same as the suggested recommended size. This way the storage will be allocated at startup, and you avoid problems of a request to expand the heap failing due to lack of storage during a buys period.

Advanced level for heap

While the above discussion is suitable for many workloads, especially if they are single threaded. It can get more complex when there are multiple thread using the heappools.

If you have a “hot” or highly active pool you can get contention when obtaining and releasing blocks from the heap pool. You can define multiple pools for an element size. For example

HEAPP(ON,(56,4),1,280,1,848,1,2080,1,4096,1,0)

The (56,4) says make 4 pools with block size of 56 bytes.

The output has

HEAPPOOLS Summary:                                                          
  Specified Element   Extent   Cells Per  Extents    Maximum      Cells In  
  Cell Size Size      Percent  Extent     Allocated  Cells Used   Use       
  ------------------------------------------------------------------------  
       56       64     1           4         251        1002           2  
       56       64     1           4           0           0           0  
       56       64     1           4           0           0           0  
       56       64     1           4           0           0           0  
      280       288      1           4           1           1           0  
      848       856      1           4           1           1           0  
     2080      2088      1           4           1           1           1  
     4096      4104      1           4           0           0           0  
  ------------------------------------------------------------------------  

We can see there are now 4 pools with cell size of 56 bytes. The documentation says Multiple pools are allocated with the same cell size and a portion of the threads are assigned to allocate cells out of each of the pools.

If you have 16 threads you might expect 4 threads to be allocated to each pool.

How do you know if you have a “hot” pool.

You cannot tell from the summary, as you just get the maximum cells used.

In the report is the count of requests for different storage ranges.

Pool  2     size:   160 Get Requests:           777707 
  Successful Get Heap requests:    81-   88                 77934 
  Successful Get Heap requests:    89-   96                 59912 
  Successful Get Heap requests:    97-  104                 47233 
  Successful Get Heap requests:   105-  112                 60263 
  Successful Get Heap requests:   113-  120                 80064 
  Successful Get Heap requests:   121-  128                302815 
  Successful Get Heap requests:   129-  136                 59762 
  Successful Get Heap requests:   137-  144                 43744 
  Successful Get Heap requests:   145-  152                 17307 
  Successful Get Heap requests:   153-  160                 28673
Pool  3     size:   288 Get Requests:            65642  

I used ISPF edit, to process the report.

By extracting the records with size: you get the count of requests per pool.

Pool  1     size:    80 Get Requests:           462187 
Pool  2     size:   160 Get Requests:           777707 
Pool  3     size:   288 Get Requests:            65642 
Pool  4     size:   792 Get Requests:            18293 
Pool  5     size:  1520 Get Requests:            23861 
Pool  6     size:  2728 Get Requests:            11677 
Pool  7     size:  4400 Get Requests:            48943 
Pool  8     size:  8360 Get Requests:            18646 
Pool  9     size: 14376 Get Requests:             1916 
Pool 10     size: 24120 Get Requests:             1961 
Pool 11     size: 37880 Get Requests:             4833 
Pool 12     size: 65536 Get Requests:              716 
Requests greater than the largest cell size:               1652 

It might be worth splitting Pool 2 and seeing if makes a difference in CPU usage at peak time. If it has a benefit, try Pool 1.

You can also sort the “Successful Heap requests” count, and see what range has the most requests. I don’t know what you would use this information for, unless you were investigating why so much storage was being used.

Ph D level for heap

For high use application on boxes with many CPUs you can get contention for storage at the hardware cache level.

Before a CPU can use storage, it has to get the 256 byte cache line into the processor cache. If two CPU’s are fighting for storage in the same 256 bytes the throughput goes down.

By specifying

HEAPP(ALIGN….

It ensures each block is isolated in its own cache line. This can lead to an increase in virtual storage, but you should get improved throughput at the high end. It may make very little difference when there is little load, or on an LPAR with few engines.

What they don’t tell you about using a REST interface.

After I stumbled on a change to my Python program which gave 10 times the throughput to a Web Server, I realised that I knew only a little about using REST. It is the difference between the knowledge to get a Proof Of Concept working, and the knowledge to run properly in production; it is the difference between one request a minute to 100 requests a second.

This blog post compares REST and traditional client server and suggests ways of using REST in production. The same arguments also apply to long running classical client server applications.

A REST request is a stateless, self contained request which you send to the back-end server, and get one response back. It is also known as a one shot request. Traditional client server applications can send several requests to the back-end as part of a unit of work.

In the table below I compare an extreme REST transaction, and an extreme traditional Client Server

AttributeRESTClient Server
ConnectionCreate a new connection for every request.Connect once, stay connected all day, reuse the session, disconnect at end of day.
Workload BalancingThe request can select from any available server, and so on average, requests will be spread across all connections. If a new server is added, then it will get used.The application connects to a server and stays connected. If the session ends and restarts, it may select a different server.
If a new server is added, it may not be used.
AuthenticationEach request needs authentication. If the userid is invalidated, the request will fail. Note that servers cache userid information, so it may take minutes before the request is
re-authenticated.
Authentication is done as part of the connection. If the userid is invalidated during the day, the application will carry on working until it restarts.
IdentificationBoth userid+password, and client certificate can be used to give the userid.Both userid+password, and client certificate can be used to give the userid. If you want to change which identity is used, you should disconnect and reconnect.
CostIt is very expensive to create a new connection. It is even more expensive when using TLS, because of the generation of the secret key. As a result it is very very expensive to use REST requests.The expensive create connection is done once, at start of day. Successive request do not have this overhead, so are much cheaper
Renew TLS session keyBecause there is only one transfer per connection you do not need to renew the encryption key.Using the same session key for a whole day is weak, as it makes it easier to break it. Renewing the session key after an amount of data has been processed, or after a time period is good practice.
RequestSome requests are suitable for packaging in one request, for example where just one server is involved.This can support more complex requests, for example DB2 on system A, and MQ on system B.
Number of connectionsThe connection is active only when it is used.The connection is active even though it has not been used for a long time. This can waste resources, and prevent other connections from being made to the server.
StatisticsYou get an SMF record for every request. Creating an SMF record costs CPU.You get one SMF record for collection of work, so reducing the overall costs. The worst case is one SMF record for the whole day.

What are good practices for using REST (and Client Server) in production?

Do not have a new connection for every request. Create a session which can be reused for perhaps 50 requests or ten minutes, depending on workload. This has the advantages :

  • You reduce the costs of creating the new connection for every request, by reusing the session.
  • You get workload balancing. With the connection ending and being recreated periodically, you will get the connections spread across all available connections. You should randomise the time a connection is active for, so you do not get a lot of time-out activity occurring at the same time
  • You get the re-authentication regularly.
  • The TLS key is renewed periodically.
  • You avoid the long running connections doing nothing.
  • For a REST request you may get fewer SMF records, for a Client-Server you get more SMF requests, and so more granular data.

How can I do this?

With Java you can open a connection, and have the client control how long it is open for.

With Python and the requests package, you can use

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

res = s.get(geturl,headers=my_header,verify=v,cookies=jar,cert=cpcert)
etc

With Curl you can reuse the session.

Do I need to worry if my throughput is low?

No, If you are likely to have only one request to a server, and so cannot benefit from having multiple requests per connection you might just as well stay with a “one shot” and not use any of the tuning suggestions.

What’s going on? – getting performance data from a z/OS systrace

On my little z/OS system, one address space was using a lot of CPU – but doing nothing. What was going on? The address space was a z/OSMF based on the Liberty Web server.

The blog post tells you how to take a dump, and use IPCS to display useful information from the system trace. The system trace contains deep down information like

  • Task A was dispatched on this processor at this time.
  • It issued a request MVS to get a block of storage, and time.
  • The request completed, with this return code, at this time.
  • Task A was interupted at this time
  • Task B was dispatched

There is a lot of detailed information, and it is overwhelming when you first look at it. This blog post shows how you can get summary information from the trace – while ignoring all of the detailed, scary stuff. It does not require any prior knowledge of IPCS or dumps.

Take your dump

DUMP COMM=(COLINS DUMP)
R xx,jobname=IZUSVR1

This gives output like

IEE600I REPLY TO 01 IS;JOBNAME=IZUSVR1
IEA045I AN SVC DUMP HAS STARTED AT TIME=16.24.56 DATE=06/21/2021 044
FOR ASID (0044) QUIESCE = YES

IEA611I COMPLETE DUMP ON SYS1.S0W1.Z24A.DMP00004

Go into IPCS

I find it easier to use a wide(132) screen for IPCS.

This may be in your ISPF panels, or you might need to issue a command before starting ISPF. You might need to talk to your system programmer.

You get the primary menu

 ------------------- z/OS 02.04.00 IPCS PRIMARY OPTION MENU
 OPTION  ===>                                              
                                                           
    0  DEFAULTS    - Specify default dump and options      
    1  BROWSE      - Browse dump data set                  
    2  ANALYSIS    - Analyze dump contents                 
    3  UTILITY     - Perform utility functions             
    4  INVENTORY   - Inventory of problem data             
    5  SUBMIT      - Submit problem analysis job to batch  
    6  COMMAND     - Enter subcommand, CLIST or REXX exec  
    T  TUTORIAL    - Learn how to use the IPCS dialog      
    X  EXIT        - Terminate using log and list defaults

Select option 0

------------------------- IPCS Default Values ---------------------------------
 Command ===>                                                                   
                                                                                
   You may change any of the defaults listed below.  The defaults shown before  
   any changes are LOCAL.  Change scope to GLOBAL to display global defaults.   
                                                                                
   Scope   ==> LOCAL   (LOCAL, GLOBAL, or BOTH)                                 
                                                                                
   If you change the Source default, IPCS will display the current default      
   Address Space for the new source and will ignore any data entered in         
   the Address Space field.                                                     
                                                                                
   Source  ==> DSNAME('SYS1.CTRACE1')
   Address Space   ==> RBA
   Message Routing ==> NOPRINT TERMINAL NOPDS
   Message Control ==> CONFIRM VERIFY FLAG(WARNING)
   Display Content ==> NOMACHINE REMARK REQUEST NOSTORAGE SYMBOL ALIGN
                                                                                
 Press ENTER to update defaults.                                                
                                                                                
 Use the END command to exit without an update.                                 

Replace the source with DSN(‘your dumpname’).

Change Scope from LOCAL to BOTH

Press enter to update. Use =6 on the command line to get to the IPCS command window.

Enter a free-form IPCS subcommand or a CLIST or REXX exec invocation below: 
                                                                            
===>                                                                        
                                                                            
                                                                            
----------------------- IPCS Subcommands and Abbreviations -----------------
ADDDUMP           | DROPDUMP, DROPD   | LISTDUMP, LDMP    | RENUM,    REN   
ANALYZE           | DROPMAP,  DROPM   | LISTMAP,  LMAP    | RUNCHAIN, RUNC  
ARCHECK           | DROPSYM,  DROPS   | LISTSYM,  LSYM    | SCAN            
ASCBEXIT, ASCBX   | EPTRACE           | LISTUCB,  LISTU   | SELECT          
ASMCHECK, ASMK    | EQUATE,   EQU, EQ | LITERAL           | SETDEF,   SETD  
CBFORMAT, CBF     | FIND,     F       | LPAMAP            | STACK           
CBSTAT            | FINDMOD,  FMOD    | MERGE             | STATUS,   ST    
CLOSE             | FINDUCB,  FINDU   | NAME              | SUMMARY,  SUMM  
COPYDDIR          | GTFTRACE, GTF     | NAMETOKN          | SYSTRACE        
COPYDUMP          | INTEGER           | NOTE,     N       | TCBEXIT,  TCBX  
COPYTRC           | IPCS HELP, H      | OPEN              | VERBEXIT, VERBX 
CTRACE            | LIST,     L       | PROFILE,  PROF    | WHERE,    W     

If you use the command “systrace” you will see the scary internal trace. PF3 out of it.
Use the command

systrace jobname(IZUSVR1) PERFDATA(DOWHERE) time(LOCAL)

Go to the bottom of the report ( type m and press PF8) and type

REPORT VIEW

This gives you the report in an editor session, so you can exclude, delete, sort count etc.

This gives a lot of data. It is in sections, the sections are…FLocal

Summary of the dump

Analysis from 06/21/2021 16:24:46.391102 to 16:24:56.042146 9.651044 seconds 

This gives the time of day, and the interval of the trace is 9.65 seconds.

Summary of CPU usage by engine

CPU  Type Pol  Park   SRB Time              TCB Time             Idle Time           
---- ---- ---- ---- --------------------- --------------------- ---------------------
0000 CP   High No       0.190562   1.974%     0.828988   8.589%     8.603271  89.143%
0001 CP   High No       0.098836   1.024%     0.393259   4.074%     9.143735  94.743%
0002 CP   High No       0.086573   0.897%     0.415063   4.300%     9.136385  94.667%
0003 zIIP High No       0.015463   0.160%     2.227832  23.083%     7.398707  76.662%
0004 zIIP High No       0.000000   0.000%     1.094373  11.339%     8.551280  88.604%
---- ---- ---- ---- --------------------- --------------------- ---------------------
                        0.391434              4.959518             42.833380 

This shows

  • Most of the time was spent in TCB “application thread” mode (4.959 seconds of CPU) rather than SRB “system thread” mode (0.391 seconds of CPU).
  • One ZIIP was busy 23 % of the time, the other ZIIP was busy 11 % of the time.

Summary of CPU overall over 5 engines

 SRB time      :     0.391434 
 TCB time      :     4.959518 
 Idle time     :    42.833380 
 CPU Overhead  :     0.070886 
                 ------------ 
         Total :    48.255220  

This summarises the data

  • 4.95 seconds of CPU in TCB mode in 9.65 seconds of trace
  • 42 seconds idle
  • 5 engines * 9.65 seconds duration = 48.25

CPU break down by ASID/Jobname

CPU breakdown by ASID: 
                                                    
ASID Jobname    SRB Time     TCB Time    Total Time 
---- -------- ------------ ------------ ------------
0001 *MASTER*     0.011086     0.017940     0.029027
0003 RASP         0.000186     0.000000     0.000186
0005 DUMPSRV      0.035545     0.008959     0.044504
0006 XCFAS        0.021590     0.074411     0.096001
...   
0044 IZUSVR1      0.021217     3.638295     3.659513
0045 COLIN        0.000000     0.000000     0.000000
0046 RMF          0.010238     0.020204     0.030442
0047 RMFGAT       0.019961     0.160512     0.180474
              ------------ ------------ ------------
                  0.391434     4.959518     5.350953

Most of the CPU was in ASID 44 for job IZUSVR1.

Breakdown by system thread (SRB) by address space/jobname

SRB breakdown by ASID: (WHERE command bypassed for CPU usage less than 0.100000): 
                                                                                   
ASID: 0001   Jobname: *MASTER* 
IASN      SRB PSW      # of SRBs     Time 
---- ----------------- --------- ------------ 
0001 070C0000 83D0E8A0         2     0.000314 
...  
ASID: 0003   Jobname: RASP 
IASN      SRB PSW      # of SRBs     Time

Ignore this unless the SRB usage was high.

Breakdown of CPU by used thread by address space/jobname


TCB breakdown by ASID: 
                                                   
ASID Jobname  TCB Adr  # of DSPs     Time 
---- -------- -------- --------- ------------ 
0001 *MASTER* 008EDE88         1     0.000535
... 
ASID Jobname  TCB Adr  # of DSPs     Time 
---- -------- -------- --------- ------------ 
0044 IZUSVR1  008C8E88        22     0.013143 
0044 IZUSVR1  008AD7A0        30     0.006694 
0044 IZUSVR1  008B97B8        37     0.015926 
0044 IZUSVR1  008BA3E8        50     0.017547 
0044 IZUSVR1  008B2628        15     0.007748 
0044 IZUSVR1  008C4840        19     0.008433 
0044 IZUSVR1  008BD2D8        20     0.008551 
0044 IZUSVR1  008CDC68        14     0.008107 
0044 IZUSVR1  008C8328        15     0.006540 
0044 IZUSVR1  008CAC68        16     0.006612 
0044 IZUSVR1  008C9E88        14     0.006634 
0044 IZUSVR1  008B5C68        14     0.005668 
0044 IZUSVR1  008CBBE0        28     0.015650 
0044 IZUSVR1  008ADE00        17     0.005861 
0044 IZUSVR1  008B9470        15     0.006014 
0044 IZUSVR1  008BEA48        17     0.017092 
0044 IZUSVR1  008C6CF0        20     0.010093
...
0044 IZUSVR1  008CC2D8       548     0.827491 
0044 IZUSVR1  008D2E88        25     0.445230 
0044 IZUSVR1  008D2510       819     0.412526 
0044 IZUSVR1  008CEE88        14     0.158703
0044 IZUSVR1  008D3E88         8     0.003189 
0044 IZUSVR1  008C4CF0        18     0.013237 
                                 ------------ 
                                     3.638295
  • There were 166 TCB’s which did something in the time period.
  • TCB with address 008D2510 was dispatched 819 times times in 9 seconds – using 0.4 seconds of CPU! This was being dispatched 100 times a second, and used 5 milliseconds of CPU on average per dispatch. This looks high considering the system was not doing any work.
  • TCB with address 008d2E88 was dispatched 25 times in 9 seconds, and used 0.44 seconds of CPU or 17 ms of CPU per dispatch. This is doing more work per dispatch than the previous TCB.

Display lock usage

Lock events for CEDQ   
  None found                
Lock events for CSMF       
  None found               
Lock events for CLAT        
  None found              
Lock events for CMS         
  None found                
Lock events for OTHR        
  None found                

Nothing of interest here.

Display local lock usage – locking the job

Lock events for LOCL of ASID 0010 OMVS 
Lock ASID Jobname  TCB/WEB  Type    PSW Address    IASN  Suspended at    Resumed at     Suspend Time 
---- ---- -------- -------- ---- ----------------- ---- --------------- --------------- ------------ 
CML  0044 IZUSVR1  008C33E8 TCB  00000000_04868084 0010 16:24:49.612051 16:24:49.612076     0.000025 
CML  0044 IZUSVR1  008B4938 TCB  00000000_048687E4 0010 16:24:49.612090 16:24:49.612570     0.000480 
... 
---- ---- -------- -------- ---- ----------------- ---- --------------- --------------- ------------ 
Suspends:      6  Contention Time:     0.000821    0.008%               WU Suspend Time:    0.000823 
                                                                                                        
Lock events for LOCL of ASID 0044 IZUSVR1 
Lock ASID Jobname  TCB/WEB  Type    PSW Address    IASN  Suspended at    Resumed at     Suspend Time 
---- ---- -------- -------- ---- ----------------- ---- --------------- --------------- ------------ 
LOCL 0044 IZUSVR1  008D3E88 TCB  00000000_010CCD62 0044 16:24:46.404417 16:24:46.404561     0.000144 
LOCL 0044 IZUSVR1  008D3E88 TCB  00000000_010ADA78 0044 16:24:46.410188 16:24:46.412182     0.001993
Suspends:     83  Contention Time:     0.042103    0.436%               WU Suspend Time:    0.079177

The LOCal Lock (LOCL) is the MVS lock used to serialise on the address space, for example updating some MVS control blocks. For example if MVS wants to cancel an address space, it has to get the Local lock, to make sure that critical work completes.

  • For the OMVS addess space, address space IZUZVSR1 got the lock 6 times, and was delayed for 0.823 milliseconds waiting for the local lock.
  • For the IZUSVR1 address space, 83 TCBs got the local lock, and were suspended for a total of 79 milliseconds.

Display timer events (CPU Clock comparator CLKC and timer TIMR)

ASID: 0044   Jobname: IZUSVR1 
SRB/TCB  IASN   Interrupt PSW    Count   Where processing 
-------- ---- -------- -------- -------- ----------------------------------------
00000000 0044 070C0000 81D83CB8        2 IEANUC01.ASAXMPSR+00     READ/WRITE NUCLEUS 
...
008CEE88 0044 078D0401 945F2B28       11 AREA(Subpool252Key00)+CB28 EXTENDED PRIVATE 
008CEE88 0044 078D2401 945F99BE        1 AREA(Subpool252Key00)+0139BE EXTENDED PRIVATE 
008CEE88 0044 078D2401 FA63F71E        1 SPECIALNAME+03F71E     EXTENDED PRIVATE 
008CEE88 0044 078D0401 FAB00178        1 SPECIALNAME+0178     EXTENDED PRIVATE 
008CEE88 0044 078D2401 FAB447BE        1 SPECIALNAME+0447BE     EXTENDED PRIVATE 
008CEE88 0044 078D0401 FAD9E660        1 SPECIALNAME+29E660     EXTENDED PRIVATE 
008B17B8 0044 070C0000 81C92030        1 IEANUC01.IAXVP+4048     READ ONLY NUCLEUS 
008B27C0 0044 072C1001 91AF2460        1 BBGZAFSM+7520     EXTENDED CSA 
...
008D2E88 0044 078D0401 945F2B28       22 AREA(Subpool252Key00)+CB28     EXTENDED PRIVATE 
008D2E88 0044 078D0401 FB036F08        1 SPECIALNAME+036F08     EXTENDED PRIVATE 
...
008D2E88 0044 078D0401 FC145732        1 AREA(Subpool229Key00)+A732     EXTENDED PRIVATE 

This displays

  • The TCB
  • The virtual adress where the interrupt occurred
  • These entries are in time sequence, and so we can see the second entry had 11 interupts in quick succession (count is 11).
  • The Where processing, is a guess at converting the address into a module name. Sometimes it works, for example Module IEANUC01, csect ASAXMPSR, offset 0. Sometimes it cannot tell, for example from Java code.

This shows 2 things

  • The application said wake me up in a certain time period
  • The TCB was executing and z/OS interrupted it because it needed to go and dispatch some other work. This gives a clue as to hot spots in the code. If the same address occurs many times – the code was executing here many times. I look in the raw systrace to see if this is a TIMer (boring) or a CLKC interesting. Interesting gives you a profile of what code is CPU intensive.
  • You can delete all the records outside of this block, then sort 15 32 to sort on PSW address. For my IPCS dump the address 078D0401 945F2B28 occurred 35 times.

I/O activity

 Device   SSCH Issued    I/O Occurred     Duration   
 ------ --------------- --------------- ------------ 
  0A99  16:24:48.009819 16:24:48.010064     0.000244 
  0A99  16:24:48.033619 16:24:48.033856     0.000236 
  0A99  16:24:48.051014 16:24:48.051081     0.000066 
  0A99  16:24:48.057377 16:24:48.057434     0.000056 
  0A99  16:24:48.080331 16:24:48.080430     0.000098 
                                        ------------ 
                                            0.000702 
                                                     
    Events for 0A99 :            5                   
    Quickest I/O    :     0.000056                   
    Slowest  I/O    :     0.000244                   
    Total           :     0.000702                   
    Average         :     0.000140                   

This says for the device 0A99 there were 5 I/O requests, total time 0.7 milliseconds

  • I used the REPORT VIEW to get the data into ISPF edit,
  • deleted all the records above the I/O section
  • Used X ALL
  • F TOTAL ALL
  • This shows the totals for all I/Os. Most totals were under 1 ms. One I/O was over 5 seconds.
  • Displaying the detailed records above this TOTAL record showed one I/O took over 5 seconds!

End of report

End of PERFDATA analysis.

Advanced topic: Look at hot spots

I had seen that PSW 078D0401 945F2B28 was hot. If you go back to the IPCS command panel, you may be able to use the command

L 945F2B28

To display the storage. This will not work. You have to remove the top bit (80), so

L 145F2B28

may work.

If the first character is a letter (A-F) then you need to put a 0 on the front for example

L 0D2345678

You might need to put the address space in as well for example

L 145F2B28 ASID ID(x’44’)

You can say

L 145F2B28 ASID ID(x’44’) LENGTH(4096)

To display large sections of storage

Dig into the trace

You can use

systrace jobname(izusvr1)tcb(x’008CC2D8′)

to display all entries for the specified TCB and jobname.

  • Go to the bottom ( type Max press PF8)
  • use the report view command to get into and edit session
  • Columns 79 to 88 contain a description of some of the system calls
  • use X ALL;f ‘ ‘ 79 84 all;del all nx to delete all lines without a description

This gives you a picture of the MVS services being used.

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.