From michael.hixson at gmail.com Sat May 30 01:05:00 2015 Content-Type: multipart/mixed; boundary="===============0743539769878683327==" MIME-Version: 1.0 From: Michael Hixson To: undertow-dev at lists.jboss.org Subject: Re: [undertow-dev] http/2 server starts dying after rapid refresh Date: Fri, 29 May 2015 22:04:58 -0700 Message-ID: In-Reply-To: 4EA9BD5A-06AB-4828-ACF1-C5959EBA75BF@redhat.com --===============0743539769878683327== Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Hi Jason, I believe the close() call is coming from me declaring the writer in a try-with-resources statement. Here's a jstack from just now, where my CPU is sitting at 96%: https://gist.github.com/michaelhixson/8a6f2ebf4b167fb1b67e -Michael On Fri, May 29, 2015 at 9:28 PM, Jason T. Greene wrote: > Hi Michael, > > That stack trace seems to show a close() call to the writer in your handl= er, but I don't see that call in the code? > > Note that getting I/o exceptions during write and close calls is normal a= fter a client abnormally terminates. You typically just drop the exception = (perhaps trace logging). > > Could you get a jstack output under the scenario where you see high CPU l= oad? > > >> On May 28, 2015, at 6:19 PM, Michael Hixson = wrote: >> >> Hello, >> >> I'm trying out HTTP/2 with undertow-core in my application, and I see >> that I'm able to get the server into a bad state pretty reliably by >> refreshing quickly in my browser. It stops responding to requests and >> the CPU usage of the Java process starts to climb towards 100%. >> >> I was able to replicate this in the HTTP/2 example in the latest from >> the master branch, by changing the main HttpHandler. This is what I >> put in Http2Server#main(String[]): >> >> Undertow server =3D Undertow.builder() >> .setServerOption(UndertowOptions.ENABLE_HTTP2, true) >> .setServerOption(UndertowOptions.ENABLE_SPDY, true) >> .addHttpListener(8080, bindAddress) >> .addHttpsListener(8443, bindAddress, sslContext) >> .setHandler(new HttpHandler() { >> @Override >> public void handleRequest(HttpServerExchange exchange) { >> if (exchange.isInIoThread()) { >> exchange.dispatch(this); >> return; >> } >> exchange.startBlocking(); >> exchange.getResponseHeaders().put( >> new HttpString("Content-Type"), "text/html"); >> try (BufferedWriter writer =3D new BufferedWriter( >> new OutputStreamWriter( >> exchange.getOutputStream(), >> StandardCharsets.UTF_8))) { >> writer.append("\n"); >> for (int i =3D 0; i < 100; i++) { >> writer.append( >> "\n"); >> } >> writer.append("hello"); >> } catch (IOException e) { >> e.printStackTrace(); >> throw new RuntimeException(e); >> } >> } >> }).build(); >> >> Then I go to https://localhost:8443/ in a browser and hold down F5 for >> a bit. I start seeing errors like this: >> >> java.nio.channels.ClosedChannelException >> at io.undertow.server.protocol.framed.AbstractFramedStreamSinkCha= nnel.write(AbstractFramedStreamSinkChannel.java:396) >> at org.xnio.channels.Channels.writeFinalBasic(Channels.java:961) >> at io.undertow.server.protocol.framed.AbstractFramedStreamSinkCha= nnel.writeFinal(AbstractFramedStreamSinkChannel.java:420) >> at org.xnio.conduits.StreamSinkChannelWrappingConduit.writeFinal(= StreamSinkChannelWrappingConduit.java:66) >> at org.xnio.conduits.ConduitStreamSinkChannel.writeFinal(ConduitS= treamSinkChannel.java:104) >> at io.undertow.channels.DetachableStreamSinkChannel.writeFinal(De= tachableStreamSinkChannel.java:195) >> at io.undertow.server.HttpServerExchange$WriteDispatchChannel.wri= teFinal(HttpServerExchange.java:1882) >> at io.undertow.io.UndertowOutputStream.writeBufferBlocking(Undert= owOutputStream.java:288) >> at io.undertow.io.UndertowOutputStream.close(UndertowOutputStream= .java:331) >> at sun.nio.cs.StreamEncoder.implClose(StreamEncoder.java:320) >> at sun.nio.cs.StreamEncoder.close(StreamEncoder.java:149) >> at java.io.OutputStreamWriter.close(OutputStreamWriter.java:233) >> at java.io.BufferedWriter.close(BufferedWriter.java:266) >> at io.undertow.examples.http2.Http2Server$1.handleRequest(Http2Se= rver.java:94) >> at io.undertow.server.Connectors.executeRootHandler(Connectors.ja= va:199) >> at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange= .java:774) >> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1142) >> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:617) >> at java.lang.Thread.run(Thread.java:745) >> >> In case it helps, I saw a different error in my real (not undertow >> example) application when I started seeing the same effects visibly >> (site down and CPU climbing to 100%). Maybe it is the same root cause >> but just being caught/logged differently: >> >> ERROR [2015-05-28 14:23:59,804] org.xnio.nio: XNIO000011: Task >> io.undertow.server.protocol.framed.AbstractFramedChannel$2(a)308b5f1f >> failed with an exception >> java.lang.IllegalStateException: null >> at io.undertow.server.protocol.framed.AbstractFramedStreamSinkChannel.g= etBuffer(AbstractFramedStreamSinkChannel.java:523) >> ~[undertow-core-1.3.0.Beta1-SNAPSHOT.jar:1.3.0.Beta1-SNAPSHOT] >> at io.undertow.server.protocol.framed.AbstractFramedChannel.flushSender= s(AbstractFramedChannel.java:496) >> ~[undertow-core-1.3.0.Beta1-SNAPSHOT.jar:1.3.0.Beta1-SNAPSHOT] >> at io.undertow.server.protocol.framed.AbstractFramedChannel$2.run(Abstr= actFramedChannel.java:581) >> ~[undertow-core-1.3.0.Beta1-SNAPSHOT.jar:1.3.0.Beta1-SNAPSHOT] >> at org.xnio.nio.WorkerThread.safeRun(WorkerThread.java:560) >> ~[xnio-nio-3.3.1.Final.jar:3.3.1.Final] >> at org.xnio.nio.WorkerThread.run(WorkerThread.java:462) >> ~[xnio-nio-3.3.1.Final.jar:3.3.1.Final] >> >> I see the same behavior in my real application with both undertow-core >> 1.2.6.Final and 1.3.0.Beta1-SNAPSHOT (the latter installed locally >> from source). I only tried the Http2Server example in the latest >> version though. >> >> -Michael >> _______________________________________________ >> undertow-dev mailing list >> undertow-dev(a)lists.jboss.org >> https://lists.jboss.org/mailman/listinfo/undertow-dev --===============0743539769878683327==--