Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8297285

Shenandoah pacing causes assertion failure during VM initialization

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Fixed
    • Icon: P4 P4
    • 20
    • 20
    • hotspot
    • gc
    • b27

      Shenandoah pacing hits the following assert with fastdebug build if the allocation credit is exhausted during VM initialization.
      Command to recreate:

      $ java -XX:+UseShenandoahGC -Xmx32m -XX:+UnlockExperimentalVMOptions -XX:ShenandoahPacingIdleSlack=1 -version

      Assertion:

      # Internal Error (/home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/runtime/mutex.cpp:235), pid=925459, tid=925460
      # assert(self->is_active_Java_thread()) failed: invariant

      Upon credit exhaustion, the pacing algorithm (in ShenandoahPacer::pace_for_alloc()) tries to delay the progress of allocating thread by doing a timed wait on a MonitorLocker (in ShenandoahPacer::wait()) which asserts as the main thread is not yet in the thread list. Main thread is added to the thread list much later during initialization.

      Relevant stack trace at the time of assertion is:

      #5 0x00007f25a184af6b in report_vm_error (file=file@entry=0x7f25a2a12e30 "/home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/runtime/mutex.cpp", line=line@entry=235,
          error_msg=error_msg@entry=0x7f25a2a13658 "assert(self->is_active_Java_thread()) failed", detail_fmt=detail_fmt@entry=0x7f25a2a6af8b "invariant")
          at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/runtime/thread.hpp:651
      #6 0x00007f25a21c3e39 in Monitor::wait (this=0x7f259c0e09f0, timeout=timeout@entry=10) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/runtime/mutex.cpp:235
      #7 0x00007f25a24d01b5 in ShenandoahPacer::wait (this=this@entry=0x7f259c0e0740, time_ms=10) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shenandoah/shenandoahPacer.cpp:279
      #8 0x00007f25a24d03b0 in ShenandoahPacer::pace_for_alloc (this=0x7f259c0e0740, words=<optimized out>) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shenandoah/shenandoahPacer.cpp:256
      #9 0x00007f25a2474391 in ShenandoahHeap::allocate_memory (this=0x7f259c0b4230, req=...) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shenandoah/shenandoahAllocRequest.hpp:91
      #10 0x00007f25a247465f in ShenandoahHeap::allocate_new_tlab (this=<optimized out>, min_size=256, requested_size=9834, actual_size=0x7f25a3f1c830)
          at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shenandoah/shenandoahHeap.cpp:798
      #11 0x00007f25a210dc5d in MemAllocator::allocate_inside_tlab_slow (this=this@entry=0x7f25a3f1c8a0, allocation=...) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/memory/universe.hpp:311
      #12 0x00007f25a210ef9e in MemAllocator::allocate_inside_tlab (allocation=..., this=0x7f25a3f1c8a0) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shared/memAllocator.cpp:280
      #13 MemAllocator::mem_allocate (allocation=..., this=0x7f25a3f1c8a0) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shared/memAllocator.cpp:356
      #14 MemAllocator::allocate (this=this@entry=0x7f25a3f1c8a0) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shared/memAllocator.cpp:369
      #15 0x00007f25a1c0f70e in CollectedHeap::array_allocate (do_zero=true, this=<optimized out>, __the_thread__=0x7f259c099890, length=3, size=<optimized out>, klass=<optimized out>)
          at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/gc/shared/collectedHeap.inline.hpp:41
      #16 InstanceKlass::allocate_objArray (this=this@entry=0x800000f70, n=n@entry=1, length=length@entry=3, __the_thread__=__the_thread__@entry=0x7f259c099890)
          at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/oops/instanceKlass.cpp:1350
      #17 0x00007f25a223e2e0 in oopFactory::new_objArray (klass=0x800000f70, length=3, __the_thread__=__the_thread__@entry=0x7f259c099890)
          at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/oops/instanceKlass.hpp:927
      #18 0x00007f25a17e4e9e in ConstantPool::restore_unshareable_info (this=0x800692bb0, __the_thread__=__the_thread__@entry=0x7f259c099890)
          at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/classfile/vmClasses.hpp:56
      #19 0x00007f25a27667ea in vmClasses::resolve_all (__the_thread__=__the_thread__@entry=0x7f259c099890) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/oops/instanceKlass.hpp:643
      #20 0x00007f25a2643719 in SystemDictionary::initialize (__the_thread__=__the_thread__@entry=0x7f259c099890) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/classfile/systemDictionary.cpp:1712
      #21 0x00007f25a26e0125 in Universe::genesis (__the_thread__=__the_thread__@entry=0x7f259c099890) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/memory/universe.cpp:346
      #22 0x00007f25a26e0d65 in universe2_init () at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/memory/universe.cpp:967
      #23 0x00007f25a1c0be9a in init_globals () at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/runtime/init.cpp:136
      #24 0x00007f25a26b4a7f in Threads::create_vm (args=args@entry=0x7f25a3f1ce90, canTryAgain=canTryAgain@entry=0x7f25a3f1cdcf) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/runtime/threads.cpp:570
      #25 0x00007f25a1da6839 in JNI_CreateJavaVM_inner (args=0x7f25a3f1ce90, penv=0x7f25a3f1ce88, vm=0x7f25a3f1ce80) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/prims/jni.cpp:3624
      #26 JNI_CreateJavaVM (vm=0x7f25a3f1ce80, penv=0x7f25a3f1ce88, args=0x7f25a3f1ce90) at /home/asmehra/data/ashu-mehra/jdk/src/hotspot/share/prims/jni.cpp:3710
      #27 0x00007f25a38e4eea in InitializeJVM (ifn=<synthetic pointer>, penv=0x7f25a3f1ce88, pvm=0x7f25a3f1ce80) at /home/asmehra/data/ashu-mehra/jdk/src/java.base/share/native/libjli/java.c:1457


      Although this is less likely to happen with current code base, but I started hitting it when working on JDK-8293650 as it increases heap allocation during JVM initialization.

            asmehra Ashutosh Mehra
            asmehra Ashutosh Mehra
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: