Sitelet https://github.com/nodejs/node/issues/1309
Skip to content

No finish/close event on aborted http-response - race condition #1309

Description

@not-implemented

When tracking requests of a HTTP-Server - with server.on('request') and res.on('finish', ...) or res.on('close', ...) - we noticed inconsistent results over time (requests that are never finished or closed).

We tracked this race condition down to the following reproducable test case:

  1. connection is aborted from client side
  2. socket gets destroyed (but socket-"close"-event still not delivered)
  3. trying to send response
  4. socket-"close" event delivered

-> No "close" and no "finish" event on response!

var common = require('../common');
var assert = require('assert');
var http = require('http');

var clientRequest = null;
var serverResponseFinishedOrClosed = 0;

var server = http.createServer(function (req, res) {
    console.log('server: request');

    res.on('finish', function () {
        console.log('server: response finish');
        serverResponseFinishedOrClosed++;
    });
    res.on('close', function () {
        console.log('server: response close');
        serverResponseFinishedOrClosed++;
    });

    console.log('client: aborting request');
    clientRequest.abort();

    setImmediate(function() {
        console.log('server: tick 1' + (req.connection.destroyed ? ' (connection destroyed!)' : ''));

        setImmediate(function () {
            console.log('server: tick 2' + (req.connection.destroyed ? ' (connection destroyed!)' : ''));

            console.log('server: sending response');
            res.writeHead(200, {'Content-Type': 'text/plain'});
            res.end('Response\n');
            console.log('server: res.end() returned');

            setImmediate(function () {
                server.close();
            });
        });
    });
});

server.on('listening', function () {
    console.log('server: listening on port ' + common.PORT);
    console.log('client: starting request');

    var options = {port: common.PORT, path: '/'};
    clientRequest = http.get(options, function () {});
    clientRequest.on('error', function () {});
});

server.on('connection', function (connection) {
    console.log('server: connection');
    connection.on('close', function () { console.log('server: connection close'); });
});

server.on('close', function () {
    console.log('server: close');
    assert.equal(serverResponseFinishedOrClosed, 1, 'Expected either one "finish" or one "close" event on the response for aborted connections (got ' + serverResponseFinishedOrClosed + ')');
});

server.listen(common.PORT);
  • With one more setImmediate() call, you get a response close event (which is fine)
  • With one less setImmediate() call, you get a response finish event (which is fine)
  • Reproducable with io.js 1.6.3, io.js 1.3.0, io.js 1.1.0, node 0.12.0
  • In node 0.10 the race-condition was different: This test case works fine, but with one more setImmediate(), two events are delivered (finish AND close)

Activity

  1. added
    confirmed-bugIssues and PRs for confirmed bugs.
    httpIssues and PRs related to the http subsystem.
    on Apr 1, 2015
  2. not-implemented commented on Apr 1, 2015

    @not-implemented
    ContributorAuthor

    The different behaviour between node 0.10 (<=0.11.5) and node 0.12 (>=0.11.6) may be related to the changes made by @isaacs ("http: Consistent 'finish' event semantics", 7c9b607, and "http: Add write()/end() callbacks" da93d6a).

  3. Olegas commented on Apr 1, 2015

    @Olegas
    Contributor

    +1
    Can see this happens sometimes.
    Neither finish nor close event is triggered on res. Stable reproduces in our environment, we can see this graphically (we count "active" connections with finish/close events).

  4. not-implemented commented on Apr 8, 2015

    @not-implemented
    ContributorAuthor

    Proposed fix see pull request #1373

  5. Fishrock123 commented on Apr 17, 2015

    @Fishrock123
    Contributor
  6. brendanashworth commented on May 14, 2015

    @brendanashworth
    Contributor

    The fix for this (#1411, semver-major) is now on track for the 3.0.0 release.

  7. KoltesDigital commented on Aug 13, 2015

    @KoltesDigital

    Could it please be released earlier? I'm afraid 3.0.0 won't come soon.

  8. Fishrock123 commented on Aug 13, 2015

    @Fishrock123
    Contributor

    3.0.0 is out and this landed in it. :) https://iojs.org/dist/v3.0.0/

  9. added a commit that references this issue on Oct 30, 2015
  10. evantahler commented on May 20, 2016

    @evantahler

    I've found something similar here, which you can emulate with node v4 and v5... just by sending the Content-Length header.

    https://gist.github.com/evantahler/2f6c4241c47d7c89f5555d833475c8b8

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    confirmed-bugIssues and PRs for confirmed bugs.httpIssues and PRs related to the http subsystem.

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions