users@grizzly.java.net

Re: Grizzly HTTP servlet: aggressive recycling revisited

From: Oleksiy Stashok <oleksiy.stashok_at_oracle.com>
Date: Thu, 11 Oct 2012 17:11:36 +0200

Matt,
can you pls. test the latest Grizzly 2.3-SNAPSHOT?

Thanks.

WBR,
Alexey.

On 10/11/2012 03:23 PM, Oleksiy Stashok wrote:
> 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
>>
>