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

java/net/httpclient/BasicWebSocketAPITest.java timed out intermittently

    XMLWordPrintable

Details

    • generic
    • generic

    Description

      This has been observed in 9 b120 promotion testing.

      It looks to be hanging on the negative checking of "checkAndClose"

      ----------messages:(151/8942)----------
      command: testng BasicWebSocketAPITest
      reason: User specified action: run testng/othervm BasicWebSocketAPITest
      Mode: othervm [/othervm specified]
      Timeout information:
      Running jstack on process 27994
      2016-05-26 20:02:40
      Full thread dump Java HotSpot(TM) 64-Bit Server VM (9-ea+120 mixed mode):

      "Attach Listener" #27 daemon prio=9 os_prio=64 tid=0x0000000101667000 nid=0x24 waiting on condition [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE

      "Thread-8" #26 prio=5 os_prio=64 tid=0x0000000101085800 nid=0x23 runnable [0xffffffff5c97e000]
         java.lang.Thread.State: RUNNABLE
      at sun.nio.ch.FileDispatcherImpl.read0(java.base@9-ea/Native Method)
      at sun.nio.ch.SocketDispatcher.read(java.base@9-ea/SocketDispatcher.java:39)
      at sun.nio.ch.IOUtil.readIntoNativeBuffer(java.base@9-ea/IOUtil.java:223)
      at sun.nio.ch.IOUtil.read(java.base@9-ea/IOUtil.java:192)
      at sun.nio.ch.SocketChannelImpl.read(java.base@9-ea/SocketChannelImpl.java:382)
      - locked <0x00000007a787f7d8> (a java.lang.Object)
      at HandshakePhase.read(HandshakePhase.java:196)
      at HandshakePhase.readRequest(HandshakePhase.java:226)
      at HandshakePhase.lambda$afterHandshake$0(HandshakePhase.java:98)
      at HandshakePhase$$Lambda$129/870027610.get(Unknown Source)
      at java.util.concurrent.CompletableFuture$AsyncSupply.run(java.base@9-ea/CompletableFuture.java:1651)
      at java.lang.Thread.run(java.base@9-ea/Thread.java:843)

      "HTTP-Cache-cleaner" #13 daemon prio=5 os_prio=64 tid=0x0000000100e12000 nid=0x16 waiting on condition [0xffffffff5d1ef000]
         java.lang.Thread.State: TIMED_WAITING (sleeping)
      at java.lang.Thread.sleep(java.base@9-ea/Native Method)
      at java.net.http.ConnectionPool$CacheCleaner.run(java.httpclient@9-ea/ConnectionPool.java:201)

      "MainThread" #12 prio=5 os_prio=64 tid=0x000000010077e800 nid=0x15 waiting on condition [0xffffffff5ecbb000]
         java.lang.Thread.State: WAITING (parking)
      at jdk.internal.misc.Unsafe.park(java.base@9-ea/Native Method)
      - parking to wait for <0x00000007a7bcc848> (a java.util.concurrent.CompletableFuture$Signaller)
      at java.util.concurrent.locks.LockSupport.park(java.base@9-ea/LockSupport.java:190)
      at java.util.concurrent.CompletableFuture$Signaller.block(java.base@9-ea/CompletableFuture.java:1747)
      at java.util.concurrent.ForkJoinPool.managedBlock(java.base@9-ea/ForkJoinPool.java:3443)
      at java.util.concurrent.CompletableFuture.waitingGet(java.base@9-ea/CompletableFuture.java:1776)
      at java.util.concurrent.CompletableFuture.get(java.base@9-ea/CompletableFuture.java:1947)
      at BasicWebSocketAPITest.checkAndClose(BasicWebSocketAPITest.java:318)
      at BasicWebSocketAPITest.webSocket(BasicWebSocketAPITest.java:81)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-ea/Native Method)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-ea/NativeMethodAccessorImpl.java:62)
      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-ea/DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(java.base@9-ea/Method.java:531)
      at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
      at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
      at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
      at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
      at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
      at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
      at org.testng.TestRunner.privateRun(TestRunner.java:767)
      at org.testng.TestRunner.run(TestRunner.java:617)
      at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
      at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:329)
      at org.testng.SuiteRunner.privateRun(SuiteRunner.java:291)
      at org.testng.SuiteRunner.run(SuiteRunner.java:240)
      at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
      at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
      at org.testng.TestNG.runSuitesSequentially(TestNG.java:1224)
      at org.testng.TestNG.runSuitesLocally(TestNG.java:1149)
      at org.testng.TestNG.run(TestNG.java:1057)
      at com.sun.javatest.regtest.TestNGAction$TestNGRunner.main(TestNGAction.java:220)
      at com.sun.javatest.regtest.TestNGAction$TestNGRunner.main(TestNGAction.java:184)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-ea/Native Method)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-ea/NativeMethodAccessorImpl.java:62)
      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-ea/DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(java.base@9-ea/Method.java:531)
      at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110)
      at java.lang.Thread.run(java.base@9-ea/Thread.java:843)

      "Service Thread" #10 daemon prio=9 os_prio=64 tid=0x00000001004fa000 nid=0x13 runnable [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE

      "Common-Cleaner" #9 daemon prio=8 os_prio=64 tid=0x00000001003d9800 nid=0x12 in Object.wait() [0xffffffff5efee000]
         java.lang.Thread.State: TIMED_WAITING (on object monitor)
      at java.lang.Object.wait(java.base@9-ea/Native Method)
      - waiting on <0x00000007a0139680> (a java.lang.ref.ReferenceQueue$Lock)
      at java.lang.ref.ReferenceQueue.remove(java.base@9-ea/ReferenceQueue.java:151)
      - waiting to re-lock in wait() <0x00000007a0139680> (a java.lang.ref.ReferenceQueue$Lock)
      at jdk.internal.ref.CleanerImpl.run(java.base@9-ea/CleanerImpl.java:148)
      at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
      at jdk.internal.misc.InnocuousThread.run(java.base@9-ea/InnocuousThread.java:122)

      "Sweeper thread" #8 daemon prio=9 os_prio=64 tid=0x000000010039c800 nid=0x11 runnable [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE

      "C1 CompilerThread1" #7 daemon prio=9 os_prio=64 tid=0x0000000100391800 nid=0x10 waiting on condition [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         No compile task

      "C2 CompilerThread0" #6 daemon prio=9 os_prio=64 tid=0x000000010034b000 nid=0xf waiting on condition [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE
         No compile task

      "Signal Dispatcher" #5 daemon prio=9 os_prio=64 tid=0x0000000100349800 nid=0xe runnable [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE

      "Reference Pending List Locker" #4 daemon prio=9 os_prio=64 tid=0x0000000100348000 nid=0xd waiting on condition [0x0000000000000000]
         java.lang.Thread.State: RUNNABLE

      "Finalizer" #3 daemon prio=8 os_prio=64 tid=0x000000010032a800 nid=0xc in Object.wait() [0xffffffff62dce000]
         java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(java.base@9-ea/Native Method)
      - waiting on <0x00000007a013a2e8> (a java.lang.ref.ReferenceQueue$Lock)
      at java.lang.ref.ReferenceQueue.remove(java.base@9-ea/ReferenceQueue.java:151)
      - waiting to re-lock in wait() <0x00000007a013a2e8> (a java.lang.ref.ReferenceQueue$Lock)
      at java.lang.ref.ReferenceQueue.remove(java.base@9-ea/ReferenceQueue.java:172)
      at java.lang.ref.Finalizer$FinalizerThread.run(java.base@9-ea/Finalizer.java:216)

      "Reference Handler" #2 daemon prio=10 os_prio=64 tid=0x0000000100325000 nid=0xb in Object.wait() [0xffffffff62edf000]
         java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(java.base@9-ea/Native Method)
      - waiting on <0x00000007a013a510> (a java.lang.ref.Reference$Lock)
      at java.lang.Object.wait(java.base@9-ea/Object.java:516)
      at java.lang.ref.Reference.tryHandlePending(java.base@9-ea/Reference.java:193)
      - waiting to re-lock in wait() <0x00000007a013a510> (a java.lang.ref.Reference$Lock)
      at java.lang.ref.Reference$ReferenceHandler.run(java.base@9-ea/Reference.java:155)

      "main" #1 prio=5 os_prio=64 tid=0x000000010021c000 nid=0x2 in Object.wait() [0xffffffff7c9ef000]
         java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait(java.base@9-ea/Native Method)
      - waiting on <0x00000007a0138670> (a java.lang.Thread)
      at java.lang.Thread.join(java.base@9-ea/Thread.java:1352)
      - waiting to re-lock in wait() <0x00000007a0138670> (a java.lang.Thread)
      at java.lang.Thread.join(java.base@9-ea/Thread.java:1426)
      at com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)

      "VM Thread" os_prio=64 tid=0x0000000100319800 nid=0xa runnable

      "GC Thread#0" os_prio=64 tid=0x000000010020b000 nid=0x3 runnable

      "GC Thread#1" os_prio=64 tid=0x000000010020c000 nid=0x4 runnable

      "G1 Main Marker" os_prio=64 tid=0x00000001001fc000 nid=0x8 runnable

      "G1 Marker#0" os_prio=64 tid=0x00000001001f1000 nid=0x9 runnable

      "G1 Refine#0" os_prio=64 tid=0x000000010020f000 nid=0x6 runnable

      "G1 Refine#1" os_prio=64 tid=0x000000010020d800 nid=0x5 runnable

      "G1 Young RemSet Sampling" os_prio=64 tid=0x0000000100210800 nid=0x7 runnable

      "VM Periodic Task Thread" os_prio=64 tid=0x00000001004fc800 nid=0x14 waiting on condition

      JNI global references: 1036

      --- Timeout information end.
      elapsed time (seconds): 481.376
      ----------configuration:(0/0)----------
      ----------System.out:(5/150)----------
      [TestNG] Running:
        java/net/httpclient/BasicWebSocketAPITest.java

      test BasicWebSocketAPITest.builder(): success
      Timeout signalled after 480 seconds
      ----------System.err:(10/974)----------
      May 26, 2016 7:54:41 PM java.net.http.WS$1 onError
      WARNING: Failing connection java.net.http.WS@eea704f[CONNECTED], reason: 'RFC 6455 7.2.1. Stream ended before a Close frame has been received'
      May 26, 2016 7:54:41 PM java.net.http.WS$1 onError
      WARNING: Failing connection java.net.http.WS@1bb3c5e9[CONNECTED], reason: 'RFC 6455 7.2.1. Stream ended before a Close frame has been received'
      May 26, 2016 7:54:41 PM java.net.http.WS$1 onError
      WARNING: Failing connection java.net.http.WS@34d63f6c[CONNECTED], reason: 'RFC 6455 7.2.1. Stream ended before a Close frame has been received'
      May 26, 2016 7:54:41 PM java.net.http.WS$1 onError
      WARNING: Failing connection java.net.http.WS@644f61eb[CONNECTED], reason: 'RFC 6455 7.2.1. Stream ended before a Close frame has been received'
      May 26, 2016 7:54:41 PM java.net.http.WS$1 onError
      WARNING: Failing connection java.net.http.WS@5807fdc4[CONNECTED], reason: 'RFC 6455 7.2.1. Stream ended before a Close frame has been received'

      Attachments

        Issue Links

          Activity

            People

              prappo Pavel Rappo
              xiaofeya Xiaofeng Yang
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: