Skip to content
Joseph Kulig edited this page Apr 9, 2022 · 11 revisions

What' Happening

April 9, 2022

Made it through a garbage collection cycle but stuck in the blockForGC()

Thread # 4 deferring yield!
Execute SimplePhase(closure) as Global...
Execute SimplePhase(closure) as Collector...
Thread  4:     Processing GC in parallel
Thread # 4 deferring yield!
Thread  4:     processing gray objects
Thread # 4 deferring yield!
Execute SimplePhase(old-root) as Global...
Execute SimplePhase(old-root) as Collector...
Execute SimplePhase(new-root) as Global...
Execute SimplePhase(new-root) as Collector...
Thread # 4 deferring yield!
Execute SimplePhase(mods) as Mutator...
Thread # 4 deferring yield!
RExecute SimplePhase(mods) as Global...
Execute SimplePhase(mods) as Collector...
Thread # 4 deferring yield!
RThread # 4 deferring yield!
RThread # 4 deferring yield!
RThread # 4 deferring yield!
Execute SimplePhase(decs) as MutThread # 4 deferring yield!
ator...
Execute SimplePhase(decs) as Global...
Execute SimplePhase(decs) as Collector...
Thread # 4 deferring yield!
RExecute SimplePhase(closure-bt) as Global...
Execute SimplePhase(closure-bt) as Collector...
Execute SimplePhase(release) as Mutator...
Thread # 4 deferring yield!
Execute SimplePhase(release) as Collector...
Execute SimplePhase(release) as Global...
Thread # 4 deferring yield!
Execute SimplePhase(complete) as Collector...
Execute SimplePhase(complete) as Global...
Thread # 4 deferring yield!
   After Collection: used = 3.68 Mb = boot 0.00 Mb + immortal 0.00 Mb + meta 0.00 Mb + los 0.00 Mb + sanity 0.00 Mb + non-moving 0.00 Mb + sm-code 0.00 Mb + lg-code 0.00 Mb + rc 1.22 Mb + rclos 2.46 Mb
                     used = 944 pgs = boot 0 pgs + immortal 0 pgs + meta 1 pgs + los 0 pgs + sanity 0 pgs + non-moving 0 pgs + sm-code 0 pgs + lg-code 0 pgs + rc 313 pgs + rclos 630Thread # 4 deferring yield!
 pgs
Key: (I)mmortal (N)onmoving (D)iscontiguous (E)xtent (F)raction
     HEAP_START 0x0000000001000000
AVAILABLE_START 0x0000000005c00000
       boot IN  0x0000000001000000->0x0000000005bfffff E 0x000000000Thread # 4 deferring yield!
4c00000
   immortal IND []
       meta  ND [0x0000000006000000->0x00000000063fffff]
        los  ND []
     sanity  ND []
 non-moving  ND []
    sm-code  ND []
    lg-code  ND []
         rc  ND [0x0000000005c00000->0x0000000005ffffff]
      rclos  ND [0x0000000006400000->0x00000000067fffff]
Thread # 4 deferring yield!
R  AVAILABLE_END 0x00000000f0000000
       HEAP_END 0x00000000f0000000
                     reserved = 3 MB (944 pgs)      used = 3 MB (944 pgs)      total = 16 MB (4096 pgs)
    Collection time: 160.11 ms
[STWController: Worker threads complete!]
[STWController: Resuming mutators...]
Thread # 5 is requesting that thread # 10 unblocks.
Thread # 5 is done requesting that thread # 10 unblocks.
Thread # 5 is requesting that thread # 3 unblocks.
Thread # 5 is done requesting that thread # 3 unblocks.
Thread # 5 is requesting that thread # 7 unblocks.
Thread # 5 is done requesting that thread # 7 unblocks.
Thread # 5 is requesting that thread # 8 unblocks.
Thread # 5 is done requesting that thread # 8 unblocks.
Thread # 5 is requesting that thread # 9 unblocks.
Thread # 5 is done requesting that thread # 9 unblocks.
Thread # 5 is requesting that thread # 1 unblocks.
Thread # 5 is done requesting that thread # 1 unblocks.
Thread # 5 is requesting that thread # 11 unblocks.
Thread # 5 is done requesting that thread # 11 unblocks.
[STWController: Waiting for request...]
QEMU 6.1.0 monitor - type 'help' for more information
(qemu) pmemsave 0 0x8000000 jam.dmp

March 29, 2022

Getting closer. Looks like it is stuck in the scan stack frame loop.

    RExecute SimplePhase(set-collection-kind) as Global...
    Execute SimplePhase(initiate) as Global...
    Collection 1:        reserved = 4 MB (1030 pgs)      used = 4 MB (1030 pgs)      total = 16 MB (4096 pgs)
      Before Collection: used = 4.02 Mb = boot 0.00 Mb + immortal 0.00 Mb + meta 0.03 Mb + los 0.00 Mb + sanity 0.00 Mb + non-moving 0.00 Mb + sm-code 0.00 Mb + lg-code 0.00 Mb + rc 1.40 Mb + rclos 2.58 Mb
                         used = 1030 pgs = boot 0 pgs + immortal 0 pgs + meta 8 pgs + los 0 pgs + sanity 0 pgs + non-moving 0 pgs + sm-code 0 pgs + lg-code 0 pgs + rc 359 pgs + rclos 663 pgs
    Key: (I)mmortal (N)onmoving (D)iscontiguous (E)xtent (F)raction
         HEAP_START 0x0000000001000000
    AVAILABLE_START 0x0000000005c00000
           boot IN  0x0000000001000000->0x0000000005bfffff E 0x0000000004c00000
       immortal IND []
           meta  ND [0x0000000006000000->0x00000000063fffff]
            los  ND []
         sanity  ND []
     non-moving  ND []
        sm-code  ND []
        lg-code  ND []
             rc  ND [0x0000000005c00000->0x0000000005ffffff]
          rclos  ND [0x0000000006400000->0x00000000067fffff]
      AVAILABLE_END 0x00000000f0000000
           HEAP_END 0x00000000f0000000
    Execute SimplePhase(prepare) as Mutator...
    Execute SimplePhase(prepare) as Global...
    Execute SimplePhase(prepare) as Collector...
    Execute SimplePhase(prepare-stacks) as Mutator...
    Execute SimplePhase(prepare-stacks) as Global...
    Execute SimplePhase(stacks) as Collector...
    scanning  10
    --- Start Of Stack Scan ---

    Thread #10
       topFrame = 0x0000000000000000
             ip = 0x000000000428ceba
             fp = 0x000000000660bd68
      registers.ip = 0x000000000428ceba
    Thread  4 at fp = 0x660bd68

    --- METHOD (BASELINE) Lorg/jikesrvm/scheduler/RoundRobin;.schedule ()V
    --- fp = 0x000000000660bd68     code base = 0x000000000428cda0     code offset = 0x000000000000011a
         line number = 43
     10 0x660bd68 Lorg/jikesrvm/scheduler/RoundRobin;.schedule()V
    RThread  4 at fp = 0x660bd98

    --- METHOD (BASELINE) Lorg/jikesrvm/scheduler/RVMThread;.yieldNoHandshake ()V
    --- fp = 0x000000000660bd98     code base = 0x00000000043addc8     code offset = 0x0000000000000053
         line number = 3456
     10 0x660bd98 Lorg/jikesrvm/scheduler/RVMThread;.yieldNoHandshake()V
    Thread  4 at fp = 0x660be10

    --- METHOD (BASELINE) Lorg/jikesrvm/scheduler/RVMThread;.waitImpl (Ljava/lang/Object;ZJ)V
    --- fp = 0x000000000660be10     code base = 0x00000000040eca28     code offset = 0x00000000000004d3
         line number = 3573
     10 0x660be10 Lorg/jikesrvm/scheduler/RVMThread;.waitImpl(Ljava/lang/Object;ZJ)V
    Thread  4 at fp = 0x660be68

    --- METHOD (BASELINE) Lorg/jikesrvm/scheduler/RVMThread;.wait (Ljava/lang/Object;)V
    --- fp = 0x000000000660be68     code base = 0x00000000043ad958     code offset = 0x0000000000000050
         line number = 3629
     10 0x660be68 Lorg/jikesrvm/scheduler/RVMThread;.wait(Ljava/lang/Object;)V
    Thread  4 at fp = 0x660bea0

    --- METHOD (BASELINE) Ljava/lang/Object;.wait ()V
    --- fp = 0x000000000660bea0     code base = 0x000000000442cce8     code offset = 0x0000000000000030
         line number = 518
     10 0x660bea0 Ljava/lang/Object;.wait()V
    Thread  4 at fp = 0x660bee8

    --- METHOD (BASELINE) Lorg/jam/net/InetProtocolProcessor;.processPackets ()V
    R--- fp = 0x000000000660bee8     code base = 0x00000000042b4fd8     code offset = 0x0000000000000082
         line number = 43
     10 0x660bee8 Lorg/jam/net/InetProtocolProcessor;.processPackets()V
    Thread  4 at fp = 0x660bf20

    --- METHOD (BASELINE) Lorg/jam/net/InetProtocolProcessor;.run ()V
    --- fp = 0x000000000660bf20     code base = 0x00000000042b4ee0     code offset = 0x000000000000003a
         line number = 28
     10 0x660bf20 Lorg/jam/net/InetProtocolProcessor;.run()V
    Thread  4 at fp = 0x660bf58

    --- METHOD (BASELINE) Ljava/lang/Thread;.run ()V
    --- fp = 0x000000000660bf58     code base = 0x00000000040a5e68     code offset = 0x0000000000000074
         line number = 695
     10 0x660bf58 Ljava/lang/Thread;.run()V
    Thread  4 at fp = 0x660bfa8

    --- METHOD (BASELINE) Lorg/jikesrvm/scheduler/RVMThread;.run ()V
    --- fp = 0x000000000660bfa8     code base = 0x000000000435bca0     code offset = 0x00000000000000f8
         line number = 2844
     10 0x660bfa8 Lorg/jikesrvm/scheduler/RVMThread;.run()V
    Thread  4 at fp = 0x660bfe8

    --- METHOD (BASELINE) Lorg/jikesrvm/scheduler/RVMThread;.startoff ()V
    --- fp = 0x000000000660bfe8     code base = 0x00000000043ae560     code offset = 0x0000000000000159
         line number = 2903
     10 0x660bfe8 Lorg/jikesrvm/scheduler/RVMThread;.startoff()V
    Thread  4 at fp = 0x0
    QEMU 6.1.0 monitor - type 'help' for more information
    (qemu) quit

March 28, 2022

Working on running the tests. Now fixing on running GC cycle.

August 16, 2021

Fixing the @InterruptHandler annotation needed for the interrupt handling. Working through the ripples that it is causing.

August 10, 2021

More progress!

Need to fix the thread initialization and startup. Very close to time slicing

SeaBIOS (version rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org)

iPXE v1.0.0-591-g7aee315
iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+07F91130+07F51130 CA00


Booting from ROM..
The Start
Booting
Setting up current RVMThread
Doing thread initialization
GETTHREAD ID
GETTHREAD PRIORITY HANDLE
MemoryManager: start=0x5060000 end=0x9060000 maxHeapSize=0x4000000
Setting up memory manager: bootrecord = 0x1000018
Setting up memory manager: bootThread = 0x266ce00
t1 t2: 0x99bacc8 0x10c5abec
cycles: 0x729ff24  min: 0x3952e34  max: 0x3952e34  loops:  81749
TSC cycle per second = 0x8f47eed0
TSC cycles per 1000 NS =  2403
Marking 0x0000000001000000 50331648
Marking 0x0000000004000000 16777216
MMAP ERRNO 0x5c00000  1048576 0
mmap succeeded at chunk 92  0x0000000005c00000 with len = 1048576
Initializing baseline compiler options to defaults
Initializing JNI for boot thread
MMAP ERRNO 0x6000000  1048576 0
mmap succeeded at chunk 96  0x0000000006000000 with len = 1048576
JNI initialized for boot thread
Fetching command-line arguments
ARG -1
Early stage processing of command line
Collector processing rest of boot options
Key: (I)mmortal (N)onmoving (D)iscontiguous (E)xtent (F)raction
     HEAP_START 0x0000000001000000
AVAILABLE_START 0x0000000005c00000
       boot IN  0x0000000001000000->0x0000000005bfffff E 0x0000000004c00000
   immortal IND []
       meta  ND [0x0000000006000000->0x00000000063fffff]
        los  ND []
     sanity  ND []
 non-moving  ND []
    sm-code  ND []
    lg-code  ND []
         rc  ND [0x0000000005c00000->0x0000000005ffffff]
      rclos  ND []
  AVAILABLE_END 0x00000000f0000000
       HEAP_END 0x00000000f0000000
================ MMTk Configuration ================
plan =
org.mmtk.plan.refcount.fullheap.RC
HEADER_MARK_BITS = true
ZERO_PAGES_ON_RELEASE = false
====================================================
Done: Collector processing rest of boot options
Initializing bootstrap class loader:
Running various class initializers
running class initializer for org.jikesrvm.classloader.Atom$InternedStrings
invoking method < BootstrapCL, Lorg/jikesrvm/classloader/Atom$InternedStrings; >.<clinit> ()V
clinit method done
running class initializer for java.lang.Runtime
invoking method < BootstrapCL, Ljava/lang/Runtime; >.<clinit> ()V
clinit method done
running class initializer for sun.misc.Unsafe
invoking method < BootstrapCL, Lsun/misc/Unsafe; >.<clinit> ()V
clinit method done
running class initializer for java.lang.Character
invoking method < BootstrapCL, Ljava/lang/Character; >.<clinit> ()V
clinit method done
running class initializer for java.lang.CharacterDataLatin1
invoking method < BootstrapCL, Ljava/lang/CharacterDataLatin1; >.<clinit> ()V
COPY 0x5c48918 0x34868e0  1024
clinit method done
running class initializer for java.lang.CharacterData00
MMAP ERRNO 0x6400000  1048576 0
mmap succeeded at chunk 100  0x0000000006400000 with len = 1048576
[Loaded [[[C]
[Loaded superclasses of [[[C]
invoking method < BootstrapCL, Ljava/lang/CharacterData00; >.<clinit> ()V
COPY 0x5c6fc18 0x34857b8  4096
COPY 0x641c028 0x34834f0  8832
COPY 0x5c5f018 0x34828f8  2992
clinit method done
running class initializer for java.lang.CharacterData01
invoking method < BootstrapCL, Ljava/lang/CharacterData01; >.<clinit> ()V
COPY 0x5c71018 0x3481780  4096
COPY 0x5c7a018 0x3481038  1792
clinit method done
running class initializer for java.lang.CharacterData02
invoking method < BootstrapCL, Ljava/lang/CharacterData02; >.<clinit> ()V
COPY 0x5c72418 0x347fd50  4096
clinit method done
running class initializer for java.lang.CharacterData0E
invoking method < BootstrapCL, Ljava/lang/CharacterData0E; >.<clinit> ()V
COPY 0x5c73818 0x347eb00  4096
clinit method done
running class initializer for java.lang.CharacterDataPrivateUse
has no clinit method
clinit method done
running class initializer for java.lang.CharacterDataUndefined
has no clinit method
clinit method done
running class initializer for java.lang.Throwable
invoking method < BootstrapCL, Lorg/jikesrvm/classlibrary/openjdk/replacements/java_lang_Throwable; >.<clinit> ()V
clinit method done
running class initializer for org.jikesrvm.classloader.TypeReferenceVector
invoking method < BootstrapCL, Lorg/jikesrvm/classloader/TypeReferenceVector; >.<clinit> ()V
clinit method done
running class initializer for org.jikesrvm.classloader.MethodVector
invoking method < BootstrapCL, Lorg/jikesrvm/classloader/MethodVector; >.<clinit> ()V
clinit method done
running class initializer for org.jikesrvm.classloader.FieldVector
invoking method < BootstrapCL, Lorg/jikesrvm/classloader/FieldVector; >.<clinit> ()V
clinit method done
Booting Lock
running class initializer for java.lang.Thread
invoking method < BootstrapCL, Ljava/lang/Thread; >.<clinit> ()V
clinit method done
Booting scheduler
Setting up boot thread
Create real boot thread
Boot thread 0x5c37598
MONITOR CREATE
MONITOR CREATE
MONITOR CREATE
MONITOR CREATE
MONITOR CREATE
MONITOR CREATE
MONITOR CREATE
MONITOR CREATE
MONITOR CREATE
STASH VMTHREAD 0x266ce00
boot thread at 0x266ce00
ip: 0x43cd9a0 sp: 0x6463028 esi: 0x5c46e18
sp0: 0x6463028 ip: 0x43cd9a0
fp: 0x6462fe8
rvmthread sp: 0x6463008 gpr: 0x5c87398
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR CREATE
MONITOR CREATE
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 2 at 0x5c46e18
stack at 0x641f028 up to 0x6463028
registered mutator for  2
Finishing initializeJniEnv() for the thread
TimerThread slot:  2
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 2 starting!
THREAD CREATE 0x5c46e18
MONITOR CREATE
ip: 0x43cd9a0 sp: 0x64a8028 esi: 0x5c47118
sp0: 0x64a8028 ip: 0x43cd9a0
fp: 0x64a7fe8
rvmthread sp: 0x64a8008 gpr: 0x5c87898
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR CREATE
MONITOR CREATE
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 3 at 0x5c47118
stack at 0x6464028 up to 0x64a8028
registered mutator for  3
Finishing initializeJniEnv() for the thread
FinalizerThread slot:  3
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 3 starting!
THREAD CREATE 0x5c47118
RVMThread booted
Booting DynamicLibrary
Jikes RVM: Warning: You have explicitly set java.ext.dirs; that will not do anything under Jikes RVM
initProperties DONE
System properties preinit
DynamicLibary setup done
running class initializer for java.lang.Thread
invoking method < BootstrapCL, Ljava/lang/Thread; >.<clinit> ()V
clinit method done
Enabling GC
Setting default thread count for MMTk to minimum of default thread count 1 and maximal thread count 2147483647 supported by current GC plan.
New default thread count value is 1
Setting actual thread count for MMTk to minimum of desired thread count 1 and maximal thread count 2147483647 supported by current GC plan.
New actual thread count is 1
New heavy cond lock: CollectorContextGroup
MONITOR CREATE
ip: 0x43cd9a0 sp: 0x64c0028 esi: 0x5c47418
sp0: 0x64c0028 ip: 0x43cd9a0
fp: 0x64bffe8
rvmthread sp: 0x64c0008 gpr: 0x5c97118
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR CREATE
MONITOR CREATE
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 4 at 0x5c47418
stack at 0x64a9028 up to 0x64c0028
registered mutator for  4
Finishing initializeJniEnv() for the thread
org.mmtk.plan.refcount.fullheap.RCCollector [0] slot:  4
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 4 starting!
THREAD CREATE 0x5c47418
init group done
worker threads created
ip: 0x43cd9a0 sp: 0x64d8028 esi: 0x5c47718
sp0: 0x64d8028 ip: 0x43cd9a0
fp: 0x64d7fe8
rvmthread sp: 0x64d8008 gpr: 0x5c97898
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR CREATE
MONITOR CREATE
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 5 at 0x5c47718
stack at 0x64c1028 up to 0x64d8028
registered mutator for  5
Finishing initializeJniEnv() for the thread
org.mmtk.plan.ControllerCollectorContext [1] slot:  5
New heavy cond lock: CollectorControlLock
MONITOR CREATE
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 5 starting!
THREAD CREATE 0x5c47718
control thread created
running class initializer for java.util.WeakHashMap
invoking method < BootstrapCL, Ljava/util/WeakHashMap; >.<clinit> ()V
clinit method done
running class initializer for sun.misc.Version
invoking method < BootstrapCL, Lsun/misc/Version; >.<clinit> ()V
clinit method done
running class initializer for sun.misc.VM
invoking method < BootstrapCL, Lsun/misc/VM; >.<clinit> ()V
clinit method done
running class initializer for sun.misc.SharedSecrets
invoking method < BootstrapCL, Lsun/misc/SharedSecrets; >.<clinit> ()V
clinit method done
running class initializer for java.io.Console
invoking method < BootstrapCL, Ljava/io/Console; >.<clinit> ()V
clinit method done
running class initializer for java.util.concurrent.atomic.AtomicInteger
invoking method < BootstrapCL, Ljava/util/concurrent/atomic/AtomicInteger; >.<clinit> ()V
clinit method done
running class initializer for java.io.FileDescriptor
invoking method < BootstrapCL, Ljava/io/FileDescriptor; >.<clinit> ()V
clinit method done
running class initializer for java.io.FileInputStream
invoking method < BootstrapCL, Ljava/io/FileInputStream; >.<clinit> ()V
clinit method done
running class initializer for java.io.FileOutputStream
invoking method < BootstrapCL, Ljava/io/FileOutputStream; >.<clinit> ()V
clinit method done
running class initializer for java.util.Collections
invoking method < BootstrapCL, Ljava/util/Collections; >.<clinit> ()V
clinit method done
running class initializer for sun.reflect.Reflection
invoking method < BootstrapCL, Lsun/reflect/Reflection; >.<clinit> ()V
clinit method done
running class initializer for java.lang.reflect.Proxy
invoking method < BootstrapCL, Ljava/lang/reflect/Proxy; >.<clinit> ()V
clinit method done
running class initializer for java.util.concurrent.atomic.AtomicReferenceFieldUpdater$AtomicReferenceFieldUpdaterImpl
invoking method < BootstrapCL, Ljava/util/concurrent/atomic/AtomicReferenceFieldUpdater$AtomicReferenceFieldUpdaterImpl; >.<clinit> ()V
clinit method done
running class initializer for java.io.BufferedInputStream
invoking method < BootstrapCL, Ljava/io/BufferedInputStream; >.<clinit> ()V
Returning caller class class java.io.BufferedInputStream for stack:
Dumping stack for Thread # 1
MONITOR ENTER 0x0
-- Stack --
(0x26874e8  4258)   at [0x26874e8, 0x42eb70d] Lorg/jikesrvm/classlibrary/openjdk/replacements/sun_reflect_Reflection; getCallerClass(I)Ljava/lang/Class; at line  86 at bytecode index  76
(0x2687560  12862)   at [0x2687560, 0x42eba3d] Ljava/util/concurrent/atomic/AtomicReferenceFieldUpdater$AtomicReferenceFieldUpdaterImpl; <init>(Ljava/lang/Class;Ljava/lang/Class;Ljava/ld
(0x26875c8  7279)   at [0x26875c8, 0x5ca4902] Ljava/util/concurrent/atomic/AtomicReferenceFieldUpdater; newUpdater(Ljava/lang/Class;Ljava/lang/Class;Ljava/lang/String;)Ljava/util/concur5
(0x2687608  15304)   at [0x2687608, 0x44477cb] Ljava/io/BufferedInputStream; <clinit>()V at line  52 at bytecode index  14 at machine code offset 0x6a
(0x2687668  14632)   at [0x2687668, 0x44480a1] Lorg/jikesrvm/VM; runClassInitializer(Ljava/lang/String;)V at line  817 at bytecode index  184 at machine code offset 0x373
(0x26876b8  14630)   at [0x26876b8, 0x4448875] Lorg/jikesrvm/VM; finishBooting()V at line  457 at bytecode index  508 at machine code offset 0x711
(0x26876e8  14629)   at [0x26876e8, 0x1001c3] Lorg/jikesrvm/VM; boot()V at line  187 at bytecode index  124 at machine code offset 0x185
Bogus looking frame pointer: 0x0 end of stack dump
MONITOR EXIT 0x0
clinit method done
running class initializer for java.nio.DirectByteBuffer
invoking method < BootstrapCL, Ljava/nio/DirectByteBuffer; >.<clinit> ()V
clinit method done
running class initializer for java.nio.Bits$1
has no clinit method
clinit method done
running class initializer for java.nio.Bits
invoking method < BootstrapCL, Ljava/nio/Bits; >.<clinit> ()V
clinit method done
running class initializer for sun.nio.cs.StreamEncoder
invoking method < BootstrapCL, Lsun/nio/cs/StreamEncoder; >.<clinit> ()V
clinit method done
running class initializer for java.nio.charset.Charset
invoking method < BootstrapCL, Ljava/nio/charset/Charset; >.<clinit> ()V
clinit method done
running class initializer for java.lang.Shutdown
invoking method < BootstrapCL, Ljava/lang/Shutdown; >.<clinit> ()V
[Loaded [Ljava/lang/Runnable;]
[Loaded superclasses of [Ljava/lang/Runnable;]
clinit method done
initializing standard streams
running class initializer for java.io.FileSystem
invoking method < BootstrapCL, Ljava/io/FileSystem; >.<clinit> ()V
clinit method done
running class initializer for java.lang.String
invoking method < BootstrapCL, Ljava/lang/String; >.<clinit> ()V
clinit method done
running class initializer for java.net.URL
invoking method < BootstrapCL, Ljava/net/URL; >.<clinit> ()V
clinit method done
running class initializer for java.net.URLClassLoader
invoking method < BootstrapCL, Ljava/net/URLClassLoader; >.<clinit> ()V
[Loaded org.jikesrvm.classloader.ReflectionBase$$Reflect5766]
[Preparing org.jikesrvm.classloader.ReflectionBase$$Reflect5766]
[Initializing org.jikesrvm.classloader.ReflectionBase$$Reflect5766]
[Initialized org.jikesrvm.classloader.ReflectionBase$$Reflect5766]
clinit method done
running class initializer for sun.misc.URLClassPath
invoking method < BootstrapCL, Lsun/misc/URLClassPath; >.<clinit> ()V
clinit method done
running class initializer for java.net.URLConnection
invoking method < BootstrapCL, Ljava/net/URLConnection; >.<clinit> ()V
clinit method done
running class initializer for java.nio.charset.CoderResult
invoking method < BootstrapCL, Ljava/nio/charset/CoderResult; >.<clinit> ()V
clinit method done
Running late class initializers
running class initializer for java.lang.Math
invoking method < BootstrapCL, Ljava/lang/Math; >.<clinit> ()V
clinit method done
running class initializer for java.util.TreeMap
has no clinit method
clinit method done
running class initializer for java.util.BitSet
invoking method < BootstrapCL, Ljava/util/BitSet; >.<clinit> ()V
[Initializing java.io.ObjectStreamField]
[Initialized java.io.ObjectStreamField]
clinit method done
running class initializer for org.jikesrvm.classloader.RVMAnnotation
invoking method < BootstrapCL, Lorg/jikesrvm/classloader/RVMAnnotation; >.<clinit> ()V
clinit method done
running class initializer for java.nio.charset.Charset
invoking method < BootstrapCL, Ljava/nio/charset/Charset; >.<clinit> ()V
clinit method done
running class initializer for sun.nio.cs.StandardCharsets
invoking method < BootstrapCL, Lsun/nio/cs/StandardCharsets; >.<clinit> ()V
clinit method done
running class initializer for sun.nio.cs.Surrogate$Parser
invoking method < BootstrapCL, Lsun/nio/cs/Surrogate$Parser; >.<clinit> ()V
clinit method done
running class initializer for sun.nio.cs.Surrogate$Generator
invoking method < BootstrapCL, Lsun/nio/cs/Surrogate$Generator; >.<clinit> ()V
clinit method done
running class initializer for sun.nio.cs.Surrogate
invoking method < BootstrapCL, Lsun/nio/cs/Surrogate; >.<clinit> ()V
clinit method done
VM is now fully booted
Initializing runtime compiler
Late stage processing of command line
[VM booted]
contextRegister offset 0xb0
gprs offset 0xfffffffffffffff8
sp offset 0x170
Max CPUID:  13
Vendor ID: AuthenticAMD
CPUID 1: 0x00000663 0x00000800 0x80002001 0x078bfbfd
Extended CPUID 0: 0x8000000a
Extended CPUID 1 EAX: 0x00000663
Processor Brand: QEMU Virtual CPU version 2.5+
CPUID:
FPU DE PSE TSC MSR PAE MCE CX8 APIC SEP MTRR PGE MCA CMOV PAT PSE36 CLFSH MMX FXSR SSE SSE2 SSE3 CMPXCHG16B SYSCALL64 EDB IA64
PCI Bus
Bus 0 Device 0 Vendor ID 0xffff8086 Device ID 0x00001237
Class  6 SubClass 0
Bus 0 Device  1 Vendor ID 0xffff8086 Device ID 0x00007000
Class  6 SubClass  1
Bus 0 Device  2 Vendor ID 0x00001234 Device ID 0x00001111
Class  3 SubClass 0
Bus 0 Device  3 Vendor ID 0xffff8086 Device ID 0x00001229
Class  2 SubClass 0
Wait for gate to go active %
t2: 0xfff2e5fe
cycles: 0xffffffff000d1a01  loops:  121342
APIC frequency = 0x83040a
APIC ver: 20 lvts: 5 id: 0
output stream: 0x5ce4370
lookup2: UTF-8
fastcharset.lookup utf-8
cln UTF_8
FREE 0x5ce43e8
print stream: 0x5cee698
scheduler
roundrobin stack top: 0x5c4ab08
idt
apic
ioapic
IOAPIC id 0 ver 32 max 23
bar0: fe000008
bar1: c001
bar2: feba0000
bar3: 0
bar4: 0
bar5: 0
Interrupt pin 1 line 11
class 2 subclass 0 Interface 0
Subsystem Vendor ffff8086 id 40
status 290 command 107
address len:  6  64
Ethernet Address: 0x00005452:0x00001200:0x00005634
MMAP ERRNO 0x5d00000  1048576 0
mmap succeeded at chunk 93  0x0000000005d00000 with len = 1048576
rfd 0: 5cf4118: 0 5cf4818 0 5f20000
results address: 0x05ceead0
udelay: 0x82f93bec 0x9150f1e0
status: 0x0000782d 0x00003000
phy ID = 0x015402a8
Get cmd block: 0x5cfc410 0x05ce5898  255
config 0 = 0x00000016
config  1 = 0x00000008
config  2 = 0x00000000
config  3 = 0x00000001
config  4 = 0x00000000
config  5 = 0x00000000
config  6 = 0x00000036
config  7 = 0x00000007
config  8 = 0x00000001
config  9 = 0x00000000
config  10 = 0x00000026
config  11 = 0x00000000
config  12 = 0x00000061
config  13 = 0x00000000
config  14 = 0x00000000
config  15 = 0xffffffc8
config  16 = 0x00000000
config  17 = 0x00000000
config  18 = 0xfffffff3
config  19 = 0xffffff80
config  20 = 0x0000003f
config  21 = 0x00000005
Get cmd block: 0x5cfc448 0x05ce58f8  254
IA ADDRESS:  0x00000052 0x00000054 0x00000000 0x00000012 0x00000034 0x00000056
Idle Thread
ip: 0x43cd9a0 sp: 0x64f3028 esi: 0x5cad718
sp0: 0x64f3028 ip: 0x43cd9a0
fp: 0x64f2fe8
rvmthread sp: 0x64f3008 gpr: 0x5ce64d8
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR CREATE
MONITOR CREATE
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 6 at 0x5cad718
stack at 0x64f2028 up to 0x64f3028
registered mutator for  6
Finishing initializeJniEnv() for the thread
IdleThread slot:  6
idle thread: 0x5cad718
MONITOR ENTER 0x0
MONITOR EXIT 0x0
Thread # 6 starting!
THREAD CREATE 0x5cad718
CURRENT TIME MILLIS
Creating main thread
Constructing mainThread
System out printout!
Boot sequence completed; finishing boot thread
in terminate() for Thread # 1
doing accounting...
MONITOR ENTER 0x0
active =  5, daemons =  5
MONITOR EXIT 0x0
done with accounting.
making joinable...
Thread # 1 is joinable.
making joinable...
returning cached lock...
adding to aboutToTerminate...
MONITOR ENTER 0x0
MONITOR BROADCAST 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
MONITOR ENTER 0x0
MONITOR EXIT 0x0
acquireCount for my monitor:  2
timer ticks: 0x0
yieldpoints taken: 0x0
yieldpoints taken fully: 0x0
finishing thread termination...
int48/yield ^^ 0x266ce00->0x5cad718
next thread sp: 0x64f3008 current sp: 0x2687638
QEMU 6.0.0 monitor - type 'help' for more information
(qemu)

April 23, 2021

We are booting the JOE image! This is a big step.

BaseBaseRefCount_x86_64-osx % ../../scripts/ljoe_x86_64
SeaBIOS (version rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org)

iPXE v1.0.0-591-g7aee315
iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+07F91130+07F51130 CA00


Booting from ROM..The Start
MemoryManager: start=0x505d000 end=0x905d000 maxHeapSize=0x4000000
vm internal error at:
Thread # 1
Bogus looking frame pointer: 0x25fbd20 not dumping stack
********************************************************************************
*                      Abnormal termination of Jikes RVM                       *
* Jikes RVM terminated abnormally indicating a problem in the virtual machine. *
* Jikes RVM relies on community support to get debug information. Help improve *
* Jikes RVM for everybody by reporting this error. Please see:                 *
*                    http://www.jikesrvm.org/ReportingBugs/                    *
********************************************************************************
EXIT  124
Thread  1: VM.sysFail(): We're in a (likely) recursive call to VM.sysFail(),  2 deep
   sysFail was called with the message: vm internal error at:
vm internal error at:
Thread # 1
Bogus looking frame pointer: 0x25fbbd8 not dumping stack
********************************************************************************
*                      Abnormal termination of Jikes RVM                       *
* Jikes RVM terminated abnormally indicating a problem in the virtual machine. *
* Jikes RVM relies on community support to get debug information. Help improve *
* Jikes RVM for everybody by reporting this error. Please see:                 *
*                    http://www.jikesrvm.org/ReportingBugs/                    *
********************************************************************************
Thread  1: VM.shutdown(): We're in a (likely) recursive call to VM.shutdown(),  2 deep

EXIT  124
Thread  1: VM.sysFail(): We're in a (likely) recursive call to VM.sysFail(),  3 deep
   sysFail was called with the message: vm internal error at:
vm internal error at:
Thread # 1
Bogus looking frame pointer: 0x25fba90 not dumping stack
********************************************************************************
*                      Abnormal termination of Jikes RVM                       *
* Jikes RVM terminated abnormally indicating a problem in the virtual machine. *
* Jikes RVM relies on community support to get debug information. Help improve *
* Jikes RVM for everybody by reporting this error. Please see:                 *
*                    http://www.jikesrvm.org/ReportingBugs/                    *
********************************************************************************
Thread  1: VM.shutdown(): We're in a (likely) recursive call to VM.shutdown(),  3 deep

EXIT  124
Thread  1: VM.sysFail(): We're in a (likely) recursive call to VM.sysFail(),  4 deep
   sysFail was called with the message: vm internal error at:
VM.dieAbruptlyRecursiveSystemTrouble(): Dying abruptly; we're stuck in a recursive shutdown/exit.
EXIT  128
QEMU 5.2.0 monitor - type 'help' for more information

April 18, 2021

Was working on fixing how Classpath was compiled and built but came to the realization that the project needed to resync with the latest JikesRVM release and transition over to OpenJDK6. This is happening here: New JOE. Current state of this is it can build a non-working boot image. This will only work on a Mac OSX machine (will get to building from linux later). I will be developing and working in this new forked repo until I get JOE running the Dining Philosophers again. Then I will transition that new code into the JOE repo.

January 26, 2021

Finally got the Trace class added. Still have not found my bug happening first garbage collection. But from the tracing, the issue is not with the interrupts. Will probably start adding traces to the GC next.

January 3, 2021

Crash is happening in CharsetEncoder.encode(Ljava/nio/CharBuffer;)Ljava/nio/ByteBuffer;

    Working Directory /Users/joe/github/JOE/jikesrvm-hg/target/BaseBaseRefCount_x86_64-osx/
    Processing RVM.map
    ## td 000000000451c4d8
    Thread 451c4d8 Plato index 5 slot 6
    fp 48b0c38 sp 48b0ba8
    ctxt fp 48b0c38 ip bb8 gprs 4527578
    048b0ba8: 0000000000001010 0000000000000008 ................
    048b0bb8: 0000000000000203 00000000048b0bd8 ................
    048b0bc8: 0000000000000000 00000000044cf298 ..........L.....
    048b0bd8: 0000000003097d27 0000000004473bd8 '}.......;G.....
    048b0be8: 0000000004473038 0000000004473bd8 80G......;G.....
    048b0bf8: 0000000000000002 0000000000000001 ................
    048b0c08: 00000000044cf298 000000000447b098 ..L.......G.....
    048b0c18: 00000000044cf208 0000000000000000 ..L.............
    048b0c28: 0000000000000000 000000000000062b ........+.......
    048b0c38: 00000000048b0cb8 00000000030981aa ................
    CharsetEncoder.encode(Ljava/nio/CharBuffer;)Ljava/nio/ByteBuffer;
    048b0cb8: String.getBytes(Ljava/nio/charset/Charset;)[B
    048b0d18: String.getBytes(Ljava/lang/String;)[B
    048b0d60: PrintStream.writeChars([CII)V
    048b0dc0: PrintStream.print(Ljava/lang/String;Z)V
    048b0e28: PrintStream.println(Ljava/lang/String;)V
    048b0e78: DiningPhilosophers$Philosopher.status(Ljava/lang/String;)V
    048b0ec0: DiningPhilosophers$Philosopher.run()V
    048b0f10: Thread.run()V
    048b0f48: RVMThread.run()V
    048b0f98: RVMThread.startoff()V
    048b0fd8: fffffffd

First GC cycle works but thread crashes shortly after.

    Confucius: Picking up fork 4
    Confucius: Picking up fork 0  [POLL] rc: Triggering collection
    notifying  4
      [POLL] rc: Triggering collection
    GC already triggered
    [STWController: Request recieved.] 1
    [STWController: Stopping the world...]
    [STWController: Triggering worker threads...]
    Collection 1:        reserved = 16 MB (4096 pgs)      used = 16 MB (4096 pgs)      total = 16 MB (4096 pgs)
      Before Collection: used = 16.00 Mb = boot 0.00 Mb + immortal 0.00 Mb + meta 0.00 Mb + los 0.00 Mb + sanity 0.00 Mb + non-moving 0.00 Mb + sm-code 0.00 Mbb
                         used = 4096 pgs = boot 0 pgs + immortal 0 pgs + meta 2 pgs + los 0 pgs + sanity 0 pgs + non-moving 0 pgs + sm-code 0 pgs + lg-code 0 ps
    Key: (I)mmortal (N)onmoving (D)iscontiguous (E)xtent (F)raction
         HEAP_START 0x0000000000000000
    AVAILABLE_START 0x0000000004400000
           boot IN  0x0000000000000000->0x00000000043fffff E 0x0000000004400000
       immortal IND []
           meta  ND [0x0000000004c00000->0x0000000004ffffff]
            los  ND []
         sanity  ND []
     non-moving  ND []
        sm-code  ND []
        lg-code  ND []
            ss0   D []
            ss1   D []
          trace  ND []
             rc  ND [0x0000000005800000->0x0000000005bfffff, 0x0000000005400000->0x00000000057fffff, 0x0000000005000000->0x00000000053fffff, 0x0000000004400000]
          rclos  ND [0x0000000004800000->0x0000000004bfffff]
          gcspy IND []
      AVAILABLE_END 0x00000000f0000000
           HEAP_END 0x00000000f0000000
    computeThreadRoots start
    thread slot: 5/0
    scanning  5
    scanning fp 0x486eab0 ip 0x34a2c24
    start scan: 0x450d058/ 5/0x34a2c24/0x486eb08/0x486eab0/0x44da4f0
    Scanning thread  5 from thread  3
    Thread  5 at fp = 0x486eb08 0x32b3a90
    Thread  5 at fp = 0x486eb90 0x311cca9
    Thread  5 at fp = 0x486ebf8 0x3040528
    Thread  5 at fp = 0x486ec68 0x3040603
    Thread  5 at fp = 0x486ecb8 0x32eaf76
    Thread  5 at fp = 0x486ed00 0x33991b6
    Thread  5 at fp = 0x486ed40 0x343d0a2
    Thread  5 at fp = 0x486ed70 0x33aa240
    Thread  5 at fp = 0x486ee58 0x33aa777
    Thread  5 at fp = 0x486eec8 0x311f298
    Thread  5 at fp = 0x486ef48 0x33d4f00
    Thread  5 at fp = 0x486ef98 0x34a3771
    thread slot: 2/1
    scanning  2
    scanning fp 0x4813f98 ip 0x34a374a
    start scan: 0x44dd298/ 2/0x34a374a/0x4813fd8/0x4813f98/0x44da130
    Scanning thread  2 from thread  3
    thread slot: 3/2
    thread slot: 4/3
    thread slot: 1/4
    scanning  1
    scanning fp 0x488fd78 ip 0x34a5bc2
    start scan: 0x451c058/ 1/0x34a5bc2/0x488fdd0/0x488fd78/0x45250e0
    Scanning thread  1 from thread  3
    Thread  1 at fp = 0x488fdd0 0x34a721f
    Thread  1 at fp = 0x488fe50 0x3407f27
    Thread  1 at fp = 0x488fe90 0x34a8b93
    Thread  1 at fp = 0x488fec8 0x32eaa1b
    Thread  1 at fp = 0x488ff10 0x303f3a7
    Thread  1 at fp = 0x488ff48 0x33d4f00
    Thread  1 at fp = 0x488ff98 0x34a3771
    thread slot: 6/5
    scanning  6
    scanning fp 0x48b0d60 ip 0x3407f27
    start scan: 0x451c4d8/ 6/0x3407f27/0x48b0da0/0x48b0d60/0x4525220
    Scanning thread  6 from thread  3
    Thread  6 at fp = 0x48b0da0 0x34a8b93
    Thread  6 at fp = 0x48b0dd8 0x30e34f2
    Thread  6 at fp = 0x48b0e28 0x30e2982
    Thread  6 at fp = 0x48b0e78 0x32ead80
    Thread  6 at fp = 0x48b0ec0 0x32eab3c
    Thread  6 at fp = 0x48b0f10 0x303f3a7
    Thread  6 at fp = 0x48b0f48 0x33d4f00
    Thread  6 at fp = 0x48b0f98 0x34a3771
    thread slot: 7/6
    scanning  7
    scanning fp 0x48d1d60 ip 0x3407f27
    start scan: 0x451c958/ 7/0x3407f27/0x48d1da0/0x48d1d60/0x4525360
    Scanning thread  7 from thread  3
    Thread  7 at fp = 0x48d1da0 0x34a8b93
    Thread  7 at fp = 0x48d1dd8 0x30e34f2
    Thread  7 at fp = 0x48d1e28 0x30e2982
    Thread  7 at fp = 0x48d1e78 0x32ead80
    Thread  7 at fp = 0x48d1ec0 0x32ea9c2
    Thread  7 at fp = 0x48d1f10 0x303f3a7
    Thread  7 at fp = 0x48d1f48 0x33d4f00
    Thread  7 at fp = 0x48d1f98 0x34a3771
    thread slot: 8/7
    scanning  8
    scanning fp 0x48f2740 ip 0x32c4b27
    start scan: 0x451cdd8/ 8/0x32c4b27/0x48f2778/0x48f2740/0x45254a0
    Scanning thread  8 from thread  3
    Thread  8 at fp = 0x48f2778 0x327f3f6
    Thread  8 at fp = 0x48f27d8 0x340cd1f
    Thread  8 at fp = 0x48f2830 0x329e06a
    Thread  8 at fp = 0x48f28c0 0x329e53c
    Thread  8 at fp = 0x48f2928 0x32acfa4
    Thread  8 at fp = 0x48f29a0 0x32a2d3b
    Thread  8 at fp = 0x48f2a30 0x32af362
    Thread  8 at fp = 0x48f2a98 0x32acbd2
    Thread  8 at fp = 0x48f2b18 0x32b2378
    Thread  8 at fp = 0x48f2b90 0x3497f3a
    Thread  8 at fp = 0x48f2c20 0x349829e
    Thread  8 at fp = 0x48f2cc0 0x34aecec
    Thread  8 at fp = 0x48f2d58 0x3405f28
    Thread  8 at fp = 0x48f2de8 0x3465e18
    Thread  8 at fp = 0x48f2e28 0x305b680
    Thread  8 at fp = 0x48f2e70 0x305d24c
    Thread  8 at fp = 0x48f2eb8 0x32eaa8d
    Thread  8 at fp = 0x48f2f10 0x303f3a7
    Thread  8 at fp = 0x48f2f48 0x33d4f00
    Thread  8 at fp = 0x48f2f98 0x34a3771
    thread slot: 9/8
    scanning  9
    scanning fp 0x4913578 ip 0x32c4b27
    start scan: 0x452a298/ 9/0x32c4b27/0x49135b0/0x4913578/0x45255e0
    Scanning thread  9 from thread  3
    Thread  9 at fp = 0x49135b0 0x327f3f6
    Thread  9 at fp = 0x4913610 0x340cd1f
    Thread  9 at fp = 0x4913668 0x329e06a
    Thread  9 at fp = 0x49136f8 0x329e53c
    Thread  9 at fp = 0x4913760 0x32acfa4
    Thread  9 at fp = 0x49137d8 0x32a2d3b
    Thread  9 at fp = 0x4913868 0x32af362
    Thread  9 at fp = 0x49138d0 0x32acbd2
    Thread  9 at fp = 0x4913950 0x32b2378
    Thread  9 at fp = 0x49139c8 0x3497f3a
    Thread  9 at fp = 0x4913a58 0x349829e
    Thread  9 at fp = 0x4913af8 0x34aecec
    Thread  9 at fp = 0x4913b90 0x345fce1
    Thread  9 at fp = 0x4913c08 0x345fc72
    Thread  9 at fp = 0x4913c50 0x309835e
    Thread  9 at fp = 0x4913cb8 0x302ca9e
    Thread  9 at fp = 0x4913d18 0x302cca6
    Thread  9 at fp = 0x4913d60 0x30e32fb
    Thread  9 at fp = 0x4913dc0 0x30e3574
    Thread  9 at fp = 0x4913e28 0x30e2982
    Thread  9 at fp = 0x4913e78 0x32ead80
    Thread  9 at fp = 0x4913ec0 0x32eaac1
    Thread  9 at fp = 0x4913f10 0x303f3a7
    Thread  9 at fp = 0x4913f48 0x33d4f00
    Thread  9 at fp = 0x4913f98 0x34a3771
    thread slot: 0/9
    computeThreadRoots finished
    scanBootImage start
    cursor: 0x0000000004000000 Image: 0x0000000000108000 Map Start: 0x0000000004000000 end: 0x000000000404d98c
    Thread  3: scanBootImage finished
    <boot image roots: 110 refs: 843850>    Processing GC in parallel
    Thread  3:     processing delayed root objects
    Thread  3:     processing gray objects
    Thread  3:     finished processing gray objects
    Thread  3:     finish completeTrace
       After Collection: used = 3.03 Mb = boot 0.00 Mb + immortal 0.00 Mb + meta 0.00 Mb + los 0.00 Mb + sanity 0.00 Mb + non-moving 0.00 Mb + sm-code 0.00 Mb M
                         used = 778 pgs = boot 0 pgs + immortal 0 pgs + meta 1 pgs + los 0 pgs + sanity 0 pgs + non-moving 0 pgs + sm-code 0 pgs + lg-code 0 pgs
    Key: (I)mmortal (N)onmoving (D)iscontiguous (E)xtent (F)raction
         HEAP_START 0x0000000000000000
    AVAILABLE_START 0x0000000004400000
           boot IN  0x0000000000000000->0x00000000043fffff E 0x0000000004400000
       immortal IND []
           meta  ND [0x0000000004c00000->0x0000000004ffffff]
            los  ND []
         sanity  ND []
     non-moving  ND []
        sm-code  ND []
        lg-code  ND []
            ss0   D []
            ss1   D []
          trace  ND []
             rc  ND [0x0000000005800000->0x0000000005bfffff, 0x0000000005000000->0x00000000053fffff, 0x0000000004400000->0x00000000047fffff]
          rclos  ND [0x0000000004800000->0x0000000004bfffff]
          gcspy IND []
      AVAILABLE_END 0x00000000f0000000
           HEAP_END 0x00000000f0000000
                         reserved = 3 MB (778 pgs)      used = 3 MB (778 pgs)      total = 16 MB (4096 pgs)
        Collection time: 916.46 ms
    [STWController: Worker threads complete!]
    [STWController: Resuming mutators...]
    [STWController: Waiting for request...]
    waiting  4

    Confucius: Eating...
    Confucius: Picking up fork 4
    Confucius: Picking up fork 0
    Confucius: Eating...
    Confucius: Picking up fork 4
    Confucius: Picking up fork 0
    Confucius: Eating...
    Confucius: Picking up fork 4
    Confucius: Picking up fork 0
    Confucius: Eating...
    Confucius: Picking up fork 4
    Confucius: Picking up fork 0
    Confucius: Eating...
    Confucius: Picking up fork 4
    Socrates: Picking up fork 4
    Plato: Eating...QEMU 5.0.0 monitor - type 'help' for more information
    (qemu) stop
    (qemu) info registers
    RAX=0000000004473bd8 RBX=0000000000000000 RCX=0000000004473be0 RDX=0000000004473bd8
    RSI=000000000451c4d8 RDI=0000000000000000 RBP=0000000000000000 RSP=00000000048b0ba0
    R8 =0000000000000000 R9 =0000000000000000 R10=0000000000000000 R11=0000000000000000
    R12=0000000000000000 R13=0000000000000000 R14=0000000000000000 R15=0000000000000000
    RIP=00000000033fcdc9 RFL=00000003 [------C] CPL=0 II=0 A20=1 SMM=0 HLT=1
    ES =0000 0000000000000000 00000000 00000000
    CS =0008 0000000000000000 0fffffff 00a09a00 DPL=0 CS64 [-R-]
    SS =0000 0000000000000000 ffffffff 00c09300 DPL=0 DS   [-WA]
    DS =0000 0000000000000000 00000000 00000000
    FS =0000 0000000000000000 00000000 00000000
    GS =0000 0000000000000000 00000000 00000000
    LDT=0000 0000000000000000 0000ffff 00008200 DPL=0 LDT
    TR =0000 0000000000000000 0000ffff 00008b00 DPL=0 TSS64-busy
    GDT=     0000000000100810 00000017
    IDT=     0000000000001000 000005ff
    CR0=80000011 CR2=0000000000000000 CR3=0000000000101000 CR4=000006a0
    DR0=0000000000000000 DR1=0000000000000000 DR2=0000000000000000 DR3=0000000000000000
    DR6=00000000ffff0ff0 DR7=0000000000000400
    EFER=0000000000000500
    FCW=0000 FSW=0000 [ST=0] FTW=00 MXCSR=00000000
    FPR0=0000000000000000 0000 FPR1=0000000000000000 0000
    FPR2=0000000000000000 0000 FPR3=0000000000000000 0000
    FPR4=0000000000000000 0000 FPR5=0000000000000000 0000
    FPR6=0000000000000000 0000 FPR7=0000000000000000 0000
    XMM00=0000000000000000000000004f000000 XMM01=0000000000000000000000003f800000
    XMM02=00000000000000000000000000000000 XMM03=00000000000000000000000000000000
    XMM04=00000000000000000000000000000000 XMM05=00000000000000000000000000000000
    XMM06=00000000000000000000000000000000 XMM07=00000000000000000000000000000000
    XMM08=00000000000000000000000000000000 XMM09=00000000000000000000000000000000
    XMM10=00000000000000000000000000000000 XMM11=00000000000000000000000000000000
    XMM12=00000000000000000000000000000000 XMM13=00000000000000000000000000000000
    XMM14=00000000000000000000000000000000 XMM15=00000000000000000000000000000000

Creating a new class Trace to create a trace events in hope of finding the cause. I have been debugging this issue for the past week.