Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-3431

Server shutdown hangs 'forever' after Autobahn TS execution

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Blocker Blocker
    • 7.0.0.ER6
    • 7.0.0.ER5
    • Undertow
    • None
    • Hide
      • prepare autobahn testsuite 
        curl -O https://bootstrap.pypa.io/get-pip.py
python get-pip.py
pip install autobahntestsuite
pip install unittest2
      • attaching autobahn.spec file of how tests have been executed
      • attaching websocket-endpoints.war that should be deployed in the EAP server before autobahn TS is executed
      • start autobahn: wstest -m fuzzingclient -s autobahn.spec
      Show
      prepare autobahn testsuite curl -O https: //bootstrap.pypa.io/get-pip.py python get-pip.py pip install autobahntestsuite pip install unittest2 attaching autobahn.spec file of how tests have been executed attaching websocket-endpoints.war that should be deployed in the EAP server before autobahn TS is executed start autobahn: wstest -m fuzzingclient -s autobahn.spec

      After Autobahn tests execution and calling CLI command shutdown EAP server hangs during shutdown like 'forever' (waited for about 30 minutes).

      During execution of Autobahn tests (particular test that causes this is 7.1.6 testcase), I can see following exception in console log:

      ERROR [io.undertow.websockets.core.request] (default task-3) UT025007: Unhandled exception for annotated endpoint websocket.echo.EchoAsyncWithFutureEndpoint@4dfa88e9: java.lang.RuntimeException: java.util.concurrent.ExecutionException: java.io.IOException: UT002002: Channel is closed
	at websocket.echo.EchoAsyncWithFutureEndpoint.echoTextMessage(EchoAsyncWithFutureEndpoint.java:62)
	at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at io.undertow.websockets.jsr.annotated.BoundMethod.invoke(BoundMethod.java:87)
	at io.undertow.websockets.jsr.annotated.AnnotatedEndpoint$1$1.run(AnnotatedEndpoint.java:122)
	at io.undertow.websockets.jsr.ServerWebSocketContainer.invokeEndpointMethod(ServerWebSocketContainer.java:553)
	at io.undertow.websockets.jsr.annotated.AnnotatedEndpoint$1.onMessage(AnnotatedEndpoint.java:117)
	at io.undertow.websockets.jsr.FrameHandler$7.run(FrameHandler.java:274)
	at io.undertow.websockets.jsr.ServerWebSocketContainer.invokeEndpointMethod(ServerWebSocketContainer.java:553)
	at io.undertow.websockets.jsr.ServerWebSocketContainer$5.run(ServerWebSocketContainer.java:538)
	at io.undertow.websockets.jsr.OrderedExecutor$ExecutorTask.run(OrderedExecutor.java:67)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.util.concurrent.ExecutionException: java.io.IOException: UT002002: Channel is closed
	at io.undertow.websockets.jsr.SendResultFuture.handleResult(SendResultFuture.java:145)
	at io.undertow.websockets.jsr.SendResultFuture.get(SendResultFuture.java:98)
	at io.undertow.websockets.jsr.SendResultFuture.get(SendResultFuture.java:34)
	at websocket.echo.EchoAsyncWithFutureEndpoint.echoTextMessage(EchoAsyncWithFutureEndpoint.java:56)
	... 14 more
Caused by: java.io.IOException: UT002002: Channel is closed
	at io.undertow.websockets.core.WebSocketChannel.send(WebSocketChannel.java:333)
	at io.undertow.websockets.core.WebSockets.sendInternal(WebSockets.java:392)
	at io.undertow.websockets.core.WebSockets.sendText(WebSockets.java:62)
	at io.undertow.websockets.jsr.WebSocketSessionRemoteEndpoint$AsyncWebSocketSessionRemoteEndpoint.sendText(WebSocketSessionRemoteEndpoint.java:132)
	at websocket.echo.EchoAsyncWithFutureEndpoint.echoTextMessage(EchoAsyncWithFutureEndpoint.java:64)
	... 14 more

      when all tests finish (successfully by the way), I call shutdown operation on server which causes to provide following output:

      10:00:18,834 INFO  [org.jboss.as.server] (management-handler-thread - 4) WFLYSRV0211: Suspending server with 0ms timeout.
10:00:18,840 INFO  [org.jboss.as.server] (Thread-2) WFLYSRV0220: Server shutdown has been requested.
10:00:18,855 INFO  [org.wildfly.extension.undertow] (ServerService Thread Pool -- 64) WFLYUT0022: Unregistered web context: /websocket-endpoints
10:00:28,858 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-5) WFLYUT0019: Host default-host stopping
10:00:28,859 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-6) WFLYJCA0010: Unbound data source [java:jboss/datasources/ExampleDS]
10:00:28,861 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-6) WFLYJCA0019: Stopped Driver service with driver-name = h2
10:00:28,871 INFO  [org.hibernate.validator.internal.util.Version] (MSC service thread 1-1) HV000001: Hibernate Validator 5.2.3.Final-redhat-1
10:00:28,918 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-6) WFLYUT0008: Undertow HTTP listener default suspending
10:00:28,918 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-5) WFLYSRV0028: Stopped deployment websocket-endpoints.war (runtime-name: websocket-endpoints.war) in 10076ms
10:00:28,918 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-6) WFLYUT0007: Undertow HTTP listener default stopped, was bound to 127.0.0.1:8080
10:00:28,919 INFO  [org.wildfly.extension.undertow] (MSC service thread 1-6) WFLYUT0004: Undertow 1.3.16.Final-redhat-1 stopping
10:00:28,921 ERROR [org.xnio.listener] (default I/O-15) XNIO001007: A channel event listener threw an exception: java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
	at org.xnio.nio.WorkerThread.execute(WorkerThread.java:588)
	at io.undertow.server.protocol.framed.AbstractFramedChannel.runInIoThread(AbstractFramedChannel.java:217)
	at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameCloseListener.handleEvent(AbstractFramedChannel.java:915)
	at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameCloseListener.handleEvent(AbstractFramedChannel.java:899)
	at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92)
	at org.xnio.conduits.WriteReadyHandler$ChannelListenerHandler.terminated(WriteReadyHandler.java:70)
	at org.xnio.nio.NioSocketConduit.writeTerminated(NioSocketConduit.java:197)
	at org.xnio.nio.NioSocketConduit.terminateWrites(NioSocketConduit.java:186)
	at org.xnio.nio.NioSocketConduit.truncateWrites(NioSocketConduit.java:191)
	at io.undertow.conduits.IdleTimeoutConduit.truncateWrites(IdleTimeoutConduit.java:356)
	at org.xnio.conduits.ConduitStreamSinkChannel.close(ConduitStreamSinkChannel.java:186)
	at org.xnio.IoUtils.safeClose(IoUtils.java:134)
	at org.xnio.conduits.WriteReadyHandler$ChannelListenerHandler.forceTermination(WriteReadyHandler.java:57)
	at org.xnio.nio.NioSocketConduit.forceTermination(NioSocketConduit.java:107)
	at org.xnio.nio.WorkerThread.run(WorkerThread.java:492)

      and now server just hangs on. Attaching output of jstack command eap_shutdown_after_autobahn_jstack. There can be seen:

      "default task-18" #148 prio=5 os_prio=0 tid=0x00007f767427c000 nid=0x6af2 in Object.wait() [0x00007f76c6b2b000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:502)
        at io.undertow.server.protocol.framed.AbstractFramedStreamSinkChannel.awaitWritable(AbstractFramedStreamSinkChannel.java:278)
        - locked <0x00000000f943c520> (a java.lang.Object)
        at org.xnio.channels.Channels.flushBlocking(Channels.java:64)
        at io.undertow.websockets.core.BinaryOutputStream.close(BinaryOutputStream.java:64)
        at sun.nio.cs.StreamEncoder.implClose(StreamEncoder.java:320)
        at sun.nio.cs.StreamEncoder.close(StreamEncoder.java:149)
        - locked <0x00000000f943c5c8> (a java.io.OutputStreamWriter)
        at java.io.OutputStreamWriter.close(OutputStreamWriter.java:233)
        at test.EchoBasicEndpoint.handleMessage(EchoBasicEndpoint.java:42)
        at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at io.undertow.websockets.jsr.annotated.BoundMethod.invoke(BoundMethod.java:87)
        at io.undertow.websockets.jsr.annotated.AnnotatedEndpoint$1$1.run(AnnotatedEndpoint.java:122)
        at io.undertow.websockets.jsr.ServerWebSocketContainer.invokeEndpointMethod(ServerWebSocketContainer.java:553)
        at io.undertow.websockets.jsr.annotated.AnnotatedEndpoint$1.onMessage(AnnotatedEndpoint.java:117)
        at io.undertow.websockets.jsr.FrameHandler$7.run(FrameHandler.java:274)
        at io.undertow.websockets.jsr.ServerWebSocketContainer.invokeEndpointMethod(ServerWebSocketContainer.java:553)
        at io.undertow.websockets.jsr.ServerWebSocketContainer$5.run(ServerWebSocketContainer.java:538)
        at io.undertow.websockets.jsr.OrderedExecutor$ExecutorTask.run(OrderedExecutor.java:67)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

        1. autobahn.spec
          0.8 kB
        2. eap_shutdown_after_autobahn_jstack
          17 kB
        3. websocket-endpoints.war
          8 kB

            sdouglas1@redhat.com Stuart Douglas
            jstourac@redhat.com Jan Stourac
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: