5

I am trying to profile that is often blocking in either database and rest calls. The code is not cpu bound. The following sample junit methods should illustrate the issue:

@RepeatedTest(10)
void fast() throws InterruptedException {
    Thread.sleep(100);
}

@RepeatedTest(10)
void slow() throws InterruptedException {
    // imagine a slow database or rest call or any other blocking code
    Thread.sleep(1000);
}

I am using IntelliJ and Java Flight Recorder. I expect that method fast is reported as using about 10% of execution time and method slow is using about 90% of execution time. But they are not reported at all because they don't eat CPU time.

How can I profile the real execution time that includes waiting time in blocking code instead of CPU time only?

bollin
  • 185
  • 11
  • It's very common to think what you need to do is measure the time. **No.** What you need to do is *locate* the problem. The exact percentage doesn't matter. [*Here's how.*](https://stackoverflow.com/a/317160/23771) – Mike Dunlavey Jun 13 '22 at 12:13
  • Using thread dumps can help of course. But they give me less information and they are harder to read compared to a flame graph of a properly configured profiler. – bollin Jun 14 '22 at 05:26
  • Here's the [*problem with flame-graphs.*](https://stackoverflow.com/a/27867426/23771) – Mike Dunlavey Jun 14 '22 at 11:55

2 Answers2

2

You need a profiler that understands the semantics of JDBC and HTTP calls. For example, with JProfiler, the profiling agent captures a synthetic Net I/O thread state that is included when the thread status selector is set to "All states".

enter image description here

Disclaimer: My company develops JProfiler

Ingo Kegel
  • 46,523
  • 10
  • 71
  • 102
2

Async profiler is an excellent, free, and very lightweight tool for JVM profiling. In typical settings, it indeed measures on-CPU time but it has an option to do "Wall-clock" profiling: https://github.com/jvm-profiling-tools/async-profiler#wall-clock-profiling

You can experiment with that and see if that gives you better results.

Juraj Martinka
  • 3,991
  • 2
  • 23
  • 25
  • Your suggestion does indeed help with profiling. I still have problems as it reports the main threads as eating only 1.82% of all time which makes finding my own code in the main thread hard. I'd expect a much higher value. But the relative results within the scope of my code are much more useful to me compared to CPU profiling. – bollin Jun 14 '22 at 05:19