Performance problems using jdk 1.4

MichaelLueghausen · Post by **MichaelLueghausen** » Fri Feb 11, 2005 6:35 am

Hi,

i'm using ZJOS for the 1st time.
For installation verification i started run13 and run14 both with loglvl='+T' and got following results related to performance:

run13:
12:29:08 JZOSVM13(T): <- initializeVMArgs()
12:29:08 JZOSVM13(T): -> createJvm()
12:29:09 JZOSVM13(N): Java Virtual Machine created. Version information follow
12:29:09 JZOSVM13(T): -> invoke()
12:29:09 JZOSVM13(D): About to invoke com.dovetail.jzos.ZUtil.getJavaVersionInf
12:29:09 JZOSVM13(T): <- invoke()
java version "1.3.1"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.3.1)
Classic VM (build 1.3.1, J2RE 1.3.1 IBM OS/390 Persistent Reusable VM build cm1
12:29:09 JZOSVM13(T): <- createJvm()

run14:
10:57:38 JZOSVM14(T): <- initializeVMArgs()
10:57:38 JZOSVM14(T): -> createJvm()
10:57:47 JZOSVM14(N): Java Virtual Machine created. Version information follow
10:57:47 JZOSVM14(T): -> invoke()
10:59:01 JZOSVM14(D): About to invoke com.dovetail.jzos.ZUtil.getJavaVersionInf
10:59:01 JZOSVM14(T): <- invoke()
java version "1.4.1"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.1)
Classic VM (build 1.4.1, J2RE 1.4.1 IBM z/OS Persistent Reusable VM build cm141
10:59:01 JZOSVM14(T): <- createJvm()

My question:
why takes it so long using jdk 1.4?

thanks,
Michael

Post by **dovetail** » Fri Feb 11, 2005 8:58 am

Michael,

It looks like the JNI_CreateJavaVM() call is taking 9 seconds for 1.4, but only 1 second for 1.3.1 on your system. (This is the JNI api for creating/initializing the JVM). JDK 1.4 uses a differenct set of LE libraries, perhaps there is a difference in how these are tuned in your environment (LPA, etc).

Can you do a test comparing the java command line, JDK 1.3 vs 1.4, running say the "HelloWorld" class?

For example (in a USS shell):

cd /usr/lpp/java/J1.4
./bin/java -cp . HelloWorld

cd /usr/lpp/java/IBM/J1.3
./bin/java -cp . HelloWorld

This seems to take about the same amount of time in our environment (about a second), about the same as with the batch launcher. I would assume that you would see a big discrepency here as well.

If you run it twice in a row, is there a difference the second time? (either batch or USS)?

MichaelLueghausen · Post by **MichaelLueghausen** » Mon Feb 14, 2005 1:42 am

Hi,

thanks for answering promptly.
I did the tests with following results (as you expected):

time ./bin/java -cp . HelloWorld
J1.3
real 0,58s
user 0,36s
sys 0,12s

J1.4
real 1,95s
user 0,58s
sys 0,19s

time ./bin/java -cp . HelloWorld; time ./bin/java -cp . HelloWorld

J1.3
real 0,61s 0,61s
user 0,37s 0,36s
sys 0,13s 0,12s

J1.4
real 1,95s 1,97s
user 0,57s 0,58s
sys 0,19s 0,19s

I had to mention that Java under USS is very new for our shop; so it could be absolutely possible that no tuning at all was done until now.
Any suggestion what papers i should read are welcome

Thanks,
Michael

Post by **dovetail** » Mon Feb 14, 2005 5:49 pm

No, the data that you posted was not really what I expected.
Your data seems to show that starting a 1.3 jvm takes a little less than one second, and a 1.4 jvm takes a little less than 2 seconds. This is consistent with what I see.

It doesn't explain, for me, why the JDK 1.4 JNI_CreateJavaVM() is taking 9 seconds under batch. I'm not an expert at tuning LE, but I'll try to find some references for you to look at.

Guest · Post by **Guest** » Tue Feb 15, 2005 2:13 am

I have some additional timings. All scenarios are using JDKs HelloWorld

Using BPXBATSL:
J1.3 0.6s
J1.4 0.91s

Using JZOS:
J1.3 0.67s
J1.4 52.2s

MichaelLueghausen · Post by **MichaelLueghausen** » Tue Feb 15, 2005 2:15 am

sorry, I've forgotten to login. Previous posting was mine

Post by **dovetail** » Tue Feb 15, 2005 8:18 am

There is definitely something odd about your environment. Can you run HelloWorld using both the JZOS launcher (with LOGLVL='+T') and BPXBATCH and email us the (entire) job outputs to look at? (print to a dataset using SDSF, ftp the dataset, etc).

Please send it to dev@jzos.com, and we'll compare it to some baseline runs to see if we can find any clues.

Thanks for your patience.

jvanparijs · Post by **jvanparijs** » Mon May 09, 2005 5:18 am

Hi,

We're porting a Java application to z/OS, and we'll be using Java 1.4.2 (and yes, we're considering using the JZOS toolkit to facilitate running some processes as started tasks). The performance problems mentioned in this thread make me a bit worried, though. Did this thing ever come to a resolution? Was the bad performance traced down to J1.4.2? And if so, did IBM bring out (a) fix(es) to remedy this? Or was the problem related to JZOS? And again fixed? Or...

Thanks beforehand,

Post by **dovetail** » Mon May 09, 2005 10:20 am

The vast majority of users do not have a problem, but we've had two different users report performance problems which are related to slow JVM startup. In both cases, we were able to reproduce the problem using IBM's sample JNI launcher program (modified to run as a batch job). So, we are pretty sure that it is not a JZOS problem. Our best guess is that the problem has something to do with LE. One of the users submitted the problem to the IBM support center, but I haven't heard if a resolution was found as yet. We'll post additional information here when we can get it.

Guest · Post by **Guest** » Mon May 09, 2005 11:31 am

Thanks for the quick reply; I'll keep an eye on this thread for eventual further info, and I'll try to update it with our experience (we won't be able to compare with J1.3 though, as our application requires J1.4)...

Post by **dovetail** » Mon May 09, 2005 5:15 pm

To see if the problem exists in your environment, try running the JZOS "HelloWorld" example with LOGLVL="+T" turned on. If the "createJvm()" call runs a second or two, then you are fine. The symptom that we have seen is that in rare environments, this call into the Java VM takes 10 seconds or more.

Of course, these times are for normal late-model engines. Emulated z-architecture boxes, like Flex-es will be much slower of course, even in normal circumstances.

jvanparijs · Post by **jvanparijs** » Tue May 10, 2005 4:10 pm

It looks like the system I'm testing JZOS on, is somewhere in the middle. To the best of my knowledge, we're running on a 2084-C24 under VM, with only one processor enabled (but that shouldn't matter too much for the HelloWorld appl, I guess)...
The entire job took 13 seconds with logging (without logging it took 9 seconds), and the creating of the virtual machine took 4 seconds...

I'm not attaching the JOBLOG (it's 232 lines), but if you want it, just tell me where to mail it (your wish is my command...)

Post by **dovetail** » Thu May 12, 2005 8:37 am

I don't think that your system has the problem... taking 4 seconds to initialize the JVM is not that bad if running under VM. (JVM creation is fairly expensive). On systems affected by this problem it takes around a minute.

But, we have very good news. Thanks to some help by two of the users who were affected, and the IBM support center, the problem has been found!

The problem is that -some- installations have very small defaults for the LE "downstack" (aka XPLINK STACK) size. This, BTW, is suboptions 5 and 6 of the LE "STACK" option. To make a long story short, the LE runtime options for the JZOS 1.4 launcher was only setting the first 4 subtions of the STACK parameter, and taking the defaults for downstack size.

We will be releasing a new build of the JZOS launcher in a day or two to properly set the downstack LE option. In the mean time, if you are running JZOS with JDK 1.4, you can correct the problem by setting suboptions 5 and 6 of the LE STACK runoption to 64K,16K. This can be done by updating the LE installations defaults, or adding the following LE option to the PARM= (before the /):

STACK=(,,,,64K,16K)

jvanparijs · Post by **jvanparijs** » Thu May 12, 2005 10:26 am

This LE problem should indeed be fairly exceptional, as - at least since z/OS v1r2 - the defaults are a lot higher:
STACK=((128K,128K,ANYWHERE,KEEP,512K,128K),OVR)

We're actually renting our system from the IBM DTSC in Dallas, so I've no idea if a customised LE options module exists on our system...

I'd say - unless there are good reasons to set the values differently for JZOS - to set these suboptions to at least these default values..

Post by **dovetail** » Thu May 12, 2005 11:27 am

Agreed, we've only heard of two cases where this was a problem.

Our strategy in the JZOS launcher will be to set the runtime option overrides to match the standard USS java launchers. That was our original intention, but we missed a couple. The next build will fix this, so we hope that this problem is resolved.