On 12/10/2013 5:36 AM, Graham Harris wrote:
There are no special SMF records for java stats per se. I must say, that
the amount of CPU indicated in your table, is somewhat surprising, as java
simply isnt that 'cheap'. Especially, when considering the elapsed
time....java very rarely sits around NOT consuming CPU when it has 'things
to do'!! The mere fact of just firing up the JVM can be very costly
indeed. What often happens with java, is that the actual JVM is created in
spawned/forked OMVS threads, that will be outside of the CPU captured by
the standard JES job CPU that gets reported back.
That's what I thought at first. But the batch launcher I'm using to run
the Java program sets _BPX_SHARE=MUST
by default and I don't see any other SMF 30 records related to the job.
To double check I ran the program
from a Unix shell and I see exactly the same numbers in the SMF 30
records for the spawned address space.
I think I can explain it but I'm not sure yet.
SMF30CPT = 21 - total CPU time
SMF30_TIME_ON_SUP = 71 - zIIP time
Add those two together for 0.92 CPU time. The SMF 30-4 z/OS UNIX System
Services Process Section shows a lot of I/O in the file system,
literally thousands of directory/file reads.
I suspect that's Java loading classes. The remaining 1.5 secs of
remaining elapsed time is probably down to I/O. We're not collecting
OMVS file system SMF records but I might turn them
on just to confirm my theory.
Have you kept an eye on
SDSF DA while the java step is running? Are there BENCHSQx [x=1-9] address
spaces being generated while the java step is running? Presuming this is
the case, then the CPU time consumed by all those other address spaces
should count towards to total time for the java step, although totting it
all up is easier said than done!
All very good points and any transaction analysis product must be able
handle multiple address space measurements. I reran the Java step
with _BPX_SHARE=NO and I hey presto, the spawned address space steps
were there. A pleasant surprise that SMF inherits the jobname from the
parent process.
SMF30JBN... 'BENCHSQL' SMF30PGM... 'BPXPRECP'
Thanks for you help
On 8 October 2013 13:00, David Crayford <[email protected]> wrote:
I'm running a test case for one of our products that's currently in
development and I can't figure out how to account for the total CPU time
for a Java program that executes a DB2 query.
I've got four steps running the same query in different programming
languages. The step statistics are like this
CPU (Total) Elapsed CPU (TCB)
CPU (SRB) Service
Jobname Stepname ProcStep RC I/O hh:mm:ss.th hh:mm:ss.th hh:mm:
ss.th hh:mm:ss.th Units
BENCHSQL C 00 165 00.21 00.38 00.21
00.00 4628
BENCHSQL JAVA SPAWN 00 17049 00.23 02.64 00.23
00.00 34448
BENCHSQL LUA 00 724 00.32 00.88 00.32
00.00 7170
BENCHSQL REXX 00 39 05.08 08.03 05.08
00.00 113K
Java CPU time is very good but the elapsed time is high. I know this is
because of the overhead of the JVM doing a JIT compile but I want to be
able to include that in the report. What SMF
records report Java JVM stats and how do I correlate that to a job step?
I've got a screen shot that shows the numbers http://imagebin.org/273074.
The 1E codes are actually SMF 30s, we haven't got round to converting them
to decimal yet. The 003 codes
are DB2 trace records. The DB2 trace record for the Java program seems
very low. It changes depending on the JDBC driver (2 or 4) but the job step
times remain the same.
------------------------------**------------------------------**----------
For IBM-MAIN subscribe / signoff / archive access instructions,
send email to [email protected] with the message: INFO IBM-MAIN
----------------------------------------------------------------------
For IBM-MAIN subscribe / signoff / archive access instructions,
send email to [email protected] with the message: INFO IBM-MAIN
----------------------------------------------------------------------
For IBM-MAIN subscribe / signoff / archive access instructions,
send email to [email protected] with the message: INFO IBM-MAIN
