[Async Requests] Connections are not removed from IdleTimeoutFilter's delay queue in case client aborts ChunkedOutput

[arinban]

Hello, we have found a issue with grizzly's IdleTimeoutFilter's delay queue, which keeps references to TCPNIOConnection objects, even though the requests associated with these connections have aborted.

The issue occurs when using asynchronous requests with ChunkedOutput streams as entity, in case the client aborts the connection before the stream is closed from server side. It also seems like this is a race condition between the method calls within the IdleTimeoutFilter and the cleanup procedure of the DelayedExecuter$DelayQueue

The problem is with the following code parts:

The timeout for the TCPNIOConnections is set to 0 in case the connection is closed:

@Override
    public NextAction handleClose(final FilterChainContext ctx) throws IOException {
        queue.remove(ctx.getConnection());
        return ctx.getInvokeAction();
    }

GitHub

In case the client connection is aborted we have observed that usually after this a call to ContextCompletionListener.onComplete (GitHub) which comes from a write action is made. A call to this method from the close action is never observed.

This leads to the case that there is one less call to the onComplete methods than to the Filter events. Therefore the value of the counter that is being increased and decreased in these methods in the end is 1.

The timeout is set to FOREVER_SPECIAL within the call that happens after the handleClose call, but the special logic that should set the timeout back to a different value is never triggered, as counter == 0 never happens.

My suggestion for a fix would be to add the following condition to the onComplete method:

if (IdleRecord.counterUpdater.decrementAndGet(idleRecord) == 0 || idleRecord.isClosed) {

GitHub

However we are not sure if this is the only resource that is not correctly freed in such a case. This is just what we observed

To reproduce the issue one may use the following resource

@Valid
@GET
@Path("testAsync")
@Produces({
    "application/octet-stream",
    "application/json"
})
public void getAppsTestAsync(RestRequest req, HttpHeaders headers, UriInfo uri, String q, Integer timeout, AsyncResponse async) throws Exception {
    ChunkedOutput<byte[]> chunkedOutput = new ChunkedOutput<>(byte[].class, new byte[0]);
    Response response = Response.status(RestResponseCode.HTTP_OK.getCode())
            .header("Content-Type", "application/octet-stream")
            .entity(chunkedOutput)
            .build();
    async.resume(response);
    new Thread(new Runnable() {
        @Override
        public void run() {
            veryExpensiveOperation();
        }

        private void veryExpensiveOperation() {
            try {
                for (int i = 0; i < 3; ++i) {
                    chunkedOutput.write("test\n".getBytes());
                    Thread.sleep(1000);
                }
            } catch (Exception e) {
                e.printStackTrace();
            } finally {
                try {
                    chunkedOutput.close();
                } catch (IOException e) {
                    e.printStackTrace();
                }
            }
        }
    }).start();
}

Use curl to trigger a request and abort it before the last line is sent to the stream

Affected Versions

[2.3.28]

[arinban]

• Issue Imported From: https://github.com/javaee/grizzly/issues/1878
• Original Issue Raised By:@glassfishrobot
• Original Issue Assigned To:@rlubke
• Original Issue Closed By:@glassfishrobot

[arinban]

@glassfishrobot Commented Reported by MarcBecker

[arinban]

@glassfishrobot Commented @rlubke said: I'm not a JAXRS expert and spent time trying to get a maven project working with no success. Sorry, I don't have a lot of time to spend to get it set up at the moment.

It would help if you could provide a complete test case I can run to investigate the issue.

[arinban]

@glassfishrobot Commented @rlubke said: Okay, I made some changes to the test case and have it working. Investigating.

[arinban]

@glassfishrobot Commented @rlubke said: Could you please give this JAR [1] a shot in your environment?

[1] https://www.dropbox.com/s/pmw8vy3ovnbfyrx/grizzly-framework-2.3.29-SNAPSHOT.jar?dl=0

[arinban]

@glassfishrobot Commented @rlubke said: Changes applied:

2.3.x: 3c30dc05944f88184123f57d4956a14dfc5815eb master: 8f783a3c8bd7357c77cdd45e7f07d836ada927eb

[arinban]

@glassfishrobot Commented marcbecker said: Unfortunately I wasn't able to verify the fix with the SNAPSHOT jar from the dropbox link. The issue is still present. Do you need any further information?

[arinban]

@glassfishrobot Commented This issue was imported from java.net JIRA GRIZZLY-1878

[arinban]

@glassfishrobot Commented Marked as fixed on Friday, January 13th 2017, 2:03:01 pm