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

Wrong lock ordering writing G1HeapRegionTypeChange JFR event

    XMLWordPrintable

Details

    • jfr
    • b10
    • generic
    • generic

    Backports

      Description

        When writing a G1HeapRegionTypeChange JFR event the following assertion can be triggered:
        assert(false) failed: Attempting to acquire lock JfrMsg_lock/nosafepoint-3 out of order with lock FreeList_lock/service-1 -- possible deadlock

        The associated stack trace is on Windows looks like this:
        V [jvm.dll+0xe486d3] os::platform_print_native_stack+0x63 (os_windows_x86.cpp:235)
        V [jvm.dll+0x1140ae8] VMError::report+0x1238 (vmError.cpp:835)
        V [jvm.dll+0x114334e] VMError::report_and_die+0x6ce (vmError.cpp:1683)
        V [jvm.dll+0x11439b1] VMError::report_and_die+0x81 (vmError.cpp:1468)
        V [jvm.dll+0x60a39d] report_vm_error+0x9d (debug.cpp:284)
        V [jvm.dll+0xdd7ba7] Mutex::check_rank+0x427 (mutex.cpp:444)
        V [jvm.dll+0xdd81e4] Mutex::try_lock_inner+0x44 (mutex.cpp:170)
        V [jvm.dll+0xdd8025] Mutex::try_lock+0x15 (mutex.cpp:182)
        V [jvm.dll+0x9de60f] JfrMonitorTryLock::JfrMonitorTryLock+0x3f (jfrTryLock.hpp:59)
        V [jvm.dll+0x9ddfb6] JfrPostBox::asynchronous_post+0x66 (jfrPostBox.cpp:107)
        V [jvm.dll+0x9dddb1] JfrPostBox::post+0x61 (jfrPostBox.cpp:82)
        V [jvm.dll+0x9e8a1d] JfrStorage::register_full+0xed (jfrStorage.cpp:284)
        V [jvm.dll+0x9ed8fb] JfrMemorySpace<JfrStorage,JfrMspaceRetrieval,JfrLinkedList<JfrBuffer,JfrCHeapObj>,JfrLinkedList<JfrBuffer,JfrCHeapObj>,0>::register_full+0x2b (jfrMemorySpace.inline.hpp:301)
        V [jvm.dll+0x9ea228] JfrMspaceRetrieval<JfrMemorySpace<JfrStorage,JfrMspaceRetrieval,JfrLinkedList<JfrBuffer,JfrCHeapObj>,JfrLinkedList<JfrBuffer,JfrCHeapObj>,0> >::acquire<StopOnNullCondition<JfrLinkedList<JfrBuffer,JfrCHeapObj> > >+0x108 (jfrMemorySpaceRetrieval.hpp:59)
        V [jvm.dll+0x9ebfe7] JfrMspaceRetrieval<JfrMemorySpace<JfrStorage,JfrMspaceRetrieval,JfrLinkedList<JfrBuffer,JfrCHeapObj>,JfrLinkedList<JfrBuffer,JfrCHeapObj>,0> >::acquire+0x87 (jfrMemorySpaceRetrieval.hpp:43)
        V [jvm.dll+0x9ebeaa] JfrMemorySpace<JfrStorage,JfrMspaceRetrieval,JfrLinkedList<JfrBuffer,JfrCHeapObj>,JfrLinkedList<JfrBuffer,JfrCHeapObj>,0>::acquire+0x3a (jfrMemorySpace.inline.hpp:241)
        V [jvm.dll+0x9eae78] mspace_acquire_live<JfrMemorySpace<JfrStorage,JfrMspaceRetrieval,JfrLinkedList<JfrBuffer,JfrCHeapObj>,JfrLinkedList<JfrBuffer,JfrCHeapObj>,0> >+0x38 (jfrMemorySpace.inline.hpp:422)
        V [jvm.dll+0x9eaf11] mspace_acquire_live_with_retry<JfrMemorySpace<JfrStorage,JfrMspaceRetrieval,JfrLinkedList<JfrBuffer,JfrCHeapObj>,JfrLinkedList<JfrBuffer,JfrCHeapObj>,0> >+0x91 (jfrMemorySpace.inline.hpp:428)
        V [jvm.dll+0x9e9388] acquire_promotion_buffer+0x78 (jfrStorage.cpp:178)
        V [jvm.dll+0x9e7788] JfrStorage::flush_regular_buffer+0x148 (jfrStorage.cpp:244)
        V [jvm.dll+0x9e78d8] JfrStorage::flush_regular+0x58 (jfrStorage.cpp:400)
        V [jvm.dll+0x9e8d49] JfrStorage::flush+0xe9 (jfrStorage.cpp:388)
        V [jvm.dll+0x9ab9e2] JfrFlush::JfrFlush+0x52 (jfrFlush.cpp:35)
        V [jvm.dll+0x2d2e83] Adapter<JfrFlush>::flush+0x73 (jfrStorageAdapter.hpp:84)
        V [jvm.dll+0x2d224e] StorageHost<Adapter<JfrFlush>,StackObj>::accommodate+0x2e (jfrStorageHost.inline.hpp:66)
        V [jvm.dll+0x2d2c13] WriterHost<EncoderHost<BigEndianEncoderImpl,BigEndianEncoderImpl>,EncoderHost<Varint128EncoderImpl,BigEndianEncoderImpl>,MemoryWriterHost<Adapter<JfrFlush>,StackObj,ExclusiveAccessAssert> >::ensure_size+0x53 (jfrWriterHost.inline.hpp:169)
        V [jvm.dll+0x2d18c2] WriterHost<EncoderHost<BigEndianEncoderImpl,BigEndianEncoderImpl>,EncoderHost<Varint128EncoderImpl,BigEndianEncoderImpl>,MemoryWriterHost<Adapter<JfrFlush>,StackObj,ExclusiveAccessAssert> >::write<unsigned __int64>+0x92 (jfrWriterHost.inline.hpp:77)
        V [jvm.dll+0x2d1923] WriterHost<EncoderHost<BigEndianEncoderImpl,BigEndianEncoderImpl>,EncoderHost<Varint128EncoderImpl,BigEndianEncoderImpl>,MemoryWriterHost<Adapter<JfrFlush>,StackObj,ExclusiveAccessAssert> >::write<unsigned __int64>+0x23 (jfrWriterHost.inline.hpp:182)
        V [jvm.dll+0x925733] EventG1HeapRegionTypeChange::writeData<EventWriterHost<EncoderHost<BigEndianEncoderImpl,BigEndianEncoderImpl>,EncoderHost<Varint128EncoderImpl,BigEndianEncoderImpl>,MemoryWriterHost<Adapter<JfrFlush>,StackObj,ExclusiveAccessAssert> > >+0x33 (jfrEventClasses.hpp:5368)
        V [jvm.dll+0x925ff8] JfrEvent<EventG1HeapRegionTypeChange>::write_sized_event+0x148 (jfrEvent.hpp:250)
        V [jvm.dll+0x925e57] JfrEvent<EventG1HeapRegionTypeChange>::write_event+0xa7 (jfrEvent.hpp:219)
        V [jvm.dll+0x925968] JfrEvent<EventG1HeapRegionTypeChange>::commit+0x68 (jfrEvent.hpp:93)
        V [jvm.dll+0x9256d4] HeapRegionTracer::send_region_type_change+0xb4 (heapRegionTracer.cpp:43)
        V [jvm.dll+0x913c0b] HeapRegion::report_region_type_change+0x5b (heapRegion.cpp:273)
        V [jvm.dll+0x914248] HeapRegion::set_survivor+0x18 (heapRegion.cpp:170)
        V [jvm.dll+0x80f62f] G1CollectedHeap::new_gc_alloc_region+0xef (g1CollectedHeap.cpp:3273)
        V [jvm.dll+0x7e8024] G1GCAllocRegion::allocate_new_region+0x84 (g1AllocRegion.cpp:351)
        V [jvm.dll+0x7e6bf2] G1AllocRegion::new_alloc_region_and_allocate+0x172 (g1AllocRegion.cpp:139)
        V [jvm.dll+0x7ebb0c] G1AllocRegion::attempt_allocation_using_new_region+0x3c (g1AllocRegion.inline.hpp:106)
        V [jvm.dll+0x7ebabe] G1AllocRegion::attempt_allocation_locked+0x5e (g1AllocRegion.inline.hpp:100)
        V [jvm.dll+0x7e9073] G1Allocator::survivor_attempt_allocation+0xe3 (g1Allocator.cpp:255)
        V [jvm.dll+0x7e9bd7] G1Allocator::par_allocate_during_gc+0x57 (g1Allocator.cpp:230)
        V [jvm.dll+0x7e9afc] G1Allocator::par_allocate_during_gc+0x4c (g1Allocator.cpp:216)
        V [jvm.dll+0x7ea32e] G1PLABAllocator::allocate_direct_or_new_plab+0x22e (g1Allocator.cpp:362)
        V [jvm.dll+0x86f0a2] G1ParScanThreadState::allocate_copy_slow+0x72 (g1ParScanThreadState.cpp:403)
        V [jvm.dll+0x86f361] G1ParScanThreadState::do_copy_to_survivor_space+0x151 (g1ParScanThreadState.cpp:468)
        V [jvm.dll+0x870ce7] G1ParScanThreadState::do_oop_evac<enum narrowOop>+0x147 (g1ParScanThreadState.cpp:211)
        V [jvm.dll+0x86f815] G1ParScanThreadState::dispatch_task+0x45 (g1ParScanThreadState.cpp:289)
        V [jvm.dll+0x86fbfa] G1ParScanThreadState::trim_queue_to_threshold+0x8a (g1ParScanThreadState.cpp:311)
        V [jvm.dll+0x86c7fe] G1ParScanThreadState::trim_queue_partially+0x3e (g1ParScanThreadState.inline.hpp:54)
        V [jvm.dll+0x8965b9] G1ScanHRForRegionClosure::scan_memregion+0x149 (g1RemSet.cpp:797)
        V [jvm.dll+0x893120] G1ScanHRForRegionClosure::do_claimed_block+0x1b0 (g1RemSet.cpp:817)
        V [jvm.dll+0x892e24] G1ScanHRForRegionClosure::do_card_block+0x54 (g1RemSet.cpp:825)
        V [jvm.dll+0x8963a6] G1ScanHRForRegionClosure::scan_heap_roots+0x216 (g1RemSet.cpp:857)
        V [jvm.dll+0x893e27] G1ScanHRForRegionClosure::do_heap_region+0xe7 (g1RemSet.cpp:902)
        V [jvm.dll+0x894e5e] G1RemSetScanState::iterate_dirty_regions_from+0xae (g1RemSet.cpp:420)
        V [jvm.dll+0x87fce6] G1RemSet::scan_heap_roots+0x76 (g1RemSet.cpp:923)
        V [jvm.dll+0x8ad25c] G1EvacuateRegionsTask::scan_roots+0x6c (g1YoungCollector.cpp:667)
        V [jvm.dll+0x8ad5c5] G1EvacuateRegionsBaseTask::work+0x95 (g1YoungCollector.cpp:653)
        V [jvm.dll+0x118cf46] WorkerTaskDispatcher::worker_run_task+0x76 (workerThread.cpp:72)
        V [jvm.dll+0x118d4a0] WorkerThread::run+0x30 (workerThread.cpp:164)
        V [jvm.dll+0x10a374c] Thread::call_run+0x15c (thread.cpp:365)
        V [jvm.dll+0xe40db8] thread_native_entry+0x108 (os_windows.cpp:545)
        C [ucrtbase.dll+0x21bb2]
        C [KERNEL32.DLL+0x17034]
        C [ntdll.dll+0x52651]

        The problem can be reproduced with a debug version of the VM with the following command line:
        java -XX:StartFlightRecording=settings=g1-heap-region-change.jfc,flush-interval=1h -Xmx1G -Xms128M -XX:+UseG1GC examples.Allocator

        with the following settings for the g1-heap-region-change.jfc file:
        <?xml version="1.0" encoding="UTF-8"?>
        <configuration version="2.0" label="GC History Simulation" description="Should include events anaolg to our GC history file." provider="Oracle">

          <event name="jdk.G1HeapRegionTypeChange">
            <setting name="enabled">true</setting>
          </event>

        </configuration>

        and this Allocator code:
        package examples;

        public class Allocator {

        public static void main(String[] args) {
        long maxMem = 1024 * 1024 * 768;
        long minMem = 1024 * 1024 * 64;
        int maxOverwrite = 24;
        int chunkSize = 1024 * 10;
        byte[][] roots = new byte[1 + (int) (maxMem / chunkSize)][];
        long used = 0;
        int pos = 0;

        while (true) {
        int overwriteCount = (int) (Math.random() * maxOverwrite);

        while (used < maxMem) {
        for (int i = 0; i <= overwriteCount; ++i) {
        roots[pos] = new byte[chunkSize];
        }

        pos += 1;
        used += chunkSize;
        }

        long targetUse = minMem + (long) ((maxMem - minMem) * Math.random());

        while (used > targetUse) {
        pos -= 1;
        roots[pos] = null;
        used -= chunkSize;
        }
        }
        }
        }

        Attachments

          Issue Links

            Activity

              People

                mgronlun Markus Grönlund
                rschmelter Ralf Schmelter
                Votes:
                0 Vote for this issue
                Watchers:
                8 Start watching this issue

                Dates

                  Created:
                  Updated:
                  Resolved: