Hi there, I am trying to diagnose a performance problem on a Sun T5120 running Solaris 10. I see general poor performance using Java and, in particular, loading classes. I have developed a simple java test that loads all of the classes in a Crystal Reports JAR file (around 7000 classes) which takes much longer on the T5120 (40 secs) than on a Core 2 Duo windows PC (5 secs). I recognise that this time difference may be down to hardware specification but if that is the case, I wish to fully understand which aspect of the hardware (CPU, memory, disk etc.) is limiting the performance of the T5120.
In order to try to explain this time difference, I the test on Solaris using the dtrace toolkit. Running procsystime gives the following results (I've condensed them to keep the email short): Elapsed Times: SYSCALL TIME (ns) ... stat 18498184 fstat64 18720808 open 21688773 open64 41127563 stat64 67024580 resolvepath 104326254 yield 514242236 read 608379863 lwp_mutex_timedlock 1541179345 pollsys 37961554776 lwp_park 38822747920 lwp_cond_wait 1530739381685 TOTAL: 1610584447807 CPU Times SYSCALL TIME (ns) ... stat 14066206 munmap 14522555 open64 22698725 pollsys 24852893 lwp_cond_wait 26192803 lwp_mutex_timedlock 30490184 stat64 53125558 read 55471522 resolvepath 80374974 yield 224775263 TOTAL: 634822857 Syscall Counts SYSCALL COUNT ... open64 613 fcntl 635 pollsys 647 stat 704 lwp_cond_wait 794 close 834 lwp_mutex_timedlock 845 brk 848 llseek 1403 read 1515 fstat64 1593 resolvepath 1700 stat64 1778 yield 27285 TOTAL: 43946 I'm not an expert in dtrace, but what I take from this is that of the total execution time (measured at 40 seconds), only 0.63 seconds is spent actually executing on the CPU. Q1: Is this a correct interpretation? Suspecting that perhaps this 'missing' time was spent in I/O, I executed iosnoop while the program ran, with the following results: STRTIME DEVICE MAJ MIN UID PID D BLOCK SIZE PATHNAME ARGS 2010 Mar 18 09:22:55 sd1 32 13 10054 20116 R 32569904 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:22:55 sd1 32 13 10054 20116 R 32569920 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:22:56 sd1 32 8 10054 20116 R 42673424 8192 /usr/j2sdk-1.5.0_14/jdk1.5.0_14/jre/lib/rt.jar 2010 Mar 18 09:23:02 sd1 32 13 10054 20116 R 32569888 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:23:10 sd1 32 13 10054 20116 R 32564784 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:23:10 sd1 32 13 10054 20116 R 32564816 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:23:12 sd1 32 8 10054 20116 R 6395504 8192 /usr/lib/libfontconfig.so.1 2010 Mar 18 09:23:12 sd1 32 8 10054 20116 R 6395488 8192 /usr/lib/libfontconfig.so.1 2010 Mar 18 09:23:13 sd1 32 8 10054 20116 R 1823458 7168 /usr/openwin/lib/locale/iso_8859_4/X11/fonts/Type1/LucidaSansLat4.pfb 2010 Mar 18 09:23:14 sd1 32 8 10054 20116 R 42698368 8192 /usr/j2sdk-1.5.0_14/jdk1.5.0_14/jre/lib/charsets.jar 2010 Mar 18 09:23:14 sd1 32 8 10054 20116 R 42698464 73728 /usr/j2sdk-1.5.0_14/jdk1.5.0_14/jre/lib/charsets.jar 2010 Mar 18 09:23:18 sd1 32 13 10054 20116 R 32560384 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:23:20 sd1 32 13 10054 20116 R 32566144 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:23:23 sd1 32 8 10054 20116 R 42673584 32768 /usr/j2sdk-1.5.0_14/jdk1.5.0_14/jre/lib/rt.jar 2010 Mar 18 09:23:24 sd1 32 13 10054 20116 R 32549104 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar 2010 Mar 18 09:23:25 sd1 32 13 10054 20116 R 32556848 8192 /var/tmp/test-crystal/lib/cr/CrystalReportsRuntime.jar My interpretation is that this is very little I/O which should not be holding up the CPU. Q2: Am I correct in saying that this is very little I/O? I have looked at various dtrace tutorials online and it always seems obvious from procsystime where the CPU time is going missing but here I don't see anything so obvious. Q3: Does anyone have any ideas as to how I could continue this investigation to determine where the bulk of the execution time is going? Thanks in advance for any help. Cheers, Kevin. _______________________________________________ dtrace-discuss mailing list dtrace-discuss@opensolaris.org
