users@grizzly.java.net

Re: Grizzly HTTP servlet: aggressive recycling revisited

From: Oleksiy Stashok <oleksiy.stashok_at_oracle.com>
Date: Thu, 11 Oct 2012 15:23:29 +0200

Hi Matt,

thanks a lot for the testcase!
I filed an issue

http://java.net/jira/browse/GRIZZLY-1348

Will fix it asap.

WBR,
Alexey.


On 10/10/2012 11:54 AM, Matthew Swift wrote:
>
>
> On 9 October 2012 17:22, Oleksiy Stashok <oleksiy.stashok_at_oracle.com
> <mailto:oleksiy.stashok_at_oracle.com>> wrote:
>
>
> On 10/09/2012 04:58 PM, Matthew Swift wrote:
>> Hmm, I was hoping you'd be able to figure it out ;-) I ripped the
>> sample code from my Servlet (which I have got working ok now BTW
>> but it's a bit of a balancing act). It'll take a short while for
>> me to create a unit test. Give me a moment...
> Oh, I thought it's easy to reproduce issue :))
>
>
> In fact it wasn't as easy as I thought. Here's a minimal test:
>
> import java.io.IOException;
> import java.util.logging.Logger;
>
> import javax.servlet.ServletException;
> import javax.servlet.http.HttpServlet;
> import javax.servlet.http.HttpServletRequest;
> import javax.servlet.http.HttpServletResponse;
>
>
> import org.glassfish.grizzly.http.server.HttpServer;
> import org.glassfish.grizzly.servlet.ServletRegistration;
> import org.glassfish.grizzly.servlet.WebappContext;
> import org.testng.annotations.Test;
>
> /**
> * An example server which can be run as a unit test.
> */
> public class GrizzlyTest {
> private static final Logger LOGGER =
> Logger.getLogger(GrizzlyTest.class.getName());
> private static final int PORT = 18890;
>
> /**
> * Tests isCommitted().
> *
> * @throws Exception
> * If an unexpected IO error occurred.
> */
> @Test
> public void testIsCommitted() throws Exception {
> final HttpServer httpServer = HttpServer.createSimpleServer("./",
> PORT);
> try {
> final WebappContext ctx = new WebappContext("example", "/example");
> final ServletRegistration reg = ctx.addServlet("managed", new
> HttpServlet() {
> @Override
> protected void service(HttpServletRequest req,
> HttpServletResponse resp)
> throws ServletException, IOException {
> req.startAsync();
> resp.isCommitted();
> resp.sendError(400, "Four hundred");
> resp.isCommitted();
> }
> });
> reg.addMapping("/managed/*");
> ctx.deploy(httpServer);
>
> LOGGER.info("Starting server...");
> httpServer.start();
> LOGGER.info("Server started");
> LOGGER.info("Press any key to stop the server...");
> System.in.read();
> } finally {
> LOGGER.info("Stopping server...");
> httpServer.stop();
> LOGGER.info("Server stopped");
> }
> }
> }
>
>
> And a curl command to reproduce:
>
> curl -v -H "content-type: application/json" --request GET
> "http://localhost:18890/example/managed/users"
>
>
> In the test case above the second call to isCommitted() fails with an
> IllegalStateException because the underlying response has been
> recycled. I couldn't get the test working at first because it is
> sensitive to the error code. I was initially using a 404 error which
> did not cause the internal response to be recycled (a bug?) and so the
> second call to isCommitted() was fine.
>
> FWIW, the stack trace at the point where the inner response is
> recycled is:
>
> Daemon Thread [Grizzly(3)] (Suspended (breakpoint at line 230 in
> HttpServletResponseImpl))
> HttpServletResponseImpl.recycle() line: 230
> ServletHandler$ServletAfterServiceListener.onAfterService(Request)
> line: 576
> Request.onAfterService() line: 570
> HttpServerFilter.afterService(FilterChainContext, Connection,
> Request, Response) line: 307
> HttpServerFilter.handleRead(FilterChainContext) line: 232
> ExecutorResolver$9.execute(Filter, FilterChainContext) line: 119
> DefaultFilterChain.executeFilter(FilterExecutor, Filter,
> FilterChainContext) line: 265
> DefaultFilterChain.executeChainPart(FilterChainContext,
> FilterExecutor, int, int, DefaultFilterChain$FiltersState) line: 200
> DefaultFilterChain.execute(FilterChainContext) line: 134
> DefaultFilterChain.process(Context) line: 112
> ProcessorExecutor.execute(Context) line: 77
> FilterChainContext$1.run() line: 184
> FilterChainContext.resume() line: 208
> Response$SuspendedContextImpl$SuspendCloseListener.onClosed(Connection,
> Connection$CloseType) line: 1964
> TCPNIOConnection(NIOConnection).notifyCloseListeners() line: 679
> TCPNIOConnection(NIOConnection).close0(CompletionHandler<Connection>,
> boolean) line: 423
> TCPNIOConnection.close0(CompletionHandler<Connection>, boolean)
> line: 291
> TCPNIOConnection(NIOConnection).close(CompletionHandler<Connection>)
> line: 406
> TCPNIOConnection(NIOConnection).closeSilently() line: 412
> HttpCodecFilter$FlushAndCloseHandler.completed(WriteResult) line: 1725
> HttpCodecFilter$FlushAndCloseHandler.completed(Object) line: 1718
> AsyncWriteQueueRecord.notifyCompleteAndRecycle() line: 172
> TCPNIOAsyncQueueWriter(AbstractNIOAsyncQueueWriter).write(Connection,
> SocketAddress, WritableMessage,
> CompletionHandler<WriteResult<WritableMessage,SocketAddress>>,
> PushBackHandler, MessageCloner<WritableMessage>) line: 326
> TCPNIOAsyncQueueWriter(AbstractNIOAsyncQueueWriter).write(Connection,
> SocketAddress, WritableMessage,
> CompletionHandler<WriteResult<WritableMessage,SocketAddress>>,
> PushBackHandler) line: 230
> TCPNIOAsyncQueueWriter(AbstractNIOAsyncQueueWriter).write(Connection,
> Object, WritableMessage, CompletionHandler, PushBackHandler) line: 73
> TCPNIOAsyncQueueWriter(AbstractWriter<L>).write(Connection,
> WritableMessage,
> CompletionHandler<WriteResult<WritableMessage,L>>) line: 74
> TCPNIOTransportFilter.handleEvent(FilterChainContext,
> FilterChainEvent) line: 154
> TransportFilter.handleEvent(FilterChainContext, FilterChainEvent)
> line: 209
> ExecutorResolver$6.execute(Filter, FilterChainContext) line: 94
> DefaultFilterChain.executeFilter(FilterExecutor, Filter,
> FilterChainContext) line: 265
> DefaultFilterChain.executeChainPart(FilterChainContext,
> FilterExecutor, int, int, DefaultFilterChain$FiltersState) line: 200
> DefaultFilterChain.execute(FilterChainContext) line: 134
> DefaultFilterChain.process(Context) line: 112
> ProcessorExecutor.execute(Context) line: 77
> FilterChainContext.flush(CompletionHandler) line: 723
> HttpCodecFilter.flushAndClose(FilterChainContext) line: 1706
> HttpServerFilter.processResponseComplete(FilterChainContext,
> HttpRequestPacket, boolean) line: 1179
> HttpServerFilter.handleEvent(FilterChainContext, FilterChainEvent)
> line: 1141
> ExecutorResolver$6.execute(Filter, FilterChainContext) line: 94
> DefaultFilterChain.executeFilter(FilterExecutor, Filter,
> FilterChainContext) line: 265
> DefaultFilterChain.executeChainPart(FilterChainContext,
> FilterExecutor, int, int, DefaultFilterChain$FiltersState) line: 200
> DefaultFilterChain.execute(FilterChainContext) line: 134
> DefaultFilterChain.process(Context) line: 112
> ProcessorExecutor.execute(Context) line: 77
> FilterChainContext.notifyDownstream(FilterChainEvent,
> CompletionHandler<FilterChainContext>) line: 766
> FilterChainContext.notifyDownstream(FilterChainEvent) line: 749
> OutputBuffer.endRequest() line: 370
> Response.finish() line: 491
> Response.sendError(int, String) line: 1213
> HttpServletResponseImpl.sendError(int, String) line: 536
> GrizzlyTest$1.service(HttpServletRequest, HttpServletResponse)
> line: 57
> GrizzlyTest$1(HttpServlet).service(ServletRequest,
> ServletResponse) line: 770
> FilterChainImpl.doFilter(ServletRequest, ServletResponse) line: 147
> FilterChainImpl.invokeFilterChain(ServletRequest, ServletResponse)
> line: 106
> ServletHandler.doServletService(Request, Response) line: 252
> ServletHandler.service(Request, Response) line: 188
> ServletHandler(HttpHandler).doHandle(Request, Response) line: 164
> HttpHandlerChain.service(Request, Response) line: 220
> HttpHandlerChain(HttpHandler).doHandle(Request, Response) line: 164
> HttpServerFilter.handleRead(FilterChainContext) line: 175
> ExecutorResolver$9.execute(Filter, FilterChainContext) line: 119
> DefaultFilterChain.executeFilter(FilterExecutor, Filter,
> FilterChainContext) line: 265
> DefaultFilterChain.executeChainPart(FilterChainContext,
> FilterExecutor, int, int, DefaultFilterChain$FiltersState) line: 200
> DefaultFilterChain.execute(FilterChainContext) line: 134
> DefaultFilterChain.process(Context) line: 112
> ProcessorExecutor.execute(Context) line: 77
> TCPNIOTransport.fireIOEvent(IOEvent, Connection,
> IOEventProcessingHandler) line: 886
> AbstractIOStrategy.fireIOEvent(Connection, IOEvent,
> IOEventProcessingHandler, Logger) line: 112
> WorkerThreadIOStrategy.run0(Connection, IOEvent,
> IOEventProcessingHandler) line: 115
> WorkerThreadIOStrategy.access$100(Connection, IOEvent,
> IOEventProcessingHandler) line: 55
> WorkerThreadIOStrategy$WorkerThreadRunnable.run() line: 135
> FixedThreadPool$BasicWorker(AbstractThreadPool$Worker).doWork()
> line: 578
> FixedThreadPool$BasicWorker(AbstractThreadPool$Worker).run() line: 558
> DefaultWorkerThread(Thread).run() line: 662
>
>
> I couldn't easily figure out where the HTTP result code conditional
> logic is performed (i.e. if (resultCode == 400) then recycle the
> request).
>
> Matt
>