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

RunThese24H.java failed "assert(EventThreadDump::is_enabled()) failed: invariant"

XMLWordPrintable

    • jfr
    • x86_64
    • linux

      The following test failed in the JDK18 CI:

      applications/runthese/RunThese24H.java

      Here's a snippet from the log file:

      stress.process.err]
      [stress.process.err] Note: map_callingOnEqualStreams: Passed. test cases: 81; all passed
      [stress.process.err] Note: map_fork: Passed. test cases: 81; all passed
      [stress.process.err] Note: map_fork_secondNull: Passed. test cases: 81; all passed
      [stress.process.err] Note: map_nullFunction: Passed. test cases: 81; all passed
      [stress.process.err] Note: map_umbrella: Passed. test cases: 81; all passed
      [stress.process.err] Note: testcase total time, ms: 370947
      [stress.process.err] checkForEach: Passed. test cases: 5; all passed# To suppress the following error report, specify this argument
      [stress.process.err] # after -XX: or in .hotspotrc: SuppressErrorAt=/jfrThreadDumpEvent.cpp:60
      [stress.process.err] Compiled method (n/a) 27641248 37866 n 0 jdk.jfr.internal.JVM::emitEvent (native)
      [stress.process.err] total in heap [0x00007f0a19c8f590,0x00007f0a19c8f968] = 984
      [stress.process.err] relocation [0x00007f0a19c8f708,0x00007f0a19c8f748] = 64
      [stress.process.err] main code [0x00007f0a19c8f760,0x00007f0a19c8f968] = 520
      [stress.process.err] Compiled method (n/a) 27641248 37866 n 0 jdk.jfr.internal.JVM::emitEvent (native)
      [stress.process.err] total in heap [0x00007f0a19c8f590,0x00007f0a19c8f968] = 984
      [stress.process.err] relocation [0x00007f0a19c8f708,0x00007f0a19c8f748] = 64
      [stress.process.err] main code [0x00007f0a19c8f760,0x00007f0a19c8f968] = 520
      [stress.process.err]
      [stress.process.err]
      [stress.process.err] Note: forEach_blockNullTest: Passed. test cases: 81; all passed
      [stress.process.err] Note: forEach_closedAlready: Passed. test cases: 81; all passed
      [stress.process.err] Note: forEach_forking: Passed. test cases: 81; all passed
      [stress.process.err] Note: forEach_identicalStreams: Passed. test cases: 81; all passed
      Failed to parse file /opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S13880/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/da2444f4-f1f6-4447-9934-25eb75d6b507/runs/656fd896-e0d4-4a79-8465-e9ff25584bb7/testoutput/test-support/jtreg_closed_test_hotspot_jtreg_applications_runthese_RunThese24H_java/scratch/0/perfmon-files/Perfmon.1629042659719.out
      Cannot parse null string
      [stress.process.err] Note: forEach_test: Passed. test cases: 81; all passed
      Unexpected exception Connection reset during communication. Check process module status.
      java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
      at java.base/java.util.Arrays$ArrayList.get(Arrays.java:4165)
      at applications.kitchensink.process.picker.modules.Toolkit$LinuxToolkit.setMetrics(MonitorPickerModule.java:223)
      at applications.kitchensink.process.picker.modules.Toolkit.getSystemMetrics(MonitorPickerModule.java:123)
      at applications.kitchensink.process.picker.modules.MonitorPickerModule.execute(MonitorPickerModule.java:64)
      at applications.kitchensink.process.picker.modules.PickerModule.run(PickerModule.java:140)
      at java.base/java.lang.Thread.run(Thread.java:833)
      [Sun Aug 15 15:52:05 UTC 2021] (1629042725390) Picker module is about to shutdown
      Picker module expected time before shutdown for: Jcmd: 30s
      Picker module expected time before shutdown for: Jfr: 3m 20s
      Picker module expected time before shutdown for: Jstat: 5m
      Picker module expected time before shutdown for: Monitor: 1m
      Picker module expected time before shutdown for: NMT: 1m
      Picker module expected time before shutdown for: Perfmon: 5m
      Picker module finished at [Sun Aug 15 15:52:05 UTC 2021]: Jfr
      Picker module finished at [Sun Aug 15 15:52:05 UTC 2021]: Perfmon
      Picker module finished at [Sun Aug 15 15:52:05 UTC 2021]: Jstat
      Picker module finished at [Sun Aug 15 15:52:05 UTC 2021]: NMT
      Picker module finished at [Sun Aug 15 15:52:05 UTC 2021]: Jcmd
      Picker module finished at [Sun Aug 15 15:52:05 UTC 2021]: Monitor
      [Sun Aug 15 15:52:05 UTC 2021] (1629042725440) Picker module has been shutdown
      [Sun Aug 15 15:52:05 UTC 2021] (1629042725440) Stress process is about to shutdown
      Going to request to stop or kill stress process: 22817
      WARNING: The process 22817 has already finished.
      [Sun Aug 15 15:52:05 UTC 2021] (1629042725441) Stress process has been shutdown
      [Sun Aug 15 15:52:05 UTC 2021] Execution finished.
      ----------rerun:(37/7781)*----------

      There's barely two lines about the crash in the stress.process.err file:

      [stress.process.err] checkForEach: Passed. test cases: 5; all passed# To suppress the following error report, specify this argument
      [stress.process.err] # after -XX: or in .hotspotrc: SuppressErrorAt=/jfrThreadDumpEvent.cpp:60


      Here's snippets from the hs_err_pid file:

      # Internal Error (/opt/mach5/mesos/work_dir/slaves/ff806ead-2cac-495d-9cbc-62116f99bf14-S14126/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/549e51ca-2e30-4af9-8d41-56a4e6f1724e/runs/dcfde554-b626-4ac4-9d8f-6ad890d4fd76/workspace/open/src/hotspot/share/jfr/periodic/jfrThreadDumpEvent.cpp:60), pid=22817, tid=22969
      # assert(EventThreadDump::is_enabled()) failed: invariant
      #
      # JRE version: Java(TM) SE Runtime Environment (18.0+11) (fastdebug build 18-ea+11-519)
      # Java VM: Java HotSpot(TM) 64-Bit Server VM (fastdebug 18-ea+11-519, mixed mode, sharing, tiered, compressed oops, compressed class ptrs, g1 gc, linux-amd64)
      # Problematic frame:
      # V [libjvm.so+0xf4e954] JfrDcmdEvent::thread_dump()+0x204

      <snip>

      --------------- T H R E A D ---------------

      Current thread (0x00007f09741c8f60): JavaThread "JFR Periodic Tasks" daemon [_thread_in_vm, id=22969, stack(0x00007f09132ee000,0x00007f09133ef000)]

      Stack: [0x00007f09132ee000,0x00007f09133ef000], sp=0x00007f09133ed3b0, free space=1020k
      Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
      V [libjvm.so+0xf4e954] JfrDcmdEvent::thread_dump()+0x204
      V [libjvm.so+0xf1f376] JfrPeriodicEventSet::requestThreadDump()+0x126
      V [libjvm.so+0xee6e55] jfr_emit_event+0xb15
      J 37866 jdk.jfr.internal.JVM.emitEvent(JJJ)Z jdk.jfr@18-ea (0 bytes) @ 0x00007f0a19c8f83d [0x00007f0a19c8f760+0x00000000000000dd]
      j jdk.jfr.internal.RequestEngine$RequestHook.execute()V+43 jdk.jfr@18-ea
      j jdk.jfr.internal.RequestEngine.run_requests(Ljava/util/Collection;)J+133 jdk.jfr@18-ea
      j jdk.jfr.internal.RequestEngine.doPeriodic()J+3 jdk.jfr@18-ea
      j jdk.jfr.internal.PlatformRecorder.periodicTask()V+47 jdk.jfr@18-ea
      j jdk.jfr.internal.PlatformRecorder.lambda$startDiskMonitor$1()V+1 jdk.jfr@18-ea
      j jdk.jfr.internal.PlatformRecorder$$Lambda$193+0x0000000801062540.run()V+4 jdk.jfr@18-ea
      j java.lang.Thread.run()V+11 java.base@18-ea
      v ~StubRoutines::call_stub
      V [libjvm.so+0xe6eb64] JavaCalls::call_helper(JavaValue*, methodHandle const&, JavaCallArguments*, JavaThread*)+0x504
      V [libjvm.so+0xe6f414] JavaCalls::call_virtual(JavaValue*, Klass*, Symbol*, Symbol*, JavaCallArguments*, JavaThread*)+0x4b4
      V [libjvm.so+0xe6f867] JavaCalls::call_virtual(JavaValue*, Handle, Klass*, Symbol*, Symbol*, JavaThread*)+0x77
      V [libjvm.so+0xfe6a8b] thread_entry(JavaThread*, JavaThread*)+0x12b
      V [libjvm.so+0x188b67c] JavaThread::thread_main_inner()+0x27c
      V [libjvm.so+0x1891c80] Thread::call_run()+0x100
      V [libjvm.so+0x156cbb4] thread_native_entry(Thread*)+0x104

      Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
      J 37866 jdk.jfr.internal.JVM.emitEvent(JJJ)Z jdk.jfr@18-ea (0 bytes) @ 0x00007f0a19c8f7c4 [0x00007f0a19c8f760+0x0000000000000064]
      j jdk.jfr.internal.RequestEngine$RequestHook.execute()V+43 jdk.jfr@18-ea
      j jdk.jfr.internal.RequestEngine.run_requests(Ljava/util/Collection;)J+133 jdk.jfr@18-ea
      j jdk.jfr.internal.RequestEngine.doPeriodic()J+3 jdk.jfr@18-ea
      j jdk.jfr.internal.PlatformRecorder.periodicTask()V+47 jdk.jfr@18-ea
      j jdk.jfr.internal.PlatformRecorder.lambda$startDiskMonitor$1()V+1 jdk.jfr@18-ea
      j jdk.jfr.internal.PlatformRecorder$$Lambda$193+0x0000000801062540.run()V+4 jdk.jfr@18-ea
      j java.lang.Thread.run()V+11 java.base@18-ea
      v ~StubRoutines::call_stub

            mgronlun Markus Grönlund
            dcubed Daniel Daugherty
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: