Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Server breaks when using cached server method #2665

Closed
kedemd opened this issue Jul 27, 2015 · 1 comment
Closed

Server breaks when using cached server method #2665

kedemd opened this issue Jul 27, 2015 · 1 comment
Assignees
Labels
bug Bug or defect dependency Update module dependency
Milestone

Comments

@kedemd
Copy link

kedemd commented Jul 27, 2015

Hapi 8.8.0 (Also happens on 8.2.0 and 6.11.1)

Throwing an error breaks the request lifecycle when using a cached server method.
Only the first request is returned and the server is stuck.

This only happens when multiple connections are active at the same time.

  • can be demonstrated by changing Async.times to Async.timesSeries

The expected console output is:
0: Complete
1: Complete

The actual console output is:
0: Complete

Example Code:

var Hapi = require('hapi');
var Async = require('async');

var internals = {};

var server = new Hapi.Server();
server.connection({ port: 3000 });

server.method('someCachedMethod',
    function(callback){
        return callback(null, 3);
    },
    { cache: {
        expiresIn: 20,
        staleIn: 10,
        staleTimeout: 1
    }}
);

server.ext('onPreResponse', function(request, reply){
    console.log(request.params.id + ": Response handler called");
    reply.continue();
});

server.route({
    method: 'GET',
    path: '/{id}',
    config: {
        handler: function (request, reply) {
            request.server.methods.someCachedMethod(function(err, num) {
                console.log(request.params.id + ": Triggering unhandled exception");
                throw new Error("Test Error!");
            });
        }
    }
});

server.start(function (err) {
    if (err) console.log(err);
    console.log('server running at: ' + server.info.uri);

    Async.times(2, function(n, next){
        console.log(n + ": Triggering request");

        server.inject("/" + n, function(res){
            console.log(n + ": Complete");
            return next();
        });
    }, function(err){
        console.log("Test Complete");
    });
});
@kedemd
Copy link
Author

kedemd commented Jul 28, 2015

After investigation:

  1. Hapi uses a protect method which registers a global error handler using node.js domains.
  2. When multiple methods enter the get cache method, The callbacks are registered into a _pendings array.
  3. After the cache is returned, there is a loop that invokes all the callbacks that are registered.
  4. After that point the process.domain for each callback is the same as the one that started the cache.
  5. If an error occurs in any of the subsequent requests, the wrong error handler is used in the protect method because it is registered to the wrong domain.

This means that requests that share the _pending queue will all have the wrong domain when they return.
Which makes the process.domain an unreliable storage space when using hapi.

This can easily be demonstrated using a flow like the following:

handler : function(request, reply){
process.domain.requestId = request.id;
request.server.methods.someCacheMethod(function(err, result){
  console.log("process.domain.requestId = " + process.domain.request.id + " request.id=  " + request.id);
});
}

A quick solution is to bind the correct domain context when calling the callback in the pendings array.
in: hapi/node_modules/catbox/lib/policy.js

line 47: this._pendings[pendingsId].push(callback); -> this._pendings[pendingsId].push(process.domain.bind(callback));

line 51: this._pendings[pendingsId] = [callback]; -> this._pendings[pendingsId] = [process.domain.bind(callback)];

@kedemd kedemd closed this as completed Jul 28, 2015
@kedemd kedemd reopened this Jul 28, 2015
@hueniverse hueniverse added the bug Bug or defect label Jul 28, 2015
@hueniverse hueniverse self-assigned this Aug 11, 2015
@hueniverse hueniverse added this to the 9.0.0 milestone Aug 11, 2015
@hueniverse hueniverse added the dependency Update module dependency label Aug 11, 2015
@lock lock bot locked as resolved and limited conversation to collaborators Jan 11, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Bug or defect dependency Update module dependency
Projects
None yet
Development

No branches or pull requests

2 participants