Uploaded image for project: 'Undertow'
  1. Undertow
  2. UNDERTOW-637

Server shutdown hangs 'forever' after Autobahn TS execution

    XMLWordPrintable

Details

    • 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

    Description

      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)

      Attachments

        Issue Links

          clones

          Bug - A problem that impairs or prevents the functions of the product. JBEAP-3431 Server shutdown hangs 'forever' after Autobahn TS execution

          • Blocker - To be worked above all other priorities. This term is chosen when the severity of the issue is very high, has no workaround, or the effort for the change is comparatively low. Issues that may be very publicly visible and could generate significant media attention may also drive a higher priority.
          • Closed

          Activity

            People

              sdouglas1@redhat.com Stuart Douglas
              sdouglas1@redhat.com Stuart Douglas
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: