java System.nanoTime is really slow. Is it possible to implement a high performance java profiler?
java
Solution
I've spent 10 years working on commercial Java performance profilers, for use in both development and production.
The short answer is - yes, you're right. You can't pull that off. And even if you could, putting anything but trivial instrumentation into a method that is called so frequently can:
Change the way the JIT treats the code, thus
skewing your performance numbers in hard to predict (but generally not useful, from a performance tuning standpoint) ways.
(and lets not get started on how making a system call in what is basically a tight assembly loop after the JIT is done with it affects all the fancy optimizations the CPU might otherwise be able to do in terms of prefetches, causing an otherwise unnecessary context switch and flushing your L1 cache, etc, etc)
It's OK to instrument slow (or maybe 'infrequently called' would be better?) methods. You can get away with instrumenting, for example, a lot of the JDBC API to catch database issues.
For actual performance tuning of actual Java code (as opposed to stuff Java calls into, like the network, filesystem, database, ...), instrumentation just isn't really the way to go. You get more understandable results, but no-one has done line-level instrumentation for performance tuning for probably 7 years now - same reasons.
Instead, commercial profilers use "sampling" technology - they periodically take a stack trace. JVMTI has some nice calls that make it pretty cheap to do so every few ms. Then you assume all the time between stack traces was spent on the new stack (which, obviously, isn't true, but statistically, it produces accurate results over a not-stupidly-short measurement period) - and you've got yourself some actionable performance numbers without crazy overhead or any kind of observer effect.
Problem
I did a test and found the overhead of a function call to System.nanoTime() is at least 500 ns on my machine. Seemed that it is very hard to have a high performance java profiler. For enterprise software, suppose a function takes about 350 seconds and has 12,500,000,000 times of method calls. Therefore, the number of calls to System.nanoTime() is: 12,500,000,000 * 2 = 25,000,000,000 (one for start timestamp, one for end timestamp) And the overhead of System.nanoTime in total is: 500 ns * 25,000,000,000 = 500 * 25000 s = 12500000s. Note: all data from real case. Any better way to acquire the timestamp?