Tag: java

How to take (and process) a RACF GTF trace with Java

When trying to resolve a certificate problem in a Java program, see here, I tried unsuccessfully to take a RACF trace to see what calls were being issued, and what reason codes were being returned.

The RACF GTF had no entries for the Java program!

Start RACF trace

My started task was called OZUSRV4. I had to specify a jobname to RACF trace of OZUSRV4* because Java spawns address spaces, and it was a spawned address space that did all of the Java work. If your started task is 8 characters long – just specify the 8 character name.

The trace command was the RACF SET TRACE command, where # is my RACF subsystem recognition character.

#SET TRACE(CALLABLE(TYPE(41))JOBNAME(OZUSVR4*))

Where type(41) is for IRRSDL00 which performs the R_datalib, keyring processing.

Start GTF

S GTF.GTF
R 1,trace=usrp
R 2,USR=(F44) 
R 3,END
R 4,U

Run the test

I ran my started task, and stopped the RACF trace 

#SET TRACE(CALLABLE(NONE))JOBNAME(OZUSVR4*)) 
#set list

The output of the #set list command included

TRACE OPTIONS                   - NOIMAGE                                    
                                - NOAPPC                                     
                                - NOSYSTEMSSL                                
                                - NORRSF                                     
                                - NORACROUTE                                 
                                - NOCALLABLE                                 
                                - NOPDCALLABLE                               
                                - NODATABASE                                 
                                - NOGENERICANCHOR                            
                                - NOASID                                     
                                - JOBNAME                                    
                                   OZUSVR4*                                  
                                - NOCLASS                                    
                                - NOUSERID                                   
SUBSYSTEM USERID                - START1

So the traces are off…. but it still has a reference to OZUSVR4 – strange.

Process the GTF file.

I used IPCS to look at the GTF file

  • =0 and specify the GTF file name
  • =6 dropd to drop any saved status from last time that dataset was used
  • gtf usr(all) It displays the output in an editor like window.
  • report view displays it in ISPF editor, view mod.
  • You can the do things like
    • x all
    • f ‘RACF Reason code’ all

To display the records with non zero return codes.

The output is very chatty – and it was hard to find the data I wanted from data with a hex dump of the string “OFFSET” etc. For example

Trace Identifier:             00000036                           
Record Eyecatcher:            RTRACE                             
Trace Type:                   OMVSPRE                            
Ending Sequence:              ........                           
Calling address:              00000000  79403A2D                 
Requestor/Subsystem:          ........  ........                 
Primary jobname:              OZUSVR44                           
Primary asid:                 00000035                           
Primary ACEEP:                00000000  008FC8A0                 
Home jobname:                 OZUSVR44                           
Home asid:                    00000035                           
Home ACEEP:                   00000000  008FC8A0                 
Task address:                 00000000  008CF298                 
Task ACEEP:                   00000000  00000000                 
Time:                         DDD4C11D  776E2A40                 
Error class:                  ........                           
Service number:               00000029                           
RACF Return code:             00000000                           
RACF Reason code:             00000000                           
Return area address:          00000000  00000000                 
Parameter count:              0000002B    
...                       
Area length:                  00000008                                                                                
                                                                                                                      
Area value:                                                                                                  
D6C6C6E2  C5E30050                               | OFFSET.&                         |  
                                                                                                                      
Area length:                  00000007                                                                                
                                                                                                                      
Area value:                                                                                                           
06E2E3C1  D9E3F1                                 | .START1                          |

I wrote a REXX exec which post processes the output and removes what I think is irrelevant data.

An example of what I think is useful is below. Non zero return codes have ! in column 1

! Return code: 00000008 8 
! Reason code: 00000004 4  4 Parameter list error occurred. 
-  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  - 
! Return code: 00000008 8 
! Reason code: 0000002C 44 44 No certificate found with the specified status 
-  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  - 
Area value: 
00000050  10AFC67C  ...
...
  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  -  - 
Area value:          | .START1                          | 
06E2E3C1  D9E3F1                                                
Area value:          | .MQRING                          | 
06D4D8D9  C9D5C7

You can download the rexx exec from

racfgtfDownload

You need to upload it to a CLIST available to ISPF.

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.

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.

Using enclaves in a java program

Ive blogged about using enclaves from a C program.  There is an interface from Java which uses this C interface.

Is is relatively easy to use enclave services from a java program, as there are java classes for most of the functions, available from JZOS toolkit.  For example the WorkloadManager class is defined here.

Below is a program I used to get the Work Load Manager(WLM) services working.

import java.util.concurrent.TimeUnit;
import com.ibm.jzos.wlm.ServerClassification;
import com.ibm.jzos.wlm.WorkUnit;
import com.ibm.jzos.wlm.WorkloadManager; 
public class main 
{ 
   // run it with /usr/lpp/java/J8.0_64/bin/java   main  
   public static void main(String[] args) throws Exception 
   { 
     WorkloadManager wlmToken = new  WorkloadManager("JES", "SM3");
     ServerClassification serverC = wlmToken.createServerClassification();
     serverC.setTransactionName("TCI3");
     for ( int j = 0;j<1000;j++)
     {
        WorkUnit wU = new WorkUnit(serverC, "MAINCP");
        wU.join();
        float f;
        for (int i = 0;i<1000000;i++) f=ii2;  
          TimeUnit.MICROSECONDS.sleep(20*1000); // 200 milliseconds
          wU.leave();
          wU.delete(); // end the workload
      }
      wlmToken.disconnect();
   } 
}

The WLM statements are explained below.

WorkloadManager wlmToken = new WorkloadManager(“JES”, “SM3”);

This connects to the Work Load Manager and returns a connection token.    This needs to be done once per JVM.  You can use any relevant subsystem type, I used JES, and a SubsystemInstance (SI) of SM3. As a test, I created a new  subsystem category in WLM called DOG, and used that.  I defined ServerInstance SI with a value of SM3 within DOG and it worked.

z/OS uses uses subsystems such as JES for jobs submitted into JES2, and STC for Started task.

ServerClassification serverC = m.createServerClassification();

If your application is going to classify the transaction to determine the WLM service class and reporting  class you need this.  You create it, then add the classification criteria to it, see the following section.

Internally this passes the connection token wlmToken to the createServerClassification function.

serverC.setTransactionName(“TCI3”);

This passes information to WLM to determine the best service class and reporting class.  Within Subsystem CAT, Subsystem Instance SM1, I had a sub rule TransactionName (TN) with a value TCI3.  I defined the service class and a reporting class.

WorkUnit wU = new WorkUnit(serverC, “MAINCP”);

This creates the Independent (business transaction) enclave.  I have not see the value MAINCP reported in any reports.   This invokes the C run time function CreateWorkUnit(). The CreateWorkUnit function requires a STCK value of when the work unit started.  The Java code does this for you and passes the STCK through.

wU.join();

This connect the current task to the enclave, and any CPU it uses will be recorded against the enclave. 

wU.leave();

Disconnect the current task from the enclave.  After this call any CPU used by the thread will be recorded against the address space.

wU.delete();

The Independent enclave(Business transaction) has finished. WLM records the elapsed time and resources used for the business transaction.

m.disconnect();

The program disconnects from WLM.

Reporting class output.

I used RMF to print the SMF 72 records for this program.   The Reporting class for this program had

-TRANSACTIONS--  TRANS-TIME HHH.MM.SS.FFFFFF 
AVG        0.29  ACTUAL                36320 
MPL        0.29  EXECUTION             35291 
ENDED       998  QUEUED                 1028 
END/S      8.31  R/S AFFIN                 0 
#SWAPS        0  INELIGIBLE                0 
EXCTD         0  CONVERSION                0 
                 STD DEV               18368 
                                             
----SERVICE----   SERVICE TIME  ---APPL %--- 
IOC           0   CPU   12.543  CP      0.01 
CPU       10747   SRB    0.000  IIPCP   0.01 
MSO           0   RCT    0.000  IIP    10.44 
SRB           0   IIT    0.000  AAPCP   0.00 
TOT       10747   HST    0.000  AAP      N/A

From this we can see that for the interval

  1. 998 transactions ended.  (Another report interval had 2 transactions ending)
  2. the response time was an average of 36.3 milliseconds
  3. a total of 12.543 seconds of CPU was used.
  4. it spent 10.44 % of the time on a ZIIP.
  5. 0.01 % of the time it was executing ZIIP eligible work on a CP as there was no available ZIIP.

Additional functions.

The functions below

  • ContinueWorkUnit – for dependent enclave
  • JoinWorkUnit – as before
  • LeaveWorkUnit – as before
  • DeleteWorkUnit – as before

can be used to record CPU against the dependent (Address space) enclave.  There is no WLM classify for a dependent enclave.

Java threads and WLM

A common application pattern is to use connection pooling.  For example the connect/disconnect to a database or MQ is expensive.  If you have a pool of threads, which connect, and start connected, an application can request a thread and get a thread which has already been connected to the resource manager.

It should be a simple matter of changing the interface from

connectionPool.getConnection()

to

connectionPool.getConnection(WorkUnit wU)
{
 connection = connectionPool.getConnection()
 connection.join(wU)
}

and add a connection.leave(wU) to the releaseConnection.

Magic methods to decode Java MQ constants to strings.

I had been struggling with MQ and java, and decoding what the return codes numbers were, and found some well gem methods here.

String reasonCode = MQConstants.lookup(2035, “MQRC_.*”);  gave MQRC_NOT_AUTHORIZED

and

String decode  = MQConstants.decodeOptions(gmo.options,”MQGMO_.*”);  gave me

MQGMO_WAIT | MQGMO_SYNCPOINT_IF_PERSISTENT | MQGMO_FAIL_IF_QUIESCING

I wish I had these a couple of years ago – it would have saved me a lot of time!

 

The methods are

static java.lang.String decodeOptions(int optionsP,
java.lang.String optionPattern)

This helper method takes an integer representing a set of IBM MQ options for an MQI structure, and converts them into a string displaying the constants that the options represent.
static int getIntValue(java.lang.String name)

Returns the value of the named MQSeries constant as an int.
static java.lang.Object getValue(java.lang.String name)

Returns the value of the named MQSeries constant.
static java.lang.String lookup(int value,
java.lang.String filter)

Returns the MQSeries constant name or names for the supplied int value.
static java.lang.String lookup(java.lang.Object value,
java.lang.String filter)

Returns the MQSeries constant name or names for the supplied value of type Integer, String, byte[], or char[].
static java.lang.String lookupCompCode(int reason)

Convenience method for finding the constant name for a completion code.
static java.lang.String lookupReasonCode(int reason)

Convenience method for finding the constant name for a reason code.
static void main(java.lang.String[] args)

MDBs activation specs and @things in the java program

While struggling with getting MDBs working, and looking at examples, I saw examples where they defined JMS resources within the java program using @….  statements, and could not see how they worked.  These are called annotations. The documentation on the web assumes you know about annotations  when explaining annotations!  They, in fact, are pretty simple, let me explain.

Annotations start with an @ character, and the information can be stored within the .class file as meta-data.  Programs can extract and use this meta data.

You can have java code like
@Resource(lookup="java:customerMQ")
private javax.jms... myMQ;

A program, for example,  your program, an analysis program or a web server, can issue request like

  • load class information
  • from the meta data list all fields with @resource defined.
  • do things with the list

One example would be to specify a JNDI lookup of java:customerMQ and return it into the field myMQ.

Another example from the IBM documentation

@MessageDriven(
  name = "JMSSampleMDB",
  activationConfig = 
  {
    @ActivationConfigProperty(
       propertyName  = "destinationType", 
       propertyValue = "javax.jms.Queue"),
 
    @ActivationConfigProperty(
       propertyName  = "destination", 
	propertyValue = "jndi_INPUT_Q")                         
   }
)

The resource adapter has code which does

  • load your MDB program
  • get the MessageDriven stuff.
    • within this, locate the activationConfig records
      • within these, locate the ActivationConfigProperty propertyName and propertyValue, and merge the data with the data in the ejb-jar.xml file.

 

With the definitions in your java program, and the definitions in the MDB configuration you can configure a complete set of options for MDB.  I think the definitions in the java program override the MDB configuration.

How do I see what data there is?

You can extract this meta-data using a method like (see here)

public void getAnnotations(Class inclass){
    for(Field field : inclass.getDeclaredFields()){
        Class type = field.getType();
        String name = field.getName();
        field.getDeclaredAnnotations(); //do something with these
    }

Use the javap command to display the data.

To display the annotations you can usethe command, where ….class is the name of your class file.

javap -v .....class

My java program had

import javax.annotation.Resource;
.....
@Resource(lookup = "java:app/jms/myappTopic")
String colin = "ZZZZZ";

The javap command gave

java.lang.String colin;
  descriptor: Ljava/lang/String;
  flags:
  RuntimeVisibleAnnotations:
  0: #14(#15=s#16)
...
#14 = Utf8 Ljavax/annotation/Resource;
#15 = Utf8 lookup
#16 = Utf8 java:app/jms/myappTopic

from which we get

java.lang.String colin ... 
  javax/annotation/Resource (lookup = java:app/jms/myappTopic).

which matches the source code.

Different annotation types are confusing.

As well as providing meta-information on variables and classes, java also uses annotations to modify the java compiler behaviour.   For example

  • By putting @Deprecated infront of a method, the method can be flagged when used, as deprecated, and you should not use it
  • @SuppressWarnings(“unchecked”) tells the java compiler NOT to produce an error message for the unchecked condition.  See here for a list of warning conditions.