Not for humans, but for search engines – Java messages and codes

I hit these messages when doing some Java work. Ive added more information to the messages. I expect people will only get to this page from a web search.

EDC messages

EDC5129I No such file or directory.

Also ENOENT error code 129.

This is not strictly true. When using semget() this code means the userid does not have access to it. Perhaps EACCESS code would have been better.

Java shared classes.

JVMSHRC336E Port layer error code = …

For example JVMSHRC336E Port layer error code = -197360. -197360 is 0xfffC FD10

From the first half word you can tell the external function which caused the problem

FTOK   FFFD
SEMGET FFFC
SEMCTL FFFB
SEMOP FFFA
SHMGET FFF9
SHMCTL FFF8
SHMAT FFF7
SHMDT FFF6
GETIPC FFF5

See here for the code saying…

  • EACCESS FD12 -Permission is denied.
  • EEXIST FD11 -The file exists.
  • ENOENT FD10 – No such file, directory, or IPC member exists.
  • EINVAL FD0F – The parameter is incorrect.
  • ENOMEM FD0E – Not enough space is available (I think this means virtual storage).
  • ENOSPC FD0D -No space is left on the device, or no space is available to create the IPC member ID.
  • ELOOP FD0C – A loop is encountered in symbolic links.
  • ENAMETOOLONG FD0B – The file name is too long.
  • ENOTDIR FD0A – Not a directory.
  • EPERM FD09 -The operation is not permitted.
  • ERANGE FD08 -Result is too large.
  • E2BIG FD07 – The parameter list is too long, or the message to receive was too large for the buffer.
  • EAGAIN FD06 – The resource is temporarily unavailable.
  • EFBIG FD05 – The file is too large.
  • EIDRM FD04 – Identifier removed.
  • EINTR FD03 – A function call is interrupted.
  • EMFILE FD02 – Too many files are open for this process.

So JVMSHRC336E Port layer error code = -197360 is 0xfffC FD10 which is SEMGET ENOENT .

One’s I have hit

  • -197359 is 0xfffC FD11 which is SEMGET EEXIST -The file exists.
  • -197360 is 0xfffC FD10 which is SEMGET ENOENT – No such file, directory, or IPC member exists.
  • –262894 is 0xfffb FD12 which is SEMCTL EACCESS – Permission denied.
  • -328433 is 0fffa FD0F which is SEMOP – The parameter is incorrect.
  • -393968 is 0xfff9 fd10 which is SHMGET EPERM -The operation is not permitted.
  • -459502 is 0xfff8 FD12 which SHMCTL EACCESS -Permission is denied.

JVMSHRC337E Platform error message: EDC5132I Not enough memory. (errno2=0x072B06AB)

The errno 072b06ab says


JRMmapMaxShareFail: A map request is attempted but the total share pages exceeds the MAXSHARE limit
Action: Ensure mmap usage does not exceed MAXSHARE limits.

You need to ensure that your system has the SMFLIMxx parmlib updates. This is a requirement for the ibmjava:8 container image in order to support caches mapped above the 2 GB address range. The maximum size of these caches are limited by the MAXSHARE value within the SMFLIMxx PARMLIB member.

Issue

D SMFLIM

to see what limits you have defined.

I had NO SMF LIMITS ARE IN EFFECT.

JVMSHRC020E An error has occurred while opening semaphore
JVMSHRC336E Port layer error code = -262894

JVMSHRC337E Platform error message: semctl : EDC5111I Permission denied. (errno2=0x070E0303)
JVMSHRC028E Permission Denied
JVMSHRC840E Failed to start up the shared cache.
JVMJ9VM015W Initialization error for library j9shr29(11): JVMJ9VM009E J9VMDllMain failed
Error: Could not create the Java Virtual Machine

-262894 is SEMCTL EACCESS – Permission denied.

The owner of the shared file cache was not the userid trying to use it.

chown ZWESVUSR:SYS1 *

Changed the files, such as

ZWESVUSR SYS1     314572800 Feb  9 08:43 C290M17F1A64S_zoweGW_G43L00                   
ZWESVUSR SYS1 32 Feb 10 06:35 C290M17F1A64_semaphore_zoweGW_G43L00
ZWESVUSR SYS1 40 Feb 10 06:35 C290M17F1A64_memory_zoweGW_G43L00

JVMSHRC020E An error has occurred while opening semaphore
JVMSHRC336E Port layer error code = -197360

JVMSHRC337E Platform error message: semget : EDC5129I No such file or directory.

-197360 is SEMGET ENOENT – No such file, directory, or IPC member exists.

I got these trying to restore a sharedclasses cache, when I did not have access to the file.

/usr/lpp/java/J17.0_64/bin/java -Xshareclasses:cacheDir=/u/tmp/zowec,name=zoweGW,restoreFromSnapshot

I gave the userid access and it worked

chmod 777 /u/tmp/zowec/javasharedresources/*

JVMSHRC659E An error has occurred while opening shared memory
JVMSHRC336E Port layer error code = -459502


JVMSHRC337E Platform error message: shmctl : EDC5111I Permission denied.
JVMSHRC028E Permission Denied
JVMSHRC626I The stats of the shared cache cannot be obtained since a valid shared cache does not exist.
JVMJ9VM015W Initialization error for library j9shr29(11): JVMJ9VM009E J9VMDllMain failed

-459502 is SHMCTL EACCESS -Permission is denied.

The userid issuing the command does not have access to the resource.

The documentation says the shared class cache is created with ONLY USER read/write access by default unless the groupAccess command-line suboption is used, in which case the access is read/write for user and groups.

Note: Users with super user authority gid=0(SYS1) can issue the command with no additional authority.

To find the group list the directories containing the cache, for example if /var/zosmf/data/logs/.classCache/ was specified use ls -ltr /var/zosmf/data/logs/.classCache/javasharedresources.

For me it had owner IZUSVR group IZUADMIN.

I used the RACF command connect COLIN group(IZUADMIN) to connect the userid to the group. Even then the command failed, because groupAccess had not been defined on the -Xshareclasses… parameter. I had to delete the cache so it was recreated next time theJVM started. Then the java -Xshareclasses:cacheDir=/var/zosmf/data/logs/.classCache,name=liberty-IZUSVR,verbose,printStats worked.

JVMSHRC023E   Cache does not exist

I had

-Xshareclasses:cacheDir=/javasc,name=izusvr1cache,printStats

I had to remove the printStats.

JVMSHRC364E SH_OSCachesysv::acquireWriteLock() call to j9shsem_wait on semid … has failed with error -328433.

-328433 is SEMOP – The parameter is incorrect.

You can use the ipcs Unix commands to display the semaphore ids.

JVMSHRC005I No shared class caches available

I was using

/usr/lpp/java/J11.0_64/bin/java -Xshareclasses:cacheDir=/global/zosmf/data/logs/.classCache/,verbose,listAllCaches

to display information about shared cache usage, and kept getting the JVMSHRC005I No shared class caches available message. I experienced two reasons for this.

  1. The information in the file, was for last week’s IPL, and the the information in today’s memory was invalid.
  2. I was using the wrong level of Java. Once I used the right level of Java it worked!

restoreFromSnapshot

IBMUSER:/u/ibmuser: >cd /u/tmp/zowec
IBMUSER:/u/tmp/zowec: >/usr/lpp/java/J17.0_64/bin/java -Xshareclasses:cacheDir=/u/tmp/zowec,name=zoweGW,restoreFromSnapshot
JVMSHRC020E An error has occurred while opening semaphore
JVMSHRC336E Port layer error code = -197360
JVMSHRC337E Platform error message: semget : EDC5129I No such file or directory.
JVMSHRC727E An error has occurred in creating the new non-persistent shared cache

JVMSHRC808I Compressed references shared cache “zoweGW” is destroyed. Use option -Xnocompressedrefs if you want to destroy a non-com pressed references cache.
JVMSHRC699E Failed to restore the non-persistent shared cache “zoweGW” from the snapshot

This may be connected to the the following

The following files were in the directory

-rw-r--r-- 1 ZWESVUSR ZWEADMIN ... C290M17F1A64_semaphore_zoweGW_G43L00
-rw-r--r-- 1 ZWESVUSR ZWEADMIN ... C290M17F1A64_memory_zoweGW_G43L00

For example the above files were had owner: ZWESVUSR group: ZWEADMIN.

The userid was in group ZWEADMIN, and so does not get R/W access to the files.

Errno2

  • 0x071D0303: JRIpcDenied: Access was denied because the caller does not have the correct permission.
  • 0x053b006c: JRFileNotThere: The requested file does not exist
  • 0x0594003d: JRDirNotFound: A directory in the pathname was not found

Java Health center messages

Health center Non IBM version of Java Health Center client

I got this when connecting the Health Center on Eclipse to a Liberty server. I think the message really means, unable to connect to the port.

The TSO command tso netstat allconn did not show it was active.

Setting up Java shared cache support on z/OS

With Java shared cache support, Java stores classes and JIT information in shared memory, so it can be reused by other Java applications, or it the application is restarted.

Some other shared classes blog posts

You can use the Java command snapshotCache to save the shared buffer to disk, and restoreSnapshot to restore from disk to recreate the shared memory.

For my Zowe startup I use Java start-up option

-Xshareclasses:verboseIO,verbose,name=zoweGW,cacheDirPerm=0777,cacheDir=/u/tmp/zowec/

Before you start you need to consider

  • Sharing the shared classes cache
  • Which directory to use
  • What name to use
  • How big
  • Processes to save the cache to disk
  • Read only?

Sharing the shared classes cache

Java uses a semaphore when updating the shared classes cache. I believe that multiple Java instances can share the cache, so products which have multiple address spaces can share the same cache if they are using the same level of Java.

I believe you could use one shared classes directory for all your Java applications, Liberty, z/OSMF, zOS Connect, Zowe etc. I haven’t found any documentation to say you cannot share it, but the application’s userid needs access to the cache, and so may need the same userid, or be in the correct group to be able to access the cache, and ipc memory and semaphores. The Zowe address spaces all use the same userid, so all have access to the cache.

To further complicate it…

You can run more than one JVM within a CICS address space, they can all use the same cache.

To be able to destroy and recreate a cache (for example to make it larger ), the cache cannot be in use. For availability you may want multiple caches so you do not need to shutdown all CICS regions to be able to recreate it. As all Zowe address spaces start and stop together, they can use a shared classes cache.

Which directory to use?

If you do not specify a cachDir, it defaults to /tmp. This is OK – but some on some z/OS systems, the /tmp directory is emptied on a regular basis. This means your cache is deleted, and it needs to be recreated next time your application starts.
For Zowe I used /u/tmp/zowec.

What name to use?

If you do not specify a name it takes the userid of the application, as part of the file name.

Within my cacheDir, it creates a directory javasharedresources. Within this directory I have files

  • C290M21F1A64S_zoweGW_G43L00 with size 83886080 (84MB) this is the hardened copy of the cache
  • C290M21F1A64_semaphore_zoweGW_G43L00 with size 32
  • C290M21F1A64_memory_zoweGW_G43L00 with size 40

Where the …M21F… is the level ofJava.

When I use the printStats command, it gives the cache size as 84MB.

How big?

I specified
-Xscmx80m
-Xscmaxaot180m
-Xscmaxjitdata30m

Once you have specified the size, you cannot change it unless you delete and recreate the cache, so you need to get it right before you start. Make it too large, rather than too small. Restoring it from a snapshot will use the size when the snapshot was taken.

Processes to save the cache to disk.

As part of your application shutdown you could snapshot the cache to a file. See here (tba).

Processes to save the cache to disk.

You might want to restore the cache from disk as part of your IPL processing, or as part of application start up. If the cache already exists it is not overwritten. It takes a few seconds to snapshot or restore. See here(tba).

Clean up the shared classes

If you delete the ipc shared memory, and the ipc semaphore before you start your Java application, will rebuild the shared classes – though this will take longer as all of the classes need to be read and processed.

Read only

If Java detects that the shared classes cache is out of date, it will updates the shared classes cache.

Once you created and populated a shared classes cache, you can specify readOnly, to prevent updates to it

Introduction to Java Shared classes on z/OS

Java shared classes provides the facility for Java to store classes, and JITted classes in shared memory which persists across the restart of a Java application. You can harden this shared memory to disk, and reload it after an IPL.

If shared classes are being used, then as the JVM starts it looks for the classes in the shared cache, and if not found, loads them from the file system, processes them and stores them in the shared classes memory. With this scheme, the second start of the JVM gains from the shared classes.

See the introduction documentation and some practical documentation.

Background

To support the use of the shared memory, Java uses standard facilities for shared memory, and for semaphores (to ensure single threading of updates).

I have my shared classes in directory /u/tmp/zowec. When the shared classes are used, two files are created.

  • javasharedresources/C290M17F1A64_semaphore_zoweGW_G43L00
  • javasharedresources/C290M17F1A64_memory_zoweGW_G43L00

Listing them gives

672 -rw-r--r--   1 ZWESVUSR ZWEADMIN ... C290M17F1A64_semaphore_zoweGW_G43L00  
673 -rw-r--r-- 1 ZWESVUSR ZWEADMIN ... C290M17F1A64_memory_zoweGW_G43L00

The files are owned by userid ZWESVUSR and group ZAWADMIN from my started task userid. The semaphore file has an inode of 672 (0x2a0), and the shared memory file has an inode of 673(0x2a1).

The shared memory and semaphores use InterProcess Communication (ipc) facilities.

The id in hex of the files is used as part of the ipc key.

The command ipcs gave

Shared Memory:                                                
T ID KEY MODE OWNER GROUP
m 204805 0x6102a131 --rw------- ZWESVUSR ZWEADMIN

Semaphores:
T ID KEY MODE OWNER GROUP
s 200708 0x8102a031 --ra------- ZWESVUSR ZWEADMIN

These resources are owned by userid:ZWESVUSR, and group:ZWEADMIN. The userid and group comes from the userid that created the shared classes cache.

If you need to “clean up” you can delete these using the ipcrm command.

Why can’t Java find my class?

I had specified a classpath to load a class loading program, but my program could not be found.

I specified the Java options -XshowSettings.

The value of java.class.path had just one .jar, and did not include my classpath!

I found in some Oracle documentation

When you use -jar, the specified JAR file is the source of all user classes, and other class path settings are ignored. If you’re using JAR files, then see jar.

Simple – once you know…

How to fix it

I added my class to the Jar

/usr/lpp/javaJ21.0_64/bin/jar uf /u/tmp/zowep/components/gateway/bin/gateway-service.jar -C /u/tmp/java CCLoader.class

My class was found – and it worked!

What’s going on inside my Java program?

You can use the IBM healthcenter to get information from what is running within Java.

I used Java startup option

-Xhealthcenter
-Dcom.ibm.diagnostics.healthcenter.headless=on
-Dcom.ibm.java.diagnostics.healthcenter.data.collection.level=headless
-Dcom.ibm.java.diagnostics.healthcenter.headless.files.max.size=50000000
-Dcom.ibm.java.diagnostics.healthcenter.headless.delay.start=1
-Dcom.ibm.java.diagnostics.healthcenter.headless.output.directory=/u/tmp/zowe
-Dcom.ibm.diagnostics.healthcenter.readonly=on
-Dcom.ibm.diagnostics.healthcenter.logging.level=fine
-Dcom.ibm.diagnostics.healthcenter.jmx=off
-Dcom.ibm.java.diagnostics.healthcenter.agent.transport=jrmp
-Xtrace:buffers={2m,dynamic}

which are described here.

I used -Dcom.ibm.java.diagnostics.healthcenter.headless.delay.start=1 to wait for a minute before recording, so I didn’t get the Java startup information.

When I started the Java program I got out messages

com.ibm.diagnostics.healthcenter.headless INFO: Headless data collection has started 
com.ibm.diagnostics.healthcenter.headless INFO: Agent will keep last 5 hcd files
com.ibm.diagnostics.healthcenter.headless INFO: Headless collection output directory is /u/tmp/zowec

Shutdown the Java program.

I got a file healthcenter080225_160620_33620365_1.hcd in /u/tmp/zowec.

Download this in binary to your workstation.

Start Eclipse. Window-> Perspective-> Open Perspective-> Other-> Health center profiling

File-> Load Data… Select your downloaded file.

From the status window you can select different views of the data

Method profiling

This display information like

  • Under Tree%this says 18.49 of the time was spent in this class…. including other classes it called
  • Under Self% this is the amount of time spent within just this class. 9.86 of the total time was spent within this class. 15.75 of the total time was spent in just this class. It was recorded in 1617 sample
  • If you select a line, in another part of the display it shows you what called it, and what it called.

CPU

Shows the amount of CPU used over time

Classes

Shows time from start when classes were loaded, and if they were shared classes or not,

Environment

Give you the start option, and information about the JVM

Garbage collection

Gives you a profile and other information on garbage collection

IO

Gives you information about IO. My display said “Your application has opened 45 files and closed 39 files.” It did not tell me which files were opened – it just showed the 6 which were still open, so not very useful!

What’s -Djava.security.auth.debug ever done for us?

I could not find any documentation on what the Java command option java.security.auth.debug provides. In this blog post I enabled it an give examples of the output.

The command

java -Djava.security.auth.debug=help

lists all of the options

all           turn on all debugging 
access        print all checkPermission results 
certpath      PKIX CertPathBuilder and 
              CertPathValidator debugging 
combiner      SubjectDomainCombiner debugging 
gssloginconfig 
              GSS LoginConfigImpl debugging 
configfile    JAAS ConfigFile loading 
configparser  JAAS ConfigFile parsing 
jar           jar verification 
logincontext  login context results 
jca           JCA engine class debugging 
policy        loading and granting 
provider      security provider debugging 
pkcs11        PKCS11 session manager debugging 
pkcs11keystore 
              PKCS11 KeyStore debugging 
sunpkcs11     SunPKCS11 provider debugging 
scl           permissions SecureClassLoader assigns 
ts            timestamping 
                                                                          
The following can be used with access: 
                                                                          
stack         include stack trace 
domain        dump all domains in context 
failure       before throwing exception, dump stack 
              and domain that didn't have permission 
thread        include the thread name 
                                                                          
The following can be used with stack and domain: 
                                                                          
permission=<classname> 
              only dump output if specified permission 
              is being checked 
codebase=<URL> 
              only dump output if specified codebase 
              is being checked 
permname=<name> 
              only dump output if the specified name
              matches the permission getName() 
permactions=<actions> 
              only dump output if the specified actions 
              matches the permission getActions() 
                                                                  
The following can be used with provider: 
                                                                  
engine=<engines> 
              only dump output for the specified list 
              of JCA engines. Supported values: 
              Cipher, KeyAgreement, KeyGenerator, 
              KeyPairGenerator, KeyStore, Mac, 
              MessageDigest, SecureRandom, Signature. 
                                                                  
Note: Separate multiple options with a comma  

It works with the -Dlog.level option. For example with

-Dlog.level=FINER

It gives information like

04-Sep-2023 08:16:32.820 FINER [main] com.ibm.security.x509.AlgorithmId.algName ENTRY
04-Sep-2023 08:16:32.832 FINER [main] com.ibm.security.x509.AlgorithmId.algName_46 RETURN SHA-256

This is a request to return the algName and it returns the value SHA-256

...com.ibm.crypto.provider.RACFInputStream.RACFInputStream ENTRY START1 MQRING null 
...com.ibm.crypto.provider.RACFInputStream.getEntries ENTRY START1 MQRING 
...com.ibm.crypto.provider.RACFInputStream.getEntries key = NEWTECCTEST 
...com.ibm.crypto.provider.RACFInputStream.getEntry ENTRY {NEWTECCTEST=[B@be879fff [B@358
...com.ibm.security.x509.X509CertImpl.X509CertImpl ENTRY [B@d6d840cb IBMJCE 

=certpath -Dlog.level=FINER

certpath: Constraints: MD2 
certpath: Constraints: MD5 
certpath: Constraints: RSA keySize < 1024 
...
certpath: Constraints.permits(): SHA-256, [ 
  Variant: generic 
  Certs Issued by Anchor: 
    Cert Issuer: CN=IBM Java Security CA, OU=IBM Java Security, O=IBM Corporation, C=US 
    Cert Subject: CN=IBM Java Security CA, OU=IBM Java Security, O=IBM Corporation, C=US 
    Cert Issuer: CN=USERTrust RSA Certification Authority, O=The USERTRUST Network, L=Jersey City, ST=New Jersey, C=US 
    Cert Subject: CN=Sectigo RSA Time Stamping CA, O=Sectigo Limited, L=Salford, ST=Greater Manchester, C=GB 
  Key: RSA 
  Key: RSA 
  Timestamp: Tue Jan 31 18:30:31 GMT+01:00 2023 
] 

=pkcs11,pkcs11keystore -Dlog.level=FINER

 FINER [main] KeyStoreDelegator.engineLoad Loaded a keystore in JKS format 

=jca -Dlog.level=FINER

ProviderConfig: Loading provider: com.ibm.jsse2.IBMJSSEProvider2 
ProviderConfig: Loaded provider IBMJSSE2 version 1.8 
ProviderConfig: Loading provider: com.ibm.crypto.provider.IBMJCE 

=provider -Dlog.level=FINER

Provider: IBMJSSE2.putService(): IBMJSSE2: TrustManagerFactory.IbmX509 -> com.ibm.jsse2.bk$b.
Provider: Set BootstrapProvider provider property [KeyFactory.RSA/com.ibm.security.bootstrap.RSAKeyFactory]
Provider: MessageDigest.SHA-384 algorithm from: BootstrapProvider
Provider: KeyStore.JCERACFKS type from: IBMJCE   

Then for each session that connected

Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: KeyPairGenerator.EC algorithm from: IBMJCE 
Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: MessageDigest.SHA-256 algorithm from: IBMJCE 
Provider: KeyPairGenerator.EC algorithm from: IBMJCE 
Provider: Signature.SHA384withECDSA signing algorithm from: IBMJCE 
Provider: SecureRandom.NativePRNG algorithm from: IBMJCE 
Provider: Signature.SHA384withECDSA signing algorithm from: IBMJCE 
Provider: SecureRandom.NativePRNG algorithm from: IBMJCE 

=logincontext -Dlog.level=FINER

This produced no trace output. I expect this is because the Java logincontext was not used by Apache Tomcat.

=configparser -Dlog.level=FINER

Nothing.

Solving certificate problems in Java on z/OS

I spent many any hour trying to understand why z/OSMF was getting a message saying certificate not found in keyring, when it was always there when I checked it.

I tried Java trace options but they did not help. I have my own Java program, and that gave me a message from IRRSDL00 (the callable service to access keyrings). But when I did a RACF GTF trace to get see what was going on I got no entries in the trace. Weird. Once I solved the problems, the solution was obvious.

My Java program reported

java.io.IOException: The private key of NEWTECCTEST is not available or no authority to access the private key

z/OSMF report

[ERROR ] CWPKI0024E: The NISTECCTEST certificate alias specified by the attribute serverKeyAlias is either not found in KeyStore safkeyring://START1/MQRING or it is invalid.

The problem and the solution

The message The private key … is not available or no authority to access the private key. Has a hint as to the problem. The documentation is hidden away. It was not as bad as

It was on display in the bottom of a locked filing cabinet stuck in a disused lavatory with a sign on the door saying ‘Beware of the Leopard.”

but it is not easy to find. It says

Applications can call the R_datalib callable service (IRRSDL00) to extract the private keys from certain certificates after they have access to the key ring. A private key is returned only when the following conditions are met:

  1. For RACF real key rings:
    • User certificates An application can extract the private key from a user certificate if the following conditions are met:
      • The certificate is connected to the key ring with the PERSONAL usage option.
      • One of the following two conditions is true:
        • The caller’s user ID is the user ID associated with the certificate if the access to the key ring is through the checking on IRR.DIGTCERT.LISTRING in the FACILITY CLASS, or
        • The caller’s user ID has READ or UPDATE authority to the <ringOwner>.<ringName>.LST resource in the RDATALIB class. READ access enables retrieving one’s own private key, UPDATE access enables retrieving other’s.

I had a keyring START1.MQRING and the start task userid had read access to it. Within the keyring was the certificate NISTECCTEST owner by userid START1. The started task userid needs UPDATE access to the keyring to be able to access the private key belonging to a different userid.

Reasons for “not found” reason code

Under the covers the callable server IRRSDL00 is called. The reason code are documented here. You might get SAF return code 8, RACF return code 8, RACF reason code 44.

  • The certificate was not in the keyring
  • It was NOTRUST
  • It had expired
  • The CA for the certificate was not in the keyring,
  • The userid did not have update access to the keyring when there are private certificates from other userids.

Java and z/OS keyrings – unlocking the puzzle

I had been trying to follow some instructions on how to use a z/OS keyring in a Java application, but I was having lots of error messages and little success. Searching the internet did not help because most of the documentation on the internet does not tell you what version of Java they were using; but fortunately I managed to stumble on the magic combination of options which worked.

I ended up with one of my configuration files with information for Java 8 and Java 11, which I had to clean up.

There are several pieces of the puzzle, all which have to be right.

  • Recent Java versions were better than old ones. Java V8 SR8 FP6 from 2023 was better than Java V8 SR6 FP19 from 2020
  • The java.security file; this contains the master set of security definitions for the system. Your application can override options within this file, or use a totally different file
  • Which jar file to use.
  • Which classes to use – specifying the high level qualifier
  • How you specify your keyring for example safkeyring://START1/MQRING, or safkeyringjce://START1/MQRING
  • Which Java start up overrides your Java program uses.

What worked for me

On Java 8 the following are typical default values

  • -Djava.protocol.handler.pkgs=com.ibm.crypto.provider
  • -Djavax.net.ssl.keyStoreType=JCERACFKS
  • -Djavax.net.ssl.keyStore=safkeyring://START1/MQRING

Because I was using Apache Tomcat web server, some of the definitions were taken from the server.xml file, and override the -Djavax.net.ssl.keyStoreType and -Djavax.net.ssl.keyStore parameters.

RSEAPI_KEYSTORE_FILE="safkeyring://START1/MQRING " 
RSEAPI_KEYSTORE_TYPE="JCERACFKS" 

The Java security file.

The default file is /usr/lpp/java/J8.0/lib/security/java.security or /usr/lpp/java/J8.0_64/lib/security/java.security depending on which JVM you are using (31 bit or 64 bit).

You can override this using

  • -Djava.security.properties==/etc/zexpl/java.security to specify which file to use instead of the default file.
  • -Djava.security.properties=/etc/zexpl/java.security for entries in the specified file to override the entries in the default file.

The content of interest is like

security.provider.1=com.ibm.jsse2.IBMJSSEProvider2
security.provider.2=com.ibm.crypto.provider.IBMJCE
security.provider.3=com.ibm.crypto.plus.provider.IBMJCEPlus
security.provider.4=com.ibm.security.jgss.IBMJGSSProvider
security.provider.5=com.ibm.security.cert.IBMCertPath
security.provider.6=com.ibm.security.sasl.IBMSASL

I’ll explain what this means below.

Which classes – the high level qualifier

This is defined like -Djava.protocol.handler.pkgs=com.ibm.crypto.provider

This usage is explained below.

How Java loads things

My explanation below may be wrong – but it should give the concepts.

  • By some magic Java know which classes are in which jars. (Java may look in every jar at startup).
  • My keying is defined as safkeyring://START1/MQRING.
  • I have -Djava.protocol.handler.pkgs=com.ibm.crypto.provider
  • Java combines this information and looks through the classes for com.ibm.crypto.provider.safkeyring.Handler class.
  • It finds the class in /usr/lpp/java/J8.0/lib/ext/ibmjceprovider.jar

If there are more than one potential class, it take the in the Jar file in the security.provider.n list.

When I used –Djava.protocol.handler.pkgs=com.ibm.crypto.hdwrCCA.provider, it searched for class com.ibm.crypto.hdwrCCA.provider.safkeyring.Handler which was in /usr/lpp/java/J8.0_64/lib/ext/ibmjcecca.jar .

When I used -Djava.protocol.handler.pkgs=com.ibm.crypto.hdwrCCA.provider, initially I got an ICSF security violation ( which was good news as it showed I was using ICSF). Once I fixed the security problem I got a Java exception

org.apache.catalina.LifecycleException: Protocol handler initialization failed 
Caused by: java.lang.IllegalArgumentException: Invalid keystore format 
Caused by: java.io.IOException: Invalid keystore format

There is documentation but I could not get round this problem

If I stopped ICSF (p CSF) I got Java exceptions

java.security.NoSuchAlgorithmException: no such algorithm: EC for provider IBMJCECCA 

What did not work for me

IBMJCEPlus

There was a reference which said in order to use TLS V1.3 you need to use IBMJCEPlus.

I overrode the java.security file by using

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

but this gave a Java exception

java.security.ProviderException: Could not load dependent library

which looks like it could not load a load module (.so) from the file system.

Upgrading the Java fixpack worked for me

I upgraded the level of Java V8 from 2020 to a 2023 version, going from fix pack16 to fix pack 25, and lots of problems went away.

Java 11

Java 11 has different provider of the keyring support.

security.provider.1=OpenJCEPlus
security.provider.2=IBMZSecurity
security.provider.3=SUN
security.provider.4=SunRsaSign
security.provider.5=SunEC
security.provider.6=SunJSSE
security.provider.7=SunJCE
security.provider.8=SunJGSS
security.provider.9=SunSASL
security.provider.10=XMLDSig
security.provider.11=SunPCSC

I did not try to use these, as the application I was using did not support Java 11.

There is some documentation on Java 11 and security.

LPA for Unix System Services .so modules

I discovered a shared library facility for loading OMVS modules (for example .so) into storage which can be shared by all OMVS address spaces.

This is an unusual blog, in that I’ve written about a topic – then say “do not use it!

Phil Wakelyn of CICS strategy said….

The UNIX shared library region, this is not something we currently recommend – see this doc, and its now disabled by default in CICS at the JVM level using the variable

_BPXK_DISABLE_SHLIB=NO

The reasons  for this is that that:

  • It has negligible difference on JVM startup time
  • It has a substantial negative impact on virtual storage below the bar, as storage is allocated from the high private area in MB chunks for each library (dll), so there is lots of wasted space and you can quickly use up 100MB or more. This has been a large customer support issue for CICS customers where space is very tight below the bar and MVS private storage SOS conditions are fatal.
  • Shared libraries are loaded once per address space, so are cached at the address space level

Where are modules stored?

They are stored in a common area below the 31 bit line – so taking storage from all regions.

If you issue the command

D OMVS,L

it gives

BPXO051I 10.32.34 DISPLAY OMVS 293                              
OMVS     0010 ACTIVE             OMVS=(00,01,BP,IZ,RZ,BB,ZW,PY) 
SYSTEM WIDE LIMITS:         LIMMSG=NONE                         
                  CURRENT  HIGHWATER     SYSTEM                 
                    USAGE      USAGE      LIMIT                 
...               
SHRLIBRGNSIZE    58720256   65011712   67108864   
SHRLIBMAXPAGES          0          0     409600 *  

I made it larger than the default (4096) by using the operator command

SETOMVS SHRLIBMAXPAGES=409600

How do you load modules into the shared region?

You need to set the extended attribute +l for example

extattr +l /usr/lpp/java/J8.8_64/J8.0_64/bin/j9vm/libdbgwrapper80.so

When this module is loaded, it will be loaded into the shared region – if there is enough space.

Be careful how you reference the modules

You should use a consistent reference to files. For example

/usr/lpp/java/J8.8_64/libj9a2e.so is the same file as /Z24C/usr/lpp/java/J8.8_64/libj9a2e.so, but the shared library will treat them as two different objects, and load both of them. This will waste space.

How do you unload a module from the shared region

I reset the attribute using extattr -l. This did not unload it. When it was next loaded, it appeared to be unloaded from the shared region, and the file on disk was used.

How do you know what is in the shared region?

There is no IBM answer. There is a rexx exec OMVS command written by an IBMer

The syntax is

wjsigshl -p

This gives output

Usage  Meg Used-Unused-Pgs Pathname 
    1    1       8     248 647857ED xxx/libracfimp.so 
...
    1   25    6349      51 647857EC xxx/compressedrefs/libj9jit29.so 
...
 Total Storage (Meg)             60 
 Total Module (Pages)         10146 
 Total Unused (Pages)          5214 
 Total Module Count              28 

I changed /Z24C/usr/lpp/java/J8.8_64/J8.0_64/lib/s390x to xxx so the output would fit within the area.

Each modules gets storage in multiples of 1MB, so you waste space with small objects.

The used pages does not tie up directly with the size of the object on disk. For example for libjgsk8iccs_64.so

  • using ls -ltr the size is 913408
  • from the shared region mapping information is it 379648

It may be that there is information in the disk version which is not needed once the module is loaded.

How much space do I need?

I set the +l attribute for all of the .so objects in Java V8 SR 8. When I ran my Java program (which uses TLS) there were 28 modules loaded, and 60 MB of data used.

How do I turn it off for a job?

For your job, you can use the environment variable

_BPXK_DISABLE_SHLIB=YES

The documentation says

System shared libraries are disabled. When loading a program with the system shared library extended attribute (st_sharelib), the attribute is ignored and the program is loaded into the caller’s private storage. The _BPXK_DISABLE_SHLIB setting is propagated on both fork and spawn from the parent to the child process.

End words

Now you know how it works – do not use it.
I asked on one of the z/OS news groups if anyone used this facility and unusually I got no replies. It looks like it is not used in the z/OS community.

Turbo start your Java program on z/OS and save a bucket of CPU

This blog post follows on from Some of the mysteries of Java shared classes and gives some CPU figures.

This should help you with any of the Java applications running on z/OS, such as z/OSMF, z/OS Connect, MQWEB, RSEAPI, and ZOWE.

I ran the scenarios on z/OS on zPDT running on my Ubuntu Linux machine, and so the figures are nothing like you may expect on a real z/OS machine – but my figures should show you the potential.

Topics covered:

Overview of Java shared classes

With Java shared classes support, as a Java program starts, and reads the jar and class files and also copies them into memory somewhere. Successive start can use the in memory copy and avoid the read for disk and initial processing.

You can save the in-memory copy to disk, and restore this disk copy to memory, for example across IPLs.

Measurements

I measured the CPU user from the address space once the system was started

The Java program provides a high level trace. I note the time difference between the first message and the “I am up” message

Scenarios

I used three scenarios

  • IPL and start Java program with no share classes
  • Enable shared classes
  • IPL and restore the shared classes, and start the program

No shared classes

ScenarioCPUDuration seconds
First run after IPL 394172
Second run425183

Enable shared classes

I enabled shared classes by using the Java option

-Xshareclasses:verbose,name=rseapi,cachedir=/tmp/,groupAccess,nonpersistent,nonfatal,cacheDirPerm=0777″

ScenarioCPUDuration seconds
run after shared classes enabled 500200
Second run after shared classes enabled 292116
Third run after shared classes enabled25181

IPL and restore snapshot

ScenarioCPUDuration seconds
First run after (IPL and restore snapshot )27499
Second run272121
Third run279116
Fourth run264111

Analysis of the results

Using the shared classes saved CPU in the region of 25% and reduced the elapsed time by about a half.

The first time the Java program runs and creates the shared class data has a higher CPU cost, and increased elapsed time. The savings of CPU and elapsed time when the shared cache is reused outweighs this one time cost.

Observation

It appears that each time you restart using shared classes the CPU drops. I think this is due to the optimisation being done on the classes, but it may be some totally different effect – or it may just be co-incidence!

Setting up to use the shared classes

I added two job steps to my Java program JCL

Before – restore the share classes cache from the backup copy

// EXPORT SYMLIST=* 
// SET J='/usr/lpp/java/J8.8_64/J8.0_64/bin' 
// SET C='/tmp/' 
// SET N='rseapi' 
// SET V='restoreFromSnapshot'
// SET Q='cacheDirPerm=0777,groupAccess' 
//RESTORE  EXEC PGM=BPXBATCH,REGION=0M,PARMDD=PARMDD 
//PARMDD  DD *,SYMBOLS=(JCLONLY) 
SH &J/java -Xshareclasses:cacheDir=&C,name=&N,&V,&Q 
/* 

If the in-memory cache exists you get message

JVMSHRC726E Non-persistent shared cache “rseapi” already exists. It cannot be restored from the snapshot.

After – save the shared class cache to disk

// SET V='snapshotCache' 
// SET J='/usr/lpp/java/J8.8_64/J8.0_64/bin' 
//SAVECAC  EXEC PGM=BPXBATCH,REGION=0M, 
//   PARM='SH &J/java -Xshareclasses:cacheDir=&C,name=&N,&V' 
//STDERR   DD   SYSOUT=* 
//STDOUT   DD   SYSOUT=* 

Strange behaviour

By using the startup option -verbose:class,dynload you can get information about the classes as they are loaded.

When not using shared classes, there were records saying <Loaded ….. and giving durations of the loads etc.

When using shared classes there were still a few instances of <Loaded… . I could not find out why some classes were read from disk , and the rest were read from the shared classes cache.

If we could fix these, then the startup would be even faster!

After some investigation I can explain some of the strange behaviour.

  • When a jar is first used there is a <Loaded… for the class that requested the jar.
  • A class like <Loaded sun/reflect/GeneratedMethodAccessor1 with a number at the end gets a <Loader… entry.
  • Some other classes in a jar file get loaded using <Loader… though they do not look any different to classes which are loaded from the shared cache!

All in all, very strange.

Where do you harden the cache to?

By default the cache is saved to /tmp. As /tmp is often cleared at IPL, this means the cache will not exist across IPLs. You may wish to save it in an instance specific location such as /var/myprogram.

What happens if I change my Java program?

I had a small test program which I recompiled, and created the jar file. The Java source was

public class hw   { 
  public static void main(String[] args) throws Exception { 
    System.out.println("This will be printed"); 
    System.out.println("HELLo" )  ; 
    CPUtil.print(); // this prints Util.line 10 
    hw2.print(); 
  } 
} 

When I reran the program the output contained

JVMSHRC169I Change detected in /u/adcd/hw.jar... 
  ...marked 3 cached classes stale 
class load: sun/launcher/LauncherHelper$FXHelper from: .../lib/rt.jar 
<Loaded CPUtil> 
<  Class size 427; ROM size 416; debug size 0> 
<  Read time 4 usec; Load time 108 usec; Translate time 595 usec> 
class load: CPUtil from: file:/u/adcd/hw.jar 
Output from CPUtil.line 10 
<Loaded hw2> 
<  Class size 386; ROM size 368; debug size 0> 
<  Read time 3 usec; Load time 107 usec; Translate time 635 usec> 
class load: hw2 from: file:/u/adcd/hw.jar 

Where you can see output from my program is intermixed with the loader activity.

What happens internally

From the previous topic, it seems that Java has to read the files on disk for example to spot that a class has changed. This may just be a matter of reading the time stamp of the file on disk,or it may go into the file itself.

Should I use .class files or package the .class files into a .jar files?

This will be a hand waving type answer. Generally the answer is use a .jar file.

Use one .jar fileUse multiple .class files
One directory access and one security access check should reduce the CPU usage.Multiple directory access and multiple security checks are required.
Reading one large file may be faster than reading many smaller files. An I/O has “set-up I/O”, “transfer data”, “shutdown I/O” there is one set-up and one shutdown.Each file I/O has set-up and shutdown time as well as the transfer time and is generally slower than processing bigger files. (Think about large block sizes for data sets).
The .jar files are compressed so there is less data to transfer. The decompression of the jar file takes CPU.Files do not need to be decompressed
For integrity reasons you can have your .jar file cryptographically signed.You cannot sign .class files.

Should I use of BPXBATCH or BPXBATSL?

In the Tomcat script for starting the web server it issued

exec "/usr/lpp/java/J8.8_64/J8.0_64/bin/java" ...  &

The & makes it run in the background. As I was running this as a started task, this seemed unnecessary and removed the &.

I also used EXEC PGM=BPXBATSL instead of EXEC PGM=BPXBATCH

The combination of both reduced the start time significantly!

I had to specify environment variable _BPX_SPAWN_SCRIPT=YES to be able to run the script. Without it I got

BPXM047I BPXBATCH FAILED BECAUSE SPAWN (BPX1SPN) OF … FAILED WITH RETURN CODE 00000082 REASON CODE 0B1B0C27

Problems I experienced while setting this up.

Group access

When restoring from a snapshot I used

java -Xshareclasses:cacheDir=/tmp,name=rseapi’,restoreFromSnapshot’, cacheDirPerm=0777,groupAccess’

Which worked.

When I omitted the group Access I had the following messages in stderr of my Java program.

JVMSHRC020E An error has occurred while opening semaphore 
JVMSHRC336E Port layer error code = -197358 
JVMSHRC337E Platform error message: semget : EDC5111I Permission denied. 
JVMSHRC028E Permission Denied 
JVMSHRC670I Error recovery: attempting to use shared cache in readonly mode if the shared memory region exists, in response to "-Xshareclasses:nonfatal" option.                                                                                                                      
JVMSHRC659E An error has occurred while opening shared memory 
JVMSHRC336E Port layer error code = -393966 
JVMSHRC337E Platform error message: shmget : EDC5111I Permission denied. 
JVMSHRC028E Permission Denied 
JVMSHRC627I Recreation of shared memory control file is not allowed when running in read-only mode. 
JVMSHRC840E Failed to start up the shared cache. 
JVMSHRC686I Failed to startup shared class cache. Continue without using it as -Xshareclasses:nonfatal is specified c

The OMVS command ipcs -m gave

>ipcs -m
IPC status as of Mon Aug 21 17:33:54 2023
Shared Memory:
T ID KEY MODE OWNER GROUP
m 8196 0x6100c70e --rw-rw---- OMVSKERN SYS1
m 8197 0x6100c30e --rw------- OMVSKERN STCGROUP

When the correct group access was specified the ipcs -m command gave

>ipcs -m
IPC status as of Mon Aug 21 17:38:40 2023                         
Shared Memory:                                                    
T         ID     KEY        MODE       OWNER    GROUP             
m       8196 0x6100c70e --rw-rw---- OMVSKERN     SYS1             
m      73733 0x6100c30e --rw-rw---- OMVSKERN STCGROUP             

and the group mode has values -rw.

Wrong owner

I submitted a job to run Java which created the shared cache. I then tried running the same program using a started task with a different userid.

The cache on disk had access

-rw-rw----   1 COLIN    SYS1          32 Aug 25 11:05 C290M4F1A64_semaphore_zosmf_G41L00       
-rw-rw----   1 COLIN    SYS1          40 Aug 25 11:05 C290M4F1A64_memory_zosmf_G41L00          

But my started task was running with a different userid and group.

I got messages

JVMSHRC684E An error has occurred while opening semaphore. Control file could not be locked.         
JVMSHRC336E Port layer error code = -102                                                             
JVMSHRC337E Platform error message: EDC5111I Permission denied. (errno2=0xEF076015)                  
JVMSHRC028E Permission Denied                                                                        

I delete the cache entries, and restarted the started task. I also added another step to the started task to issue snapshotCache.