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

Race in blocked thread handling in nsk.monitoring.share.ThreadController

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: P4 P4
    • tbd
    • 22
    • core-svc

      When testing JDK-8318986, we have seen a test failure in vmTestbase/nsk/monitoring/stress/thread/strace016/TestDescription.java:

      ```
      #>
      #> WARNING: switching log to verbose mode,
      #> because error is complained
      #>
      ThreadMonitor> Test mode: DIRECTLY access to MBean
      ThreadController> number of created threads: 30
      ThreadController> depth for all threads: 100
      ThreadController> invocation type: mixed

      Starting threads.

      ThreadController> locking threads

      States of the threads are culminated.
      # ERROR: Thread BLOCKED_ThreadMM001 wrong thread state: RUNNABLE
      The following stacktrace is for failure analysis.
      nsk.share.TestFailure: Thread BLOCKED_ThreadMM001 wrong thread state: RUNNABLE
      at nsk.share.Log.logExceptionForFailureAnalysis(Log.java:431)
      at nsk.share.Log.complain(Log.java:402)
      at nsk.monitoring.stress.thread.strace010.runIt(strace010.java:148)
      at nsk.monitoring.stress.thread.strace010.run(strace010.java:99)
      at nsk.monitoring.stress.thread.strace010.main(strace010.java:95)
      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)

      Checked 6 BLOCKED threads
      # ERROR: Expected amount: 7 for BLOCKED threads actual: 6
      Checked 7 WAITING threads
      Checked 8 TIMED_WAITING threads
      Checked 9 RUNNABLE threads
      # ERROR: Expected amount: 8 for RUNNABLE threads actual: 9
      ```

      I ran this test hundreds of times without failure. The output implies there is a thread that should be "blocked", but instead it is "runnable". I think the test itself contains the race condition. The harness code starts the threads, and waits before they roll to their appropriate states. But the code for blocked threads under inspection is inherently racy: for example it first notifies that we have reached the BLOCKED state, and only then blocks: https://github.com/openjdk/jdk/blob/25cebe8c3ed5c03b4da2da5bb2f7637c8cd40581/test/hotspot/jtreg/vmTestbase/nsk/monitoring/share/ThreadController.java#L577-L578

      So IMO there is a tiny window where we can see "blocked" thread as "runnable". OTOH, there is a block that waits that threads are rolled to a proper state here:
      https://github.com/openjdk/jdk/blob/25cebe8c3ed5c03b4da2da5bb2f7637c8cd40581/test/hotspot/jtreg/vmTestbase/nsk/monitoring/share/ThreadController.java#L298-L305

            Unassigned Unassigned
            shade Aleksey Shipilev
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated: