asciidoctor-diagram: Performance regression with JRuby 9

I don’t if we are doing something wrong here but AsciidoctorJ with Asciidoctor Diagram is noticeably slower with JRuby 9:

@SevereOverfl0w made a sample project to reproduce this issue. It’s a Clojure project but it’s relatively easy to run it (and it will generate a flamegraph!): https://github.com/SevereOverfl0w/asciidoctor-diagram-slow-repro

Once Clojure is installed you should be able to run clojure -A:run.

You should see somthing like:

Warming up JIT with 30 calls
Timing 100 calls of .readDocumentHeader
"Elapsed time: 1793.124807 msecs"
Producing flamegraph for 100 runs
Started [cpu] profiling

And the flamegraph will looks weird with spikes on Asciidoctor Diagram.

Now if you edit the deps.edn file and add org.jruby/jruby-complete {:mvn/version "1.7.27"} (just after net.sourceforge.plantuml/plantuml {:mvn/version "1.2018.13"}) then the output will be:

Warming up JIT with 30 calls
Timing 100 calls of .readDocumentHeader
"Elapsed time: 963.936468 msecs"
Producing flamegraph for 100 runs
Started [cpu] profiling

and the spikes on Asciidoctor Diagram are gone…

About this issue

  • Original URL
  • State: closed
  • Created 5 years ago
  • Comments: 33 (28 by maintainers)

Commits related to this issue

Most upvoted comments

My next big project for JRuby is to fix up the require/load caching logic, which should prevent this from affecting anyone in the future. Glad to see you found a good solution that is not hacky and makes sense anyway!

@pepijnve The code is now faster in JRuby 9:

Warming up JIT with 30 calls
Timing 100 calls of .readDocumentHeader
Elapsed time: 802 msecs
Producing flamegraph for 100 runs
/tmp/clj-async-profiler/results/flamegraph-2019-02-25-11-56-25.svg

I’ll take a shot at profiling this with JProfiler later this evening. Perhaps that clarifies the difference in performance between jruby 1.7 and 9. I’ll let you know what I find (if anything).