users@grizzly.java.net

Re: Grizzly HTTP servlet: aggressive recycling revisited

From: Matthew Swift <matthew.swift_at_gmail.com>
Date: Wed, 10 Oct 2012 11:54:45 +0200

On 9 October 2012 17:22, Oleksiy Stashok <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