71–80 of 81 posts
Earlier quoted context omitted.
400x slower than 70ns is still only 28us. How often is the JVM calling this function?
28us is still solid amount of time
Even called every frame 60 times per second, it's only 0.2% of a 60 fps time budget.
It's not a huge amount of time in absolute terms; only if it's relatively "hot."
Author of the OpenJDK patch here. Thanks for the write-up Jaromir :) For those interested, I explored memory overhead when reading /proc—including eBPF profiling and the history behind the poorly documented user-space ABI. Full details in my write-up: https://norlinder.nu/posts/User-CPU-Time-JVM/
So, why do you reckon they did that?
Earlier quoted context omitted.
It depends. If you’re doing continuous profiling, it’d make a call to get the current time at every method entry and exit, each of which could then add a context switch. In an absolute sense it appears to be small, but it could really add up. This is what flame graphs are super helpful for, to see whether it’s really a problem or not. Also, remember that every extra moment running instructions is a lost opportunity t…
If you are doing continuous profiling, you are probably using a low overhead stack sampling profiler rather than recording every method entry and exit.
Earlier quoted context omitted.
No, it is a very practical one and I'm actually surprised that you don't see it that way. Benchmarking is hard, and if you don't understand the basics then you can easily measure nonsense.
You raise a fair point about the percentiles. Those are reported as point estimates without confidence intervals and the implied precision overstates what system clock can deliver. The mean does get proper statistical treatment (t-distribution confidence interval), but you're right that JMH doesn't compute confidence intervals for percentiles. Reporting p0.00 with three significant figures is ... optimistic. That sai…
That said, at your CPU base frequency, 80ns is ~344 cycles, 70ns is ~300 cycles. That's ~40 cycles of difference. That's on the order of ~2x CPU pipeline flushes due to branch mispredictions. Or another example is RDTSCP which, at least on Intel CPUs, forces all prior instructions to retire before executing, and it prevents speculative execution of following instructions until theirs results are available. This can also impose a 10-30 cycle penalty. Both of these can interfere with the measurements of the scale you have so there is a possibility that you're measuring these effects instead of the optimization you thought you implemented.
I am not saying that this is the case, I am just saying it's possible. Since the test is simple enough I would eliminate other similar CPU level gotchas that can screw your hypothesis testing up. In more complex scenarios I would have to consider them as well.
The only reliable way I found to be sure what is really happening is to read the codegen. And I do that _before_ each test run, or to be more precise after each recompile, because compilers do crazy transformations with our code, even when just moving a naively looking function few lines above or adding some naive boolean flag. If I don't do that, I could again end up measuring, observing, and finally drawing the conclusion that I implemented a speedup without realizing that the compiler in that last case decided to eliminate half of the code because of that innocuous boolean flag. Just an example.
radix tree lookup looks interesting and it would be interesting to see at what exact instruction does it idle on. I had a case where the function would be sitting idle, reproducible, but when you look into the function there is nothing obvious you can optimize. It turned out that the CPU pipeline was so saturated that there were no more available CPU ports for the instruction this function was idling for. The fix was to rewrite code elsewhere but in vicinity of this function. This is something flamegraphs can never show you, which is partly the reason I had never been a huge fan of.
Earlier quoted context omitted.
I also like icicle graphs for this. They're flamegraphs, but aggregated in the reverse order. (I.e. if you have calls A->B->C and D->E->C, then both calls to C are aggregated together, rather than being stacked on top of B and E respectively. It can make it easier to see what's wrong when you have a bunch of distinct codepaths that all invoke a common library where you're spending too much time.) Regular flamegraphs…
So someone else linked the original flamegraph site [0] and it describes icicle graphs as "inverting the y axis" but that's not only what's happening, right? You bucket top-down the stack opposed to bottom-up, correct? [0] https://www.brendangregg.com/flamegraphs.html
Author of the OpenJDK patch here. Thanks for the write-up Jaromir :) For those interested, I explored memory overhead when reading /proc—including eBPF profiling and the history behind the poorly documented user-space ABI. Full details in my write-up: https://norlinder.nu/posts/User-CPU-Time-JVM/
Why do you suppose it was originally written the way it was? To my eyes, that seems like a horrible approach. Doing file IO and parsing strings in every call? What?! And yet I assume the original author was a smart person who had a reason why this made sense to them, and my inability to guess why is my own limitation and not theirs. So, why do you reckon they did that?
The method in question (Java 1.5) was released in September 2004. While the POSIX standard existed, it only provided a way to get total CPU time, not the specific user time that Java needed. You can read about it more in the history section here: https://norlinder.nu/posts/User-CPU-Time-JVM/#a-walk-through....
But it's worth noting that while this specific case can be "fixed" with a function call, parsing /proc is still the standard way to get data in Linux.
Even today, a vast amount of kernel telemetry is only exposed via the filesystem. If you look at the source code for tools like htop, they are still busy parsing text files from /proc to get memory stats (/proc/meminfo), network I/O, or per-process limits. See here https://github.com/hishamhm/htop/blob/master/linux/LinuxProc....
Author of the OpenJDK patch here. Thanks for the write-up Jaromir :) For those interested, I explored memory overhead when reading /proc—including eBPF profiling and the history behind the poorly documented user-space ABI. Full details in my write-up: https://norlinder.nu/posts/User-CPU-Time-JVM/
Hi Jonas, thanks for the work on OpenJDK and the post! I swear I hadn't seen your blog :) I finished my draft around Christmas and it’s been in the queue since. Great minds think alike, I guess. edit: I just read your blog in full and I have to say I like it more than mine. You put a lot more rigor into it. I’m just peeking into things. edit2: I linked your article from my post.
Earlier quoted context omitted.
Why do you suppose it was originally written the way it was? To my eyes, that seems like a horrible approach. Doing file IO and parsing strings in every call? What?! And yet I assume the original author was a smart person who had a reason why this made sense to them, and my inability to guess why is my own limitation and not theirs. So, why do you reckon they did that?
You are spot on that the original author had a valid reason: at the time, it was literally the only way to do it. The method in question (Java 1.5) was released in September 2004. While the POSIX standard existed, it only provided a way to get total CPU time, not the specific user time that Java needed. You can read about it more in the history section here: https://norlinder.nu/posts/User-CPU-Time-JVM/#a-walk-throug…
I knew about using proc for all that other information. I just wouldn’t have imagined using it for critical performance path. Unless, that is, that’s the way you have to get the information.
> Flame graph image > Click to zoom, open in a new tab for interactivity I admit I did not expect "Open Image in New Tab" to do what it said on the tin. I guess I was aware that it was possible with SVG but I don't think I've ever seen it done and was really not expecting it.
Courtesy of Brendan Gregg and his flamegraph.pl scripts: https://github.com/brendangregg/FlameGraph Normally, I use the generator included in async-profiler. It produces interactive HTML. But for this post, I used Brendan’s tool specifically to have a single, interactive SVG.
Also `samply` and the Firefox profiler are pretty fancy too.
There's really no reason to use the original flamegraph scripts.
Earlier quoted context omitted.
In Java it can be a bad toString() implementation hiding behind a + used for string assembly. Or another great one: new instances of ObjectMapper created inside a method for a single call and then thrown away.
To be clear this is often sloppy code that shouldn’t have been written. But in a legacy codebase this stuff can easily happen.
Unless you're inheriting code written by Bill Atkinson or something.