Overhead

Here are some examples how profiling affects runtime, for various options and platforms.

The code profiled is the same in all cases,  a JUnit test suite with ~2195 test cases.  This is not very producton-like, in particular since since setUp() very often reads XML configuration files. With the default scope, about 68 million calls are profiled. With a scope that profiles the entire application, about 1155 million calls are profiled. The applicaton itself is single-threaded.

The following tables show the elapsed time reported by JUnit for both unprofiles and profiles executions. The

WinXP Laptop

CPU JVM OS Scope Threads time
Option		 Overhead times: junit
Pentium M 1100 MHz Sun 1.5 client WinXP - - baseline 149 148 148 148



Default (~68m calls) Multi - 28% 189 190 189 190
count 10% 159 148 153 163




Single - 20% 177 176 178 176
count 0% 143 142 145 149



All (~1155m calls) Multi - 359% 678 680 681 680
count 71% 259 252 264 238




single - 226% 483 483 482 484
count
 5% 152 163 154 153
Pentium M 1100 MHz JRockIt WinXP - - 0% 157 162 148 151



Default Multi - 26% 188 192 183 182




Single - 20% 175 180 180 174



All Multi - 240% 509 496 498 510
count 37% 215 209




single - 127% 334 343 334 335
count 15% 176 179

Several remarks are in order:

The count option is a good starting point to determine packages to exclude from the scope, if the default doesn't work for you.

Linux non-SMP

These results are from a system with an Athlon 64 X2 4400 CPU with a Linux 2.6.9 non-SMP kernel (so only one of the two CPU cores gets used). 

In the following table, user time (and sometimes system time) from the Unix time (1) command are given in addition to the time reposted by JUnit. Overhead was calculated from the output of time, not the results reported from JUnit.

CPU JVM OS Scope Threads time Option Overhead
(CPU) 		times: junit (user)
Athlon 64 X2 4400 Sun 1.5 Linux 2.6.9 - - -
95
(77) 		94
(77) 		92
(76) 		91
(75)



Default Multi - 88% 157
(143) 		159
(145) 		156
(141) 		161
(147)




Single - 72% 147
(131) 		146
(131) 		146
(131) 		146
(131)





linuxSMPhack 57%
 148
(122)
(2) 		144
(119)
(2)






count 12% 100
(85)
(2) 		104
(87)
(2) 		102
(87)
(2)



All Multi - 850% 642
(647) 		641
(645) 		650
(646) 		644
(647)




Single - 611% 545
(543) 		550
(538) 		554
(543) 		553
(541)





linuxSMPhack 432% 407
(404) 		411
(406)






count 15%
 114
(91)
(2) 		111
(89)
(2) 		105
(82)
(2) 		108
(87)
(2)

Observations:

Linux SMP

These results are from the same hardware as above, but with an SMP kernel.

CPU JVM OS Scope Threads time option Overhead
(CPU) 		times: Junit (user) (sys)
Athlon 64 X2 4400 Sun 1.5 Linux 2.6.9 - - -
57
(67) 		61
(75) 		60
(73) 		60
(75)



Default Multi - 582% 461
(127)
(370) 		460
(129)
(371)





linuxSMPhack 79% 98
(129)
(3) 		99
(127)
(3)






count 18%
 66
(87)
(3) 		64
(89)
(2)




Single - 565%

454
(112)
(370) 		458
(118)
(372)





linuxSMPhack 60% 90
(110)
(3) 		92
(118)
(3)






count 18%
 62
(83)
(3) 		63
(83)
(3)




All Multi -
too slow > 2h exp.



linuxSMPhack 597%

459
(504)
(4) 		458
(505)
(4)






count 58%
 89
(114)
(2) 		92
(118)
(2)


Observatoins: