Latest build and issues with promise joining

[jefflage]

we've recently upgraded in the latest build of when and we've started to some sporadic errors from when that were not getting before. here is a part of a stack:

TypeError: object is not a function
   at Promise._beget (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:163:16)
   at Promise.then (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:137:17)
   at Promise.catch (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:153:16)
   at Promise.catch.Promise.otherwise (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/decorators/flow.js:36:22)

its not happening all of the time and it's happening in different places in our code. it was not happening before we upgraded.

[briancavalier]

Hey @jefflage, this is very strange. If there were a real error on line 163 then it's likely that nothing in when.js would work at all. Unit tests are all passing locally and on travis, so my intuition is that this particular stack trace may be obscuring some other kind of problem.

Can you let me know what version of when you were upgrading from and what version you upgraded to? That may shed some light. Another thing to try is to enable when/monitor/console and reproduce the problem. You should get a more extensive stack trace that way, and maybe that will shed even more light.

Also, 3.4.2 fixed a problem that could have caused certain unhandled promise errors to be silent in previous versions. In 3.4.2, those will be loud, so I wonder if it's possible if this error has been there, but was not being reported in previous version--hopefully with more information we can figure it out.

BTW, what is "bootstrap" in this case? I'm assuming it's not twitter bootstrap ... is it one of your own packages?

[tsouza]

I'm also getting this error. I thought that this was our fault. But today I've seen this happening in a completely different application.

[briancavalier]

@tsouza and @jefflage Can you guys provide more information? I don't think I have enough to go on to begin debugging this, as I'm not able to reproduce it.

1. What version(s) of when.js are you using when the error occurs?
   1a. @jefflage if you also know what version you upgraded from, that could be helpful (so I can diff them)
2. Can you provide more context about the error: at least the complete stack trace, and maybe the console output around it as well. It'd be ideal if you could use when/monitor/console when generating the stack trace, since it will likely give a much better trace.
3. Are you able to share the bit of actual application code that seems to trigger the error? I realize that code may be proprietary, so I understand if you can't.
   • Specifically, @jefflage you titled this issue "...issues with promise joining". Does that mean you suspect when.join() might be causing the error, or at least involved somehow?

Any help you guys can provide will help me start to look into this, but right now I feel like I don't have enough info. Thanks!

[tsouza]

What version(s) of when.js are you using when the error occurs?

• I suppose the system was using 3.3.1, but I'm not 100% sure.

Can you provide more context about the error: at least the complete stack trace

• Unfortunately, not now. But I'll keep an eye on the logs and see if I can get one.

Are you able to share the bit of actual application code that seems to trigger the error?

• Sharing code is difficult. But I've got 2 usage that triggers the error. One is a promise created with "when.promise" the other one is using "when.join". With both situation the error was triggered by chaining with "otherwise/catch".

[briancavalier]

@tsouza Thanks for the info.

I suppose the system was using 3.3.1, but I'm not 100% sure

Is your error identical to @jefflage's? ie the stack trace ends with the same line number (163) in the same file (when/lib/makePromise.js) and same function (Promise._beget)?

Sharing code is difficult. But I've got 2 usage that triggers the error.

I understand about sharing code. If you could put together a small example that reproduces the problem, that'd be extremely valuable, too!

[tsouza]

Hi Brian,

I can confirm that is on the same line.

I could share code, but I don't think it would be relevant. The bug is not
triggered 100% of the time. And there is nothing special, just basic usage
of when.promise and when.join. To make the code snippet useful I would have
to share a larger part of the code.

Cheers

On Tue, Jul 29, 2014 at 4:48 PM, Brian Cavalier notifications@github.com
wrote:

@tsouza https://github.com/tsouza Thanks for the info.

I suppose the system was using 3.3.1, but I'm not 100% sure

Is your error identical to @jefflage https://github.com/jefflage's? ie
the stack trace ends with the same line number (163) in the same file
(when/lib/makePromise.js) and same function (Promise._beget)?

Sharing code is difficult. But I've got 2 usage that triggers the error.

I understand about sharing code. If you could put together a small example
that reproduces the problem, that'd be extremely valuable, too!

—
Reply to this email directly or view it on GitHub
#345 (comment).

[tsouza]

Brian, I'll try to find a code snippet that reproduces the bug 100% of the
time.

On Tue, Jul 29, 2014 at 4:48 PM, Brian Cavalier notifications@github.com
wrote:

@tsouza https://github.com/tsouza Thanks for the info.

I suppose the system was using 3.3.1, but I'm not 100% sure

Is your error identical to @jefflage https://github.com/jefflage's? ie
the stack trace ends with the same line number (163) in the same file
(when/lib/makePromise.js) and same function (Promise._beget)?

Sharing code is difficult. But I've got 2 usage that triggers the error.

I understand about sharing code. If you could put together a small example
that reproduces the problem, that'd be extremely valuable, too!

—
Reply to this email directly or view it on GitHub
#345 (comment).

[jefflage]

@briancavalier

1. from 3.2.3 to 3.4.2
2. here is the full stack:

TypeError: object is not a function
   at Promise._beget (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:163:16)
   at Promise.then (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:137:17)
   at Promise.catch (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:153:16)
   at Promise.catch.Promise.otherwise (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/decorators/flow.js:36:22)
   at Object.convert_from_ad_to_application_entitlements [as entitle] (/usr/hs/release/amber/amber/node_modules/entitlements/lib/parser.js:33:12)
   at parse_entitlements (/usr/hs/release/amber/amber/node_modules/entitlements/lib/express/middleware.js:24:26)
   at Layer.handle [as handle_request] (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/express/lib/router/layer.js:76:5)
   at next (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/express/lib/router/route.js:100:13)
   at Route.dispatch (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/express/lib/router/route.js:81:3)
   at Layer.handle [as handle_request] (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/express/lib/router/layer.js:76:5)

1. here is the calling code:

function convert_from_ad_to_application_entitlements (user, create_defaults, next) {

        if (entitlements_have_been_parsed(user))
            return next();

        add_special_demo_entitlements(user);

        var ad_entitlements = user.entitlements;
        user.entitlements = [];

        application_config.load_all().then(function(all_application_configs){

            _.keys(ad_entitlements).forEach(function (application_code) {
                convert_entitlement_for_application(application_code, all_application_configs, user, ad_entitlements);
            });

            build_simple_entitlements_hashes(user);
            prune_environments_list(user);
            user.has_multiple_clients =  Object.keys(user.simple_entitlements.by_client).length > 1;  //user.environments.length > 1;

            next();

        }).otherwise(next);


        function entitlements_have_been_parsed (user) {
            return Array.isArray(user.entitlements);
        }

        function convert_entitlement_for_application (application_code, all_application_configs, user, ad_entitlements) {

            var application_config = _.findWhere(all_application_configs,{code:application_code});

            if (application_config)
                user.entitlements.push(create_application_entitlement_from_application_config(application_config));
            else if (create_defaults)
                user.entitlements.push(create_assumed_citrix_app(application_code, ad_entitlements[application_code]));


            function create_application_entitlement_from_application_config (config) {

                var entitlement = config;

                create_environment_entitlements_for_application();

                return entitlement;

                function create_environment_entitlements_for_application () {

                    entitlement.environments = [];

                    for (var i = 0; i < ad_entitlements[application_code].length; i++) {
                        var env = ad_entitlements[application_code][i];
                        if (env.indexOf('PRODBETA') != -1)
                            log.warning('dropping ' + env + ' for ' + application_code + ' from ' + user.username);
                        else
                            entitlement.environments.push({name: env});
                    }

                    entitlement.environments = _.sortBy(
                        entitlement.environments,
                        function (x) {
                            return x.name.toLowerCase();
                        }
                    );

                }

            }

        }

        function create_assumed_citrix_app (code, envs) {

            var info = {};

            info.name = code;
            info.citrix = true;
            info.flash = false;
            info.code = code;
            info.multi_instance = (envs && envs.length > 0);

            if (info.multi_instance) {
                info.environments = [];

                for (var i = 0; i < envs.length; i++)
                    info.environments.push({name: envs[i]});
            }

            return info;

        }

    }

note this function is called by an express route handler. i suppose it is possible that there is an error in express that is occasionally resulting in next not being a function.

as far as when/monitor/console, ill try to get that conditionally enabled in UAT today

[tsouza]

Brian, just a note. I do not use express in any application that triggers
the error.

On Tue, Jul 29, 2014 at 4:57 PM, Jeff Lage notifications@github.com wrote:

@briancavalier https://github.com/briancavalier

1. from 3.2.3 to 3.4.2
2. here is the full stack:

TypeError: object is not a function
at Promise._beget (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:163:16)
at Promise.then (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:137:17)
at Promise.catch (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/makePromise.js:153:16)
at Promise.catch.Promise.otherwise (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/when/lib/decorators/flow.js:36:22)
at Object.convert_from_ad_to_application_entitlements as entitle
at parse_entitlements (/usr/hs/release/amber/amber/node_modules/entitlements/lib/express/middleware.js:24:26)
at Layer.handle as handle_request
at next (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/express/lib/router/route.js:100:13)
at Route.dispatch (/usr/hs/release/amber/amber/node_modules/bootstrap/node_modules/express/lib/router/route.js:81:3)
at Layer.handle as handle_request

1. here is the calling code:

function convert_from_ad_to_application_entitlements (user, create_defaults, next) {

    if (entitlements_have_been_parsed(user))
        return next();

    add_special_demo_entitlements(user);

    var ad_entitlements = user.entitlements;
    user.entitlements = [];

    application_config.load_all().then(function(all_application_configs){

        _.keys(ad_entitlements).forEach(function (application_code) {
            convert_entitlement_for_application(application_code, all_application_configs, user, ad_entitlements);
        });

        build_simple_entitlements_hashes(user);
        prune_environments_list(user);
        user.has_multiple_clients =  Object.keys(user.simple_entitlements.by_client).length > 1;  //user.environments.length > 1;

        next();

    }).otherwise(next);


    function entitlements_have_been_parsed (user) {
        return Array.isArray(user.entitlements);
    }

    function convert_entitlement_for_application (application_code, all_application_configs, user, ad_entitlements) {

        var application_config = _.findWhere(all_application_configs,{code:application_code});

        if (application_config)
            user.entitlements.push(create_application_entitlement_from_application_config(application_config));
        else if (create_defaults)
            user.entitlements.push(create_assumed_citrix_app(application_code, ad_entitlements[application_code]));


        function create_application_entitlement_from_application_config (config) {

            var entitlement = config;

            create_environment_entitlements_for_application();

            return entitlement;

            function create_environment_entitlements_for_application () {

                entitlement.environments = [];

                for (var i = 0; i < ad_entitlements[application_code].length; i++) {
                    var env = ad_entitlements[application_code][i];
                    if (env.indexOf('PRODBETA') != -1)
                        log.warning('dropping ' + env + ' for ' + application_code + ' from ' + user.username);
                    else
                        entitlement.environments.push({name: env});
                }

                entitlement.environments = _.sortBy(
                    entitlement.environments,
                    function (x) {
                        return x.name.toLowerCase();
                    }
                );

            }

        }

    }

    function create_assumed_citrix_app (code, envs) {

        var info = {};

        info.name = code;
        info.citrix = true;
        info.flash = false;
        info.code = code;
        info.multi_instance = (envs && envs.length > 0);

        if (info.multi_instance) {
            info.environments = [];

            for (var i = 0; i < envs.length; i++)
                info.environments.push({name: envs[i]});
        }

        return info;

    }

}

note this function is called by an express route handler. i suppose it is
possible that there is an error in express that is occasionally resulting
in next not being a function.

as far as when/monitor/console, ill try to get that conditionally enabled
in UAT today

—
Reply to this email directly or view it on GitHub
#345 (comment).

[briancavalier]

Definitely appreciate the additional info, guys! @jefflage I'm looking at the code now.

[briancavalier]

@jefflage quick q: can you point out line 33 in entitlements/lib/parser.js ? That's the line specifically mentioned in the stack trace just before it enters when.js code from you application code. Thanks.

UPDATE: I'll assume it's this line, since it's the only one that calls promise.otherwise, which is mentioned in the stack trace.

        }).otherwise(next);

[jefflage]

otherwise(next) is the only thing on that line
its right above the declaration function entitlements_have_been_parsed (user)

[briancavalier]

Got it, thanks. I'm trying a few tests involving when.promise, when.join and otherwise to see if I can create any sort of similar failure ... so far I haven't been able to, tho, even if I pass a non-function to otherwise (when.js ignores (at least, should ignore) non functions pass to then/catch/otherwise/finally, etc.).

[jefflage]

yeah that was a shot in the dark, but from digging into your code it seems like a red herring. it seems to think that parent.join is not a function

[briancavalier]

it seems to think that parent.join is not a function

Yeah, I'm wondering about that as well. I'll look into that angle a bit more, too. Thanks.

[jefflage]

maybe some backstory on what our code is doing:

application_config.load_all() is returning a promise, but that promise never goes any further than its usage here. express is callback based so there are places where we using promises internally but at the 'boundary' with express, those promises don't go any further.

we don't use done anywhere in our code. is that possibly causing some issues?

[briancavalier]

Thanks for the explanation.

we don't use done anywhere in our code. is that possibly causing some issues?

It shouldn't cause problems. In most other promise libs, not calling .done() means that errors will be silent. When.js makes errors loud by default, ie without the need for .done(). Using .done() additionally forces a crash (ie VM halt) in node when an error escapes the promise chain.

[jefflage]

@briancavalier i pushed a change to UAT just now to enable when/monitor/console so the next time we get the error, i'll check to see if there is any additional information

[briancavalier]

i pushed a change to UAT just now to enable when/monitor/console

Awesome, thanks!

Looking more at the code, the most obvious way I can see for parent.join not to be a function at makePromise.js:163 is for this to somehow not be what when.js expects it to be, ie it's not the promise instance. If that somehow happened, then on makePromise.js:162, this._handler would be something unexpected, thus setting parent to that unexpected thing. At that point, parent.join would also be something unexpected :)

It's hard to see how the code could even get that far, though, if this were something other than a promise instance. Definitely puzzling!

[jefflage]

@briancavalier i got the error in dev today. here is the stack trace (seems to be the same was before):

2014-07-30T15:16:40.874Z - error: TypeError: object is not a function
    at Promise._beget (/Users/jlage/dev/web/server/bootstrap/node_modules/when/lib/makePromise.js:163:16)
    at Promise.then (/Users/jlage/dev/web/server/bootstrap/node_modules/when/lib/makePromise.js:137:17)
    at Promise.catch (/Users/jlage/dev/web/server/bootstrap/node_modules/when/lib/makePromise.js:153:16)
    at Promise.catch.Promise.otherwise (/Users/jlage/dev/web/server/bootstrap/node_modules/when/lib/decorators/flow.js:36:22)
    at load_distinct_values_for_column (/Users/jlage/dev/web/server/datastream/src/express/controller.js:40:18)
    at Layer.handle [as handle_request] (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/router/layer.js:76:5)
    at next (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/router/route.js:100:13)
    at require_environment (/Users/jlage/dev/web/server/entitlements/lib/express/middleware.js:8:24)
    at Layer.handle [as handle_request] (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/router/layer.js:76:5)
    at next (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/router/route.js:100:13)

and then just a little further down in the console, i see the output from when/monitor/console:

[promises] Unhandled rejections: 1
Error: Can't set headers after they are sent.
    at ServerResponse.OutgoingMessage.setHeader (http.js:689:11)
    at ServerResponse.header (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/response.js:595:10)
    at ServerResponse.send (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/response.js:143:12)
    at ServerResponse.json (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/response.js:229:15)
    at ServerResponse.send (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/response.js:131:21)
from execution context:
    at Promisified_Redis_Connection.<anonymous> (/Users/jlage/dev/web/server/redis-replicant/src/simple/connection.js:37:17)
    at try_callback (/Users/jlage/dev/web/server/redis-replicant/node_modules/redis/index.js:592:9)
    at RedisClient.return_reply (/Users/jlage/dev/web/server/redis-replicant/node_modules/redis/index.js:685:13)
    at HiredisReplyParser.<anonymous> (/Users/jlage/dev/web/server/redis-replicant/node_modules/redis/index.js:321:14)
    at HiredisReplyParser.EventEmitter.emit (events.js:95:17)
    at HiredisReplyParser.execute (/Users/jlage/dev/web/server/redis-replicant/node_modules/redis/lib/parser/hiredis.js:43:18)
    at RedisClient.on_data (/Users/jlage/dev/web/server/redis-replicant/node_modules/redis/index.js:547:27)
from execution context:
    at pipeline (/Users/jlage/dev/web/server/bootstrap/node_modules/when/pipeline.js:40:10)
    at IndexTraverser.traverse_index (/Users/jlage/dev/web/server/redis-accessor/lib/index-traverser.js:39:12)
    at IndexTraverser.traverse_index_to_hash (/Users/jlage/dev/web/server/redis-accessor/lib/index-traverser.js:66:17)
    at Object.load_for (/Users/jlage/dev/web/server/datastream/src/refdata/index-metadata.js:6:30)
    at Object.distinct_values_for (/Users/jlage/dev/web/server/datastream/src/refdata/index-metadata.js:12:25)
    at Object.distinct_values_for (/Users/jlage/dev/web/server/datastream/src/refdata/index.js:32:35)
    at load_distinct_values_for_column (/Users/jlage/dev/web/server/datastream/src/express/controller.js:38:32)
    at Layer.handle [as handle_request] (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/router/layer.js:76:5)
    at next (/Users/jlage/dev/web/server/bootstrap/node_modules/express/lib/router/route.js:100:13)

though i have to admit, its not obvious to me that these are related, but it may be to you

[briancavalier]

Thanks @jefflage. It's not obvious to me either how the two might be related. However, the fact that the original error is not tracked by when/monitor/console does seem to indicate that something unexpected is happening inside of when.js itself. I'm still stumped on what/how, but I'll keep thinking and digging.

It would be interesting to see what happens if the second error (the one being reported by when/monitor/console) is fixed, ie does that have any effect on the first error. That'd rule in or out any relationship between the two.

[briancavalier]

@jefflage @tsouza Are either of you subclassing when.js's Promise?

[tsouza]

Hi Brian,

No
On Jul 30, 2014 5:19 PM, "Brian Cavalier" notifications@github.com wrote:

@jefflage https://github.com/jefflage @tsouza
https://github.com/tsouza Are either of you subclassing when.js's
Promise?

—
Reply to this email directly or view it on GitHub
#345 (comment).

[jefflage]

yes:

    var Promise = require('when').Promise;
    var timeoutCount = 0;
    var origTimeout = Promise.prototype.timeout;
    Promise.prototype.timeout = function(ms, e) {
        increment();
        return origTimeout.apply(this, arguments).finally(decrement);
    };

    function increment() {
        timeoutCount +=1;
        log.debug('timeout set: ' + timeoutCount);
    }
    function decrement() {
        timeoutCount -= 1;
        log.debug('timeout cleared: ' + timeoutCount);
    }

you and i discussed adding it to try to track down some odd behavior i was saying around timeouts.

[jefflage]

i guess replying via email doesn't do the markdown formatting!

[briancavalier]

@tsouza Thanks for confirming.

@jefflage Right, I remember you're directly overriding timeout to help debug. That should be fine. I'm curious about actual inheritance, for example:

var Promise = require('when').Promise;
function MyPromiseSubType(whatevs) {
    Promise.apply(this, arguments);
    // ...
}

MyPromiseSubType.prototype = Object.create(Promise.prototype);
// ...

Sounds like you're not doing that, but just wanted to make sure.

i guess replying via email doesn't do the markdown formatting!

Wow, yeah, weird.

[briancavalier]

@jefflage @tsouza on which specific platforms and versions are you seeing this error? Note: version is very important, as Node 0.8, 0.10, and 0.11 output different error messages under the same conditions! It's likely that is due to different underlying versions of v8, so may affect Chrome error message as well.

Thanks!

[jefflage]

0.10.29 in dev and 0.10.26 in prod

On Jul 30, 2014, at 5:01 PM, Brian Cavalier notifications@github.com wrote:

@jefflage @tsouza on which specific platforms and versions are you seeing this error? Note: version is very important, as Node 0.8, 0.10, and 0.11 output different error messages under the same conditions! It's likely that is due to different underlying versions of v8, so may affect Chrome error message as well.

Thanks!

—
Reply to this email directly or view it on GitHub.

[tsouza]

Same here
On Jul 30, 2014 6:02 PM, "Jeff Lage" notifications@github.com wrote:

0.10.29 in dev and 0.10.26 in prod

On Jul 30, 2014, at 5:01 PM, Brian Cavalier notifications@github.com
wrote:

@jefflage @tsouza on which specific platforms and versions are you
seeing this error? Note: version is very important, as Node 0.8, 0.10, and
0.11 output different error messages under the same conditions! It's likely
that is due to different underlying versions of v8, so may affect Chrome
error message as well.

Thanks!

—
Reply to this email directly or view it on GitHub.

—
Reply to this email directly or view it on GitHub
#345 (comment).

[jefflage]

@briancavalier,

granted i don’t have a large sample size here, but since i added when/monitor/console, i had the issue 3 times, and each time, there has been a trace from the monitor for a potentially uncaught exception. in my case, those exceptions are always around a boundary btwn promise and non-promise code.

just thought i’d share.

On Jul 30, 2014, at 3:53 PM, Brian Cavalier notifications@github.com wrote:

Thanks @jefflage. It's not obvious to me either how the two might be related. However, the fact that the original error is not tracked by when/monitor/console does seem to indicate that something unexpected is happening inside of when.js itself. I'm still stumped on what/how, but I'll keep thinking and digging.

It would be interesting to see what happens if the second error (the one being reported by when/monitor/console) is fixed, ie does that have any effect on the first error. That'd rule in or out any relationship between the two.

—
Reply to this email directly or view it on GitHub.

[briancavalier]

Woohoo! Thanks @jefflage!

That's pretty convincing to me that the ultimate cause is v8 inlining or optimization of some sort. Unfortunately, leaving the try/finally in there isn't a great solution. It's a hack, and preventing optimization on that method probably isn't good for performance [1].

I wish I could recreate this problem locally so that I didn't have to ask you guys to keep trying stuff. But I've yet to find a way. @tsouza @pbarnes Have you guys had any luck creating smaller test cases?

Our next steps could be to run a series of more focused experiments, each of which tests a specific v8 optimization, until we narrow down the cause to a particular v8 feature. For example, as @stefanpenner suggested above, we could add a large comment to increase the text size of the function, which will prevent v8 from inlining it. If the error stays away in that case, we know (100%? not sure) it's because of inlining.

I'm more than happy to keep making branches, if you're willing to give them a try, until we find the minimal solution. Please let me know if you'd be ok with that.

1: Interestingly, I did run some benchmarks and it seemed not to affect performance on node 0.10.28. I'm not convinced that try/finally wouldn't affect performance in some other environment or versions of node, though.

[jefflage]

@briancavalier quick update, still no errors.

on a side note, have you ever looked into node modules that can parse 'function bodies'. meaning you can do something like this:

function foo(bar) {
    console.log(bar);
}
console.log(bar.toString())

which will spit out the source for the function declaration. have you ever looked at libraries that can parse that output to tell you things like the names of the parameters the function is expecting? I'm only asking as i could see where you might have wanted something like that for when.

[KidkArolis]

Running into the same issue with 3.5.0. Can't reproduce reliably, but have continuously seen this sporadically happen in dev for the last few weeks.
I've just put in the try{} finally{} locally to see if that fixes the problem.

[briancavalier]

@KidkArolis We've concluded that v8 is incorrectly optimizing a function inside of when/lib/makePromise.js. It's been nigh impossible to determine the circumstances under which it happens, though. Seems like a pretty horrible bug in v8, with no obvious solution except to blindly refactor that function and hope for the best :( We may have to do that, though.

[briancavalier]

@jefflage Sorry for not responding sooner. I don't know of any libs that specifically parse function bodies, other than the usual AST parsers like esprima. Parsing just the function declaration to extract parameters names is pretty simple:

var paramsRx = /\(([^)]*)/;
var match = paramsRx.exec(foo.toString());
var paramNames = match ? match[1].split(/\s*,\s*/) : [];

We use that technique over in most.js's lift() to generate lifted functions whose name, arity, and parameter names match the original function. It's a cool technique. It's a little slow due to the dynamic compilation with new Function, but the idea is you only ever do that once at init time. Then, the lifted functions it generates are very fast.

[anodynos]

Updating from 3.5 to 3.6 started causing "TypeError: object is not a function" in urequire latest beta, in places I had not problems before, like this When.sequence. Perhaps is cause task items don't (always) return a promise ? I m trying to isolate and reproduce the problem outside, still no luck. Note the error is quite random. One run works, the next fails...

[briancavalier]

@anodynos sequence allows you to return either a promise or non-promise, so that should be ok. The code for sequence also hasn't changed in quite some time. However, when.reduce did change in 3.6.0, so it's possible that introduced a new bug outside of our test coverage. Any chance you have a test case that reproduces the problem?

[briancavalier]

@anodynos Another thing you could do is try master. It has a greatly simplified when.reduce. If that works, then that would be pretty strong evidence that 3.6.0 has a reduce bug. Thanks!

[anodynos]

I am not using reduce, only sequence and iterate.
I ll try to debug it but its rough cause its not consistently reproducible, even though I am starting the exact same urequire build from scratch (CLI). Also the build (latest uberscore) doesn't produce any errors (normally with when@3.5) that get uncaught or smthng..

[anodynos]

Good news - it seems to fail more predictably on Windows / non SSD disk. You never know...

[anodynos]

That what I got so far (when@3.6.0)

 [TypeError: object is not a function] TypeError: object is not a function
  at Promise._beget (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:166:16)
  at Promise.then (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:140:17)
  at Promise.catch (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:156:16)
  at Promise.catch.Promise.otherwise (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\decorators\flow.js:37:22)
  at e:\dev\uBerscore\node_modules\urequire\build\code\fileResources\FileResource.js:173:20
  at e:\dev\uBerscore\node_modules\urequire\build\code\promises\whenFull.js:44:14
  at next (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\decorators\iterate.js:57:20)
  at e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\decorators\array.js:35:24
  at tryCatchReject (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:830:30)
  at runContinuation1 (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:789:4)
  at Fulfilled.when (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:580:4)
  at Pending.run (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:471:13)
  at Scheduler._drain (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\Scheduler.js:62:19)
  at Scheduler.drain (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\Scheduler.js:27:9)
  at process._tickCallback (node.js:419:13)

The last call of urequire's is in FileResource.js:173:20 and is a catch call registering a function, and after that I get the error. Its a call that's been called many times before in the build without problems (its inside an When.each loop, which is really a masquaraded iterate) and it fails (sometimes) on the n-th call.

[briancavalier]

@anodynos Thanks for the all that info!

I am not using reduce, only sequence

sequence is implemented using when.reduce. So, indirectly, you are :) But it seems like that's probably not the problem, since ...

at Promise._beget (e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:166:16)

Ah, yes, that's very helpful! That line turns out to be the exact same line (although it's line number has changed in 3.6.0 due to refactoring) on which the error was reported by others in this thread.

So, it appears you are being bitten by the same v8 optimization bug :( One workaround is to insert the following as the first line of the Promise.prototype._beget method:

try {} finally {}

Yes, literally an empty try/finally. This prevents all but the most recent versions of v8 from optimizing that method, and thus it won't generate invalid optimized code. The bug is sporadic (as you've seen!) and very difficult to reproduce, so I haven't been able to duplicate it locally. However, others have had success with this workaround.

Sorry, I realize that kinda stinks. Please politely ask the v8 maintainers to fix this :)

Please give it a try and let me know if it helps. I may have to bite the bullet and somehow integrate a workaround into the codebase, which would make me sad, but might be worth it.

[KidkArolis]

This should be patched before more people run into it IMHO.. At least until
v8 is fixed. We had to fork when.js and use the fork in our projects to
avoid this issue which we've seen happen in production.

On Wed, Nov 12, 2014, 06:03 Brian Cavalier notifications@github.com wrote:

@anodynos https://github.com/anodynos Thanks for the all that info!

I am not using reduce, only sequence

sequence is implemented
https://github.com/cujojs/when/blob/master/sequence.js#L32 using
when.reduce. So, indirectly, you are :) But it seems like that's probably
not the problem, since ...

at Promise._beget
(e:\dev\uBerscore\node_modules\urequire\node_modules\when\lib\makePromise.js:166:16)

Ah, yes, that's very helpful! That line
https://github.com/cujojs/when/blob/3.6.0/lib/makePromise.js#L166 turns
out to be the exact same line (although it's line number has changed in
3.6.0 due to refactoring) on which the error was reported by others in this
thread.

So, it appears you are being bitten by the same v8 optimization bug :( One
workaround is to insert the following as the first line of the
Promise.prototype._beget method:

try {} finally {}

Yes, literally an empty try/finally. This prevents all but the most recent
versions of v8 from optimizing that method, and thus it won't generate
invalid optimized code. The bug is sporadic (as you've seen!) and very
difficult to reproduce, so I haven't been able to duplicate it locally.
However, others have had success with this workaround.

Sorry, I realize that kinda stinks. Please politely ask the v8 maintainers
to fix this :)

Please give it a try and let me know if it helps. I may have to bite the
bullet and somehow integrate a workaround into the codebase, which would
make me sad, but might be worth it.

—
Reply to this email directly or view it on GitHub
#345 (comment).

[anodynos]

Thanks for the info @briancavalier - I think I'll stick to 3.5.0 for now that seems to somehow avoid the bug. I believe like @KidkArolis that the patch should go in ;-)

Another strange thing I noticed that might help: that last catch call (just before it fails) seems to be called asynchronously, cause the first task of that sequence is executed after the call is made, just after the catch call, and when that task returns, it throws the error.

[anodynos]

FYI, this DID NOT help:

        Promise.prototype._beget = function() {
            try {} finally {};
            var parent = this._handler;
            var child = new Pending(parent.receiver, parent.join().context);
            return new this.constructor(Handler, child);
        };

Only reverting to 3.5.0 solves it. Testing on node v0.10.33 on Windows 7 x64, it fails more often than same version in Kubuntu 14 x64, if that's useful.

[briancavalier]

Hmmm, what version of node?

[anodynos]

I was just updating the above comment - Testing on node v0.10.33 on Windows 7 x64, it fails more often than same version in Kubuntu 14 x64, if that's useful.

[briancavalier]

@jefflage @KidkArolis @tsouza @stefanpenner v8 bug report filed: https://code.google.com/p/v8/issues/detail?id=3692

Please +1 it :)

[unscriptable]

Voted!

[jefflage]

ditto

On Nov 12, 2014, at 10:50 AM, John Hann notifications@github.com wrote:

Voted!

—
Reply to this email directly or view it on GitHub #345 (comment).

[briancavalier]

@jefflage @tsouza @pbarnes @KidkArolis 3.6.2 just landed with a workaround for this. Thank you all for your help in debugging this, and for your patience!

Please let me know if you encounter the failure again after updating.