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

sun/tools/jhsdb/JStackStressTest.java failed with "InternalError: We should have found a thread that owns the anonymous lock"

    XMLWordPrintable

Details

    • b18
    • x86_64
    • linux

    Backports

      Description

        The following test failed in an adhoc Tier5 job that is testing:

            JDK-8315880 Change LockingMode default from LM_LEGACY to LM_LIGHTWEIGHT

        Here's a snippet from the log file:

        #section:main
        ----------messages:(7/346)----------
        command: main JStackStressTest
        reason: User specified action: run main/timeout=240 JStackStressTest
        started: Sun Sep 17 22:21:56 UTC 2023
        Mode: othervm [test requires non-default system module]
        Additional options from @modules: --add-modules jdk.hotspot.agent,java.management
        finished: Sun Sep 17 22:22:08 UTC 2023
        elapsed time (seconds): 11.96
        ----------configuration:(3/61)----------
        Boot Layer
          add modules: jdk.hotspot.agent java.management

        ----------System.out:(135/8723)----------
        Starting Jshell
        [JShell]:/opt/mach5/mesos/work_dir/jib-master/install/2023-09-17-1736580.daniel.daugherty.8315880_for_jdk22.git/linux-x64-debug.jdk/jdk-22/fastdebug/bin/jshell -J-Xmx768m -J-XX:MaxRAMPercentage=4.16667 -J-Dtest.boot.jdk=/opt/mach5/mesos/work_dir/jib-master/install/jdk/20/36/bundles/linux-x64/jdk-20_linux-x64_bin.tar.gz/jdk-20 -J-Djava.io.tmpdir=/opt/mach5/mesos/work_dir/slaves/cd627e65-f015-4fb1-a1d2-b6c9b8127f98-S179455/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/647b6357-7ad2-47b6-a884-93007503a691/runs/fb791c2d-470c-40ea-99a6-ffd196fc0b7a/testoutput/test-support/jtreg_open_test_jdk_svc_tools/tmp -J-ea -J-esa
        [2023-09-17T22:21:56.889643057Z] Gathering output for process 590799
        ###### Starting jstack iteration 1 against 590799
        [2023-09-17T22:21:57.092332068Z] Gathering output for process 590855
        [2023-09-17T22:21:59.775374274Z] Waiting for completion for process 590855
        [2023-09-17T22:21:59.775620992Z] Waiting for completion finished for process 590855
        Output and diagnostic info for process 590855 was saved into 'pid-590855-output.log'
        jhsdb jstack stdout:
        Attaching to process ID 590799, please wait...
        Debugger attached successfully.
        Server compiler detected.
        JVM version is 22-internal-2023-09-17-1736580.daniel.daugherty.8315880forjdk22.git
        Deadlock Detection:

        No deadlocks found.

        "main" #1 prio=5 tid=0x00007f5b6802b560 nid=590802 runnable [0x00007f5b6de81000]
           java.lang.Thread.State: RUNNABLE
           JavaThread state: _thread_in_vm
         - java.util.stream.Nodes.builder() @bci=0, line=179 (Interpreted frame)
         - java.util.stream.Nodes.builder(long, java.util.function.IntFunction) @bci=26, line=169 (Interpreted frame)
         - java.util.stream.ReferencePipeline.makeNodeBuilder(long, java.util.function.IntFunction) @bci=2, line=135 (Interpreted frame)
         - java.util.stream.AbstractPipeline.evaluate(java.util.Spliterator, boolean, java.util.function.IntFunction) @bci=23, line=573 (Interpreted frame)
         - java.util.stream.AbstractPipeline.evaluateToArrayNode(java.util.function.IntFunction) @bci=74, line=260 (Interpreted frame)
         - java.util.stream.ReferencePipeline.toArray(java.util.function.IntFunction) @bci=4, line=616 (Interpreted frame)
         - jdk.internal.jshell.tool.JShellTool$Options.selectOptions(java.util.function.Predicate) @bci=35, line=326 (Interpreted frame)
         - jdk.internal.jshell.tool.JShellTool$Options.remoteVmOptions() @bci=6, line=330 (Interpreted frame)
         - jdk.internal.jshell.tool.JShellTool.resetState() @bci=148, line=1106 (Interpreted frame)
         - jdk.internal.jshell.tool.JShellTool.start(java.lang.String[]) @bci=44, line=955 (Interpreted frame)
         - jdk.internal.jshell.tool.JShellToolBuilder.start(java.lang.String[]) @bci=5, line=261 (Interpreted frame)
         - jdk.internal.jshell.tool.JShellToolProvider.main(java.lang.String[]) @bci=4, line=120 (Interpreted frame)

        <snip>

        jhsdb jstack stderr:

        ###### End of all output for iteration 1 which took 2711ms
        [2023-09-17T22:21:59.781166361Z] Waiting for completion for process 590855
        [2023-09-17T22:21:59.781288311Z] Waiting for completion finished for process 590855
        ###### Starting jstack iteration 2 against 590799
        [2023-09-17T22:21:59.799234929Z] Gathering output for process 591292
        [2023-09-17T22:22:01.895444885Z] Waiting for completion for process 591292
        [2023-09-17T22:22:01.895737860Z] Waiting for completion finished for process 591292
        Output and diagnostic info for process 591292 was saved into 'pid-591292-output.log'
        jhsdb jstack stdout:
        Attaching to process ID 590799, please wait...
        Debugger attached successfully.
        Server compiler detected.
        JVM version is 22-internal-2023-09-17-1736580.daniel.daugherty.8315880forjdk22.git
        Deadlock Detection:


        jhsdb jstack stderr:
        java.lang.InternalError: We should have found a thread that owns the anonymous lock
        at jdk.hotspot.agent/sun.jvm.hotspot.runtime.Threads.owningThreadFromMonitor(Threads.java:244)
        at jdk.hotspot.agent/sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:88)
        at jdk.hotspot.agent/sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:39)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:62)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:45)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.JStack.run(JStack.java:67)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.startInternal(Tool.java:278)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.start(Tool.java:241)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.execute(Tool.java:134)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.JStack.runWithArgs(JStack.java:90)
        at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runJSTACK(SALauncher.java:302)
        at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:500)

        ###### End of all output for iteration 2 which took 2112ms
        [2023-09-17T22:22:01.896570437Z] Waiting for completion for process 591292
        [2023-09-17T22:22:01.896724810Z] Waiting for completion finished for process 591292
        [2023-09-17T22:22:01.896844778Z] Waiting for completion for process 591292
        [2023-09-17T22:22:01.896938326Z] Waiting for completion finished for process 591292
        [2023-09-17T22:22:01.910460800Z] Waiting for completion for process 591292
        [2023-09-17T22:22:01.910652533Z] Waiting for completion finished for process 591292
        [JShell] | Welcome to JShell -- Version 22-internal
        [JShell] | For an introduction type: /help intro
        [JShell] | Goodbye
        jshell Output: | Welcome to JShell -- Version 22-internal
        | For an introduction type: /help intro
        | Goodbye

        jshell>
        ----------System.err:(40/2464)----------
         stdout: [Attaching to process ID 590799, please wait...
        Debugger attached successfully.
        Server compiler detected.
        JVM version is 22-internal-2023-09-17-1736580.daniel.daugherty.8315880forjdk22.git
        Deadlock Detection:

        ];
         stderr: [java.lang.InternalError: We should have found a thread that owns the anonymous lock
        at jdk.hotspot.agent/sun.jvm.hotspot.runtime.Threads.owningThreadFromMonitor(Threads.java:244)
        at jdk.hotspot.agent/sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:88)
        at jdk.hotspot.agent/sun.jvm.hotspot.runtime.DeadlockDetector.print(DeadlockDetector.java:39)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:62)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.StackTrace.run(StackTrace.java:45)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.JStack.run(JStack.java:67)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.startInternal(Tool.java:278)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.start(Tool.java:241)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.Tool.execute(Tool.java:134)
        at jdk.hotspot.agent/sun.jvm.hotspot.tools.JStack.runWithArgs(JStack.java:90)
        at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.runJSTACK(SALauncher.java:302)
        at jdk.hotspot.agent/sun.jvm.hotspot.SALauncher.main(SALauncher.java:500)
        ]
         exitValue = 1

        [JShell] jshell>
        java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
        at JStackStressTest.testjstack(JStackStressTest.java:78)
        at JStackStressTest.main(JStackStressTest.java:107)
        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
        at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
        at java.base/java.lang.Thread.run(Thread.java:1570)
        Caused by: java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
        at jdk.test.lib.process.OutputAnalyzer.shouldHaveExitValue(OutputAnalyzer.java:490)
        at JStackStressTest.testjstack(JStackStressTest.java:70)
        ... 5 more

        JavaTest Message: Test threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
        JavaTest Message: shutting down test

        STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Test ERROR java.lang.RuntimeException: Expected to get exit value of [0], exit value is: [1]
        ----------rerun:(38/7573)*----------

        This error mesg from jhsdb:

        > jhsdb jstack stderr:
        > java.lang.InternalError: We should have found a thread that owns the
        > anonymous lock

        could indicate a bug in the LM_LIGHTWEIGHT locking code.
        I have not seen any sightings of this test failing like this in
        the Oracle CIs. I'm starting this bug off in hotspot/runtime for
        initial triage.

        Attachments

          Issue Links

            Activity

              People

                rkennke Roman Kennke
                dcubed Daniel Daugherty
                Votes:
                0 Vote for this issue
                Watchers:
                9 Start watching this issue

                Dates

                  Created:
                  Updated:
                  Resolved: