Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[GR-62070] Increased debug info size in comparison to GraalVM for JDK 23 #10512

Open
zakkak opened this issue Jan 20, 2025 · 12 comments
Open

[GR-62070] Increased debug info size in comparison to GraalVM for JDK 23 #10512

zakkak opened this issue Jan 20, 2025 · 12 comments

Comments

@zakkak
Copy link
Collaborator

zakkak commented Jan 20, 2025

Describe the issue
The debug info generated with the latest graal master is larger than that generated with GraalVM for JDK 23, resulting in GDB taking more time to load symbols.

Steps to reproduce the issue

git clone https://github.com/Karm/mandrel-integration-tests/
cd mandrel-integration-tests/apps/debug-symbols-smoke
mvn package
native-image -g -jar target/debug-symbols-smoke.jar target/debug-symbols-smoke
cat > gdb.cmd <<EOF
run < test_data_small.txt
info functions .*smoke.*
exit
EOF
time (for i in {1..10}; do echo $i; gdb ./target/debug-symbols-smoke < gdb.cmd done)

Describe GraalVM and your environment:

  • GraalVM version (latest snapshot builds can be found here), or commit id if built from source: CE 23.0.1 and bbdf41b
  • JDK major version: 23 and 25
  • OS: Fedora 41
  • Architecture: AMD64

More details

Locally it takes 27.798 seconds for the 10 iterations when using GraalVM for JDK 23 and 37.218 seconds when using GraalVM for JDK 25.

@zakkak
Copy link
Collaborator Author

zakkak commented Jan 21, 2025

FYI @olpaw

@selhagani selhagani self-assigned this Jan 21, 2025
@fniephaus
Copy link
Member

Could be related to #9802

@selhagani
Copy link
Member

Hi @zakkak,

Thank you for reaching out to us about this.
I ran the tests on my aarch64 linux machine and I got the following results:

Image Image

It seems like running things on GraalVM for JDK 25 is a few seconds faster than on GraalVM for JDK 23.
Perhaps this is limited to AMD64?

@zakkak
Copy link
Collaborator Author

zakkak commented Jan 22, 2025

It seems like running things on GraalVM for JDK 25 is a few seconds faster than on GraalVM for JDK 23.
Perhaps this is limited to AMD64?

That's interesting.

cc @Karm

@selhagani selhagani changed the title Increased debug info size in comparison to GraalVM for JDK 23 [GR-61688] Increased debug info size in comparison to GraalVM for JDK 23 Jan 28, 2025
@selhagani selhagani changed the title [GR-61688] Increased debug info size in comparison to GraalVM for JDK 23 Increased debug info size in comparison to GraalVM for JDK 23 Jan 29, 2025
@selhagani
Copy link
Member

After reviewing it seems like the results on Linux for amd64 also showed that GraalVM for JDK 25 is faster than on GraalVM for JDK 23.

Image

Image

@zakkak
Copy link
Collaborator Author

zakkak commented Jan 29, 2025

@selhagani I tried reproducing the issue once more and it seems to persist, except for the debug info size which now (that I tested with a newer build) seems to be larger in GraalVM for JDK 23 than in GraalVM for JDK 25. Can you please also check the debug info size of the generated binaries in your case?

Apples to Oranges, or GraalVM CE to Oracle GraalVM, comparison.

I am getting

Java version: 23.0.2+7, vendor version: GraalVM CE 23.0.2+7.1 (sdk install java 23.0.2-graalce)

   6.57MB (22.13%) for code area:    10,568 compilation units
   9.06MB (30.52%) for image heap:  116,495 objects and 80 resources
  12.37MB (41.65%) for debug info generated in 0.5s
   1.69MB ( 5.69%) for other data
  29.69MB in total
❯ hyperfine "gdb ./target/debug-symbols-smoke < gdb.cmd"
Benchmark 1: gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      2.855 s ±  0.028 s    [User: 2.827 s, System: 0.080 s]
  Range (min … max):    2.822 s …  2.903 s    10 runs

Java version: 25+5-LTS, vendor version: Oracle GraalVM 25-dev+5.1 (sdk install java 25.ea.6-graal)

   6.79MB (24.51%) for code area:     8,539 compilation units
   7.27MB (26.27%) for image heap:  107,743 objects and 55 resources
  11.93MB (43.07%) for debug info generated in 0.6s
   1.70MB ( 6.15%) for other data
  27.69MB in total
❯ hyperfine "gdb ./target/debug-symbols-smoke < gdb.cmd"
Benchmark 1: gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      3.274 s ±  0.089 s    [User: 3.235 s, System: 0.102 s]
  Range (min … max):    3.130 s …  3.391 s    10 runs

Please see #10512 (comment) instead.

@selhagani
Copy link
Member

I just retested using the latest version of GraalVM for JDK 23 (23.0.2) and the latest available Dev build for JDK 25 and I got the following results:

with GraalVM for JDK 23 Community 23.0.2 I get:

   6.25MB (20.91%) for code area:    10,557 compilation units
   9.00MB (30.10%) for image heap:  115,429 objects and 55 resources
  12.47MB (41.71%) for debug info generated in 1.9s
   2.18MB ( 7.28%) for other data
  29.90MB in total
debug_symbols_smoke.Main$$Lambda/0x2672b2fcc272dcf55fe47efd0ea63ad20::accept(java.lang.Object*);
50:	void debug_symbols_smoke.Main::lambda$thisIsTheEnd$0(java.io.ByteArrayOutputStream*, debug_symbols_smoke.ClassA*);
64:	void debug_symbols_smoke.Main::main(java.lang.String[]*);
49:	void debug_symbols_smoke.Main::thisIsTheEnd(java.util.List*);
(gdb) 
real	0m33.343s
user	0m32.915s
sys	0m0.694s
hyperfine "gdb ./target/debug-symbols-smoke < gdb.cmd"
Benchmark 1: gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean \u00b1 \u03c3):      3.254 s \u00b1  0.159 s    [User: 3.232 s, System: 0.048 s]
  Range (min \u2026 max):    3.011 s \u2026  3.449 s    10 runs

with GraalVM CE 25.0.0-dev-20250208_1102 I get:

   5.38MB (20.88%) for code area:     8,915 compilation units
   8.13MB (31.55%) for image heap:  100,532 objects and 55 resources
  10.13MB (39.33%) for debug info generated in 1.5s
   2.12MB ( 8.24%) for other data
  25.76MB in total
File debug_symbols_smoke/Main.java:
	void debug_symbols_smoke.Main$$Lambda/0x2672b2fcc272dcf55fe47efd0ea63ad20::accept(java.lang.Object*);
50:	void debug_symbols_smoke.Main::lambda$thisIsTheEnd$0(java.io.ByteArrayOutputStream*, debug_symbols_smoke.ClassA*);
64:	void debug_symbols_smoke.Main::main(java.lang.String[]*);
49:	void debug_symbols_smoke.Main::thisIsTheEnd(java.util.List*);
(gdb) 
real	0m28.133s
user	0m27.448s
sys	0m0.830s
hyperfine "gdb ./target/debug-symbols-smoke < gdb.cmd"
Benchmark 1: gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean \u00b1 \u03c3):      2.619 s \u00b1  0.154 s    [User: 2.570 s, System: 0.075 s]
  Range (min \u2026 max):    2.411 s \u2026  2.800 s    10 runs

I will be sharing these results with our team and I'll keep you updated with any news.

@selhagani selhagani changed the title Increased debug info size in comparison to GraalVM for JDK 23 [GR-62070] Increased debug info size in comparison to GraalVM for JDK 23 Feb 10, 2025
@selhagani selhagani assigned dougxc and unassigned selhagani Feb 10, 2025
@dougxc dougxc assigned wirthi and unassigned dougxc Feb 10, 2025
@olpaw
Copy link
Member

olpaw commented Feb 20, 2025

@zakkak in #10512 (comment) you are comparing apples to oranges.

To get any meaningful results for comparison for debuginfo generation time and size you have to test Oracle GraalVM Version X to Oracle GraalVM Version Y (or GraalVM CE X to GraalVM CE Y).

Comparing Oracle GraalVM X to GraalVM CE Y will lead to a distorted view because Oracle GraalVM is much more aggressively inlining and therefore the debuginfo generator will more often have to process compilation results with deep inlining trees (which is more effort).

Please provide data for e.g. GraalVM CE 23 to GraalVM CE 25.

I do not expect the changes @dominikmascherbauer implemented (that show up in 25) to cause any debuginfo generation performance regressions. Regarding debuginfo size, improvements (smaller size) are expected because he switched output to generate DWARF5 (which is more compact)

@zakkak
Copy link
Collaborator Author

zakkak commented Feb 20, 2025

Good catch @olpaw I got carried away with the easy of getting an early build from sdkman that didn't notice that it was Oracle GraalVM instead of CE (and yes I didn't even notice when copy pasting the version over...). Thanks for pointing this out.

So back to apples to apples (or as close as I can get to that :) )

Java version: 23.0.2+7, vendor version: GraalVM CE 23.0.2+7.1 (sdk install java 23.0.2-graalce)

   6.57MB (22.13%) for code area:    10,568 compilation units
   9.06MB (30.52%) for image heap:  116,484 objects and 80 resources
  12.37MB (41.65%) for debug info generated in 0.7s
   1.69MB ( 5.69%) for other data
  29.69MB in total
❯ hyperfine "gdb ./target/debug-symbols-smoke < gdb.cmd"
Benchmark 1: gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      2.834 s ±  0.067 s    [User: 2.800 s, System: 0.088 s]
  Range (min … max):    2.732 s …  2.940 s    10 runs

Java version: 25+9, vendor version: GraalVM CE 25-dev+9.1 (installed using GraalVM for JDK 25.0.0-dev-20250219_0536 dev build)

   5.58MB (22.01%) for code area:     8,934 compilation units
   8.13MB (32.05%) for image heap:  101,181 objects and 55 resources
  10.04MB (39.60%) for debug info generated in 0.5s
  11.65MB (45.94%) for other data
  25.36MB in total
❯ hyperfine "gdb ./target/debug-symbols-smoke < gdb.cmd"
Benchmark 1: gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      3.657 s ±  0.055 s    [User: 3.629 s, System: 0.082 s]
  Range (min … max):    3.590 s …  3.754 s    10 runs

The key points remain present:

  1. gdb takes longer to load debug info for binaries generated with GraalVM for JDK 25
  2. debug info size is smaller in binaries generated with GraalVM for JDK 25

Regarding debuginfo size, improvements (smaller size) are expected because he switched output to generate DWARF5 (which is more compact)

I wonder if the more compact representation of DWARF5 is the one responsible for the additional overhead. But what I am really curious about is why/how @selhagani seems to be getting exactly the oposite results (in terms of performance not size).

@olpaw
Copy link
Member

olpaw commented Feb 20, 2025

But what I am really curious about is why/how @selhagani seems to be getting exactly the oposite results (in terms of performance not size).

Different versions of GDB maybe?

Before @dominikmascherbauer merged his PR I requested that he checks for such regressions and he also did not see GDB load times to get worse with DWARF5. But even if load times would indeed slightly regress, having smaller .debug files is definitely worth it.

@dominikmascherbauer
Copy link
Contributor

That's some interesting observations, I did not see such results in my checks.
I did some testing of my own, also with different versions of GDB (which made a huge difference in load times).

Overall it shows similar results to @zakkak (on my amd64 machine), with slower load times for the updated DWARF5 debug info.
However, when I force reading full symbols with --readnow in GDB, execution times are almost equal between DWARF4 and DWARF5 dfebug info and faster(!) than running without --readnow.
(I just added the --readnow run for GDB 15, but it showed similar results throughout)

GDB 10.2

Benchmark 1: /home/dominik/projects/gdb-builds/gdb10/bin/gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):     543.4 ms ±   8.2 ms    [User: 498.4 ms, System: 61.9 ms]
  Range (min … max):   524.9 ms … 555.1 ms    10 runs
 
Benchmark 1: /home/dominik/projects/gdb-builds/gdb10/bin/gdb ./target/debug-symbols-smoke-dwarf4 < gdb.cmd
  Time (mean ± σ):     534.1 ms ±   9.7 ms    [User: 485.7 ms, System: 65.2 ms]
  Range (min … max):   521.2 ms … 552.4 ms    10 runs

GDB 11.2

Benchmark 1: /home/dominik/projects/gdb-builds/gdb11/bin/gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      1.186 s ±  0.014 s    [User: 1.142 s, System: 0.060 s]
  Range (min … max):    1.172 s …  1.218 s    10 runs
 
Benchmark 1: /home/dominik/projects/gdb-builds/gdb11/bin/gdb ./target/debug-symbols-smoke-dwarf4 < gdb.cmd
  Time (mean ± σ):      1.267 s ±  0.012 s    [User: 1.222 s, System: 0.061 s]
  Range (min … max):    1.250 s …  1.284 s    10 runs

GDB 12.1

Benchmark 1: /home/dominik/projects/gdb-builds/gdb12/bin/gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      1.160 s ±  0.010 s    [User: 1.122 s, System: 0.056 s]
  Range (min … max):    1.144 s …  1.176 s    10 runs

Benchmark 1: /home/dominik/projects/gdb-builds/gdb12/bin/gdb ./target/debug-symbols-smoke-dwarf4 < gdb.cmd
  Time (mean ± σ):      1.253 s ±  0.014 s    [User: 1.213 s, System: 0.058 s]
  Range (min … max):    1.236 s …  1.286 s    10 runs

GDB 13.2

Benchmark 1: /home/dominik/projects/gdb-builds/gdb13/bin/gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      3.484 s ±  0.016 s    [User: 3.515 s, System: 0.094 s]
  Range (min … max):    3.460 s …  3.508 s    10 runs
 
Benchmark 1: /home/dominik/projects/gdb-builds/gdb13/bin/gdb ./target/debug-symbols-smoke-dwarf4 < gdb.cmd
  Time (mean ± σ):      2.427 s ±  0.007 s    [User: 2.441 s, System: 0.087 s]
  Range (min … max):    2.418 s …  2.441 s    10 runs

GDB 14.2

Benchmark 1: /home/dominik/projects/gdb-builds/gdb14/bin/gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      3.483 s ±  0.012 s    [User: 3.512 s, System: 0.097 s]
  Range (min … max):    3.470 s …  3.502 s    10 runs
 
Benchmark 1: /home/dominik/projects/gdb-builds/gdb14/bin/gdb ./target/debug-symbols-smoke-dwarf4 < gdb.cmd
  Time (mean ± σ):      2.440 s ±  0.008 s    [User: 2.458 s, System: 0.087 s]
  Range (min … max):    2.420 s …  2.451 s    10 runs

GDB 15.2

Benchmark 1: /home/dominik/projects/gdb-builds/gdb15/bin/gdb ./target/debug-symbols-smoke < gdb.cmd
  Time (mean ± σ):      4.391 s ±  0.018 s    [User: 4.422 s, System: 0.085 s]
  Range (min … max):    4.366 s …  4.419 s    10 runs
 
Benchmark 1: /home/dominik/projects/gdb-builds/gdb15/bin/gdb ./target/debug-symbols-smoke-dwarf4 < gdb.cmd
  Time (mean ± σ):      2.860 s ±  0.012 s    [User: 2.865 s, System: 0.079 s]
  Range (min … max):    2.842 s …  2.873 s    10 runs

GDB 15.2 with --readnow

Benchmark 1: /home/dominik/projects/gdb-builds/gdb15/bin/gdb ./target/debug-symbols-smoke --readnow < gdb.cmd
  Time (mean ± σ):      1.504 s ±  0.007 s    [User: 1.457 s, System: 0.062 s]
  Range (min … max):    1.494 s …  1.514 s    10 runs
 
Benchmark 1: /home/dominik/projects/gdb-builds/gdb15/bin/gdb ./target/debug-symbols-smoke-dwarf4 --readnow < gdb.cmd
  Time (mean ± σ):      1.537 s ±  0.011 s    [User: 1.490 s, System: 0.062 s]
  Range (min … max):    1.518 s …  1.547 s    10 runs

@olpaw
Copy link
Member

olpaw commented Feb 24, 2025

I did some testing of my own, also with different versions of GDB (which made a huge difference in load times).

In other words, from GDB 13 onwards loading times (for GDB command info functions .*smoke.*) for DWARF5 debuginfo are significantly worse compared to DWARF4 (unless --readnow is used). cc @zakkak @adinn

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

8 participants