asciidoctor / asciidoctorj

:coffee: Java bindings for Asciidoctor. Asciidoctor on the JVM!
http://asciidoctor.org
Apache License 2.0
624 stars 173 forks source link

Concurrent use of AsciidoctorJ `Asciidoctor` interface results in `ConcurrentModificationException` #1158

Closed rocketraman closed 1 year ago

rocketraman commented 1 year ago

I'm testing using the Asciidoctor interface in concurrent code. I am able to reproduce this error reasonably consistently (though not every time) simply by starting 100 concurrent threads that all convert asciidoc to PDF. My conversion code looks like this:

      asciidoctor.convert(
        adoc,
        Options.builder()
          .backend("pdf")
          .headerFooter(true)
          .attributes(
            Attributes.builder()
              .attribute(
                "pdf-theme",
                "uri:classloader:/my/package/render/pdf/theme.yml"
              )
              .attribute(
                "pdf-fontsdir",
                "uri:classloader:/my/package/render/pdf/fonts;GEM_FONTS_DIR"
              )
              .attribute("imagesdir", "uri:classloader:/my/package/render/pdf/")
              .build()
          )
          .safe(SafeMode.UNSAFE)
          .toStream(outputStream)
          .build()
      )

The exception is:

java.util.ConcurrentModificationException
    at java.base/java.util.HashMap.computeIfAbsent(HashMap.java:1221)
    at org.jruby.Ruby.addBoundMethod(Ruby.java:2955)
    at org.jruby.anno.TypePopulator$ReflectiveTypePopulator.addBoundMethodsUnlessOmitted(TypePopulator.java:140)
    at org.jruby.anno.TypePopulator$ReflectiveTypePopulator.populate(TypePopulator.java:127)
    at org.jruby.RubyModule.defineAnnotatedMethodsIndividually(RubyModule.java:1296)
    at org.jruby.RubyModule.defineAnnotatedMethods(RubyModule.java:1203)
    at org.asciidoctor.jruby.internal.RubyOutputStreamWrapper.getOrCreateOutputStreamWrapperClass(RubyOutputStreamWrapper.java:63)
    at org.asciidoctor.jruby.internal.RubyOutputStreamWrapper.wrap(RubyOutputStreamWrapper.java:28)
    at org.asciidoctor.jruby.internal.JRubyAsciidoctor.convert(JRubyAsciidoctor.java:304)
    at org.asciidoctor.jruby.internal.JRubyAsciidoctor.convert(JRubyAsciidoctor.java:336)
    at org.asciidoctor.jruby.internal.JRubyAsciidoctor.convert(JRubyAsciidoctor.java:331)
    at my.package.MyClass.generatePdf(MyClass.kt:139)
    at my.package.MyClass$generatePdf$1.invokeSuspend(MyClass.kt)

I also see the following warnings:

(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
(unknown):0: warning: already initialized constant AsciidoctorJ::OutputStreamWrapper
WARNING: while creating new bindings for class org.asciidoctor.jruby.internal.RubyOutputStreamWrapper,
found an existing binding; you may want to run a clean build.
WARNING: while creating new bindings for class org.asciidoctor.jruby.internal.RubyOutputStreamWrapper,
found an existing binding; you may want to run a clean build.
WARNING: while creating new bindings for class org.asciidoctor.jruby.internal.RubyOutputStreamWrapper,
found an existing binding; you may want to run a clean build.
WARNING: while creating new bindings for class org.asciidoctor.jruby.internal.RubyOutputStreamWrapper,
found an existing binding; you may want to run a clean build.
rocketraman commented 1 year ago

This should probably be moved to the asciidoctorj repository, I apologize for putting it in the wrong place.

robertpanzer commented 1 year ago

Do you get this issue as well if you first convert a document once, and after that start your concurrent threads?

rocketraman commented 1 year ago

Do you get this issue as well if you first convert a document once, and after that start your concurrent threads?

Nope, I am unable to replicate the issue after doing a single conversion, and there are no warning messages printed either. The problem appears to be with concurrent initalization.

An effective workaround (in Kotlin) appears to be to run an extremely simple conversion at initialization time:

  private val asciidoctor: Asciidoctor by lazy {
    Asciidoctor.Factory.create().apply {
      // do a one-time conversion to initialize it, as initialization doesn't appear to be thread-safe
      // see https://github.com/asciidoctor/asciidoctorj/issues/1158
      ByteArrayOutputStream().use {
        convert("= Hello", Options.builder().backend("pdf").safe(SafeMode.UNSAFE).toStream(it).build())
      }
    }
  }
mojavelinux commented 1 year ago

The problem appears to be with concurrent initalization.

If memory serves me correctly, JRuby is not thread-safe when loading gems, but once everything is loaded, AsciidoctorJ is thread-safe.

rocketraman commented 1 year ago

The problem appears to be with concurrent initalization.

If memory serves me correctly, JRuby is not thread-safe when loading gems, but once everything is loaded, AsciidoctorJ is thread-safe.

In that case, it sounds like the gems should be loaded eagerly when the factory is created rather than waiting until the first conversion? Or alternatively, load them lazily but wrapped such that only one thread can load the gems (as in my workaround snippet above).

mojavelinux commented 1 year ago

I agree that if the claim is correct, action may be warranted. But let's prove it first before making any decisions based on it. As I said, it was only based on my memory of past experiences. Let's sure up the facts first.

rocketraman commented 1 year ago

I agree that if the claim is correct, action may be warranted. But let's prove it first before making any decisions based on it. As I said, it was only based on my memory of past experiences. Let's sure up the facts first.

Fair enough. Let me know if I can help with testing or whatever. I'm not super-familiar with Ruby/JRuby.

robertpanzer commented 1 year ago

I can provide a fix for that. I think I have a clear idea what is going wrong.