Error log message is not dynamic in all engines #151

Closed
kaerus opened this Issue Dec 12, 2012 · 17 comments

Projects

None yet

6 participants

@ghost
ghost commented Dec 12, 2012

Whenever I reject a promise I get a 'Should be empty' with the return value I'm rejecting.
Yet I have an errback registered that should handle the error like this.

if(callback) deferred.promise.then(function(ret){
    callback(null,ret.result,ret.headers);
  },function(err){
    callback(err.code,err.message);
  });

I've just started to exlore this framework so probably I'm doing something wrong. :)

Collaborator
domenic commented Dec 12, 2012

Which browser (version is important) or server environment?

@ghost
ghost commented Dec 12, 2012

right now, in safari 5.1.7.
in nodejs v0.8.6, I don't get this error.

Collaborator
domenic commented Dec 12, 2012

Pretty sure this shouldn't be happening :(. If you could put together a small self-contained test case that's a whole HTML file (from <!DOCTYPE> to </html>, I mean), that would be super-helpful. Then we can test it in various browsers etc. Otherwise we can try to reproduce on our own.

@ghost
ghost commented Dec 12, 2012

ok, I'll try to isolate the issue.

Collaborator
domenic commented Dec 12, 2012

Much appreciated! I know it sucks to just start using a project and then get sucked into the bug tracker. If it's any consolation, I'm pretty sure this won't impact your use of the library, and will likely just be annoying in the console.

@ghost
ghost commented Dec 12, 2012

no problems, so far it has been a pleasure to use, just this little annoyance. :)

@ghost
ghost commented Dec 12, 2012

There you have it.

var depends = [
    'q',
    'jQuery/jquery-1.8.2.min'
];

require(depends,function(Q){

    function test(call) {
        var deferred = Q.defer();

        $.ajax(call)
            .done(function(result) { deferred.resolve(result) })
            .fail(function(error) { deferred.reject(error) });

        return deferred.promise;
    }   

    test("something")
    .then(function(res) { console.log("ok:",res) },
        function(err) { console.log("err:", err) } );
});
<!DOCTYPE html>
<html lang="en">
<head>
    <meta charset="utf-8" />
    <meta http-equiv="Cache-control" content="no-cache">
    <title>Should be empty</title>
</head>

<body>
    <script data-main="js/should_be_empty" src="js/require.js"></script>
</body>
@ghost
ghost commented Dec 12, 2012

Sorry, I missed the part about a self contained version.

<!DOCTYPE html>
<head>
    <meta charset="utf-8" />
    <title>Should be empty</title>
</head>

<body>
    <h1>Should be empty</h1>
    <div></div>

    <script src="https://raw.github.com/kriskowal/q/master/q.min.js"></script>
    <script src="http://ajax.googleapis.com/ajax/libs/jquery/1.8.3/jquery.min.js"></script>
    <script>
    var e = document.getElementsByTagName("div")[0];

    function test(call) {
            var deferred = Q.defer();

            $.ajax(call)
                .done(function(result) { deferred.resolve(result) })
                .fail(function(error) { deferred.reject(error) });

            return deferred.promise;
        }   

        test("something")
        .then(function(res) { e.innerHTML = JSON.stringify(res) },
            function(err) { e.innerHTML = JSON.stringify(err) } );
    </script>
</body>

...or without jquery/ajax stuff.

<!DOCTYPE html>
<html lang="en">
<head>
    <meta charset="utf-8" />
    <meta http-equiv="Cache-control" content="no-cache">
    <title>Should be empty</title>
</head>

<body>
    <h1>Should be empty</h1>
    <div></div>

    <script src="https://raw.github.com/kriskowal/q/master/q.min.js"></script>
    <script>
    var e = document.getElementsByTagName("div")[0];

    function test(call) {
            var deferred = Q.defer();

            deferred.reject("rejected " + call);

            return deferred.promise;
        }   

        test("something")
        .then(function(res) { e.innerHTML = JSON.stringify(res) },
            function(err) { e.innerHTML = JSON.stringify(err) } );
    </script>
</body>
@ghost
ghost commented Dec 12, 2012

same with FireFox 17.x, Omniweb 5.11.1, Chrome 23.0.1271.97...
However in Chrome Canary it seems to work.

@ghost
ghost commented Dec 14, 2012

I can see that the rejection is pushed twice into the rejections array in the reject method.
Which means that reject() is being called two times where this snippet lies.

...
   displayErrors();
   rejections.push(rejection);
   errors.push(exception);
...

After a little more debugging:
First it is called by this function

  deferred.reject = function (exception) {
        become(reject(exception));
    };

Later it is called again by this function

"when": function (rejected) {
            // note that the error has been handled
            if (rejected) {
                var at = array_indexOf(rejections, this);
                if (at !== -1) {
                    errors.splice(at, 1);
                    rejections.splice(at, 1);
                }
            }
            return rejected ? rejected(exception) : reject(exception);
        }

it seems like the above function is actually being called twice.
First when rejected is undefined and later when it is set to a function.

Which in turn gets called twiced by promise.promiseDispatch function at Line 481 with the following arguments:

promiseDispatch resolve=(undefined) op=(when) args=(Array[2])

and again by

promiseDispatch resolve=(function (value) {
            if (done) {
                return;
            }
            done = true;

            deferred.resolve(_fulfilled(value));
        }) op=(when) args=(Array[1])

oh my... this gets complicated.

q.js:640reject called by: function (exception) {
        become(reject(exception));
    }
q.js:629Should be empty: [
Object
]
q.js:484promiseDispatch caller: function () {
                value.promiseDispatch.apply(value, pending);
            }
q.js:652rejected: undefined
q.js:640reject called by: function (rejected) {
            // note that the error has been handled
            if (rejected) {
                var at = array_indexOf(rejections, this);
                if (at !== -1) {
                    errors.splice(at, 1);
                    rejections.splice(at, 1);
                }
            }
            console.log("rejected:", rejected);
            return rejected ? rejected(exception) : reject(exception);
        }
q.js:484promiseDispatch caller: function () {
                value.promiseDispatch.apply(value, pending);
            }
q.js:652rejected: function (exception) {
            if (done) {
                return;
            }
            done = true;
            console.log("asdfds");
            deferred.resolve(_rejected(exception));
        }
@ghost
ghost commented Dec 14, 2012

I don't understand the dance with displayErrors.
Why have a errorDisplayed flag and why care about touch devices and so on ?

var errorsDisplayed;
function displayErrors() {
    if (
        !errorsDisplayed &&
        typeof window !== "undefined" &&
        !window.Touch &&
        window.console
    ) {
        // This promise library consumes exceptions thrown in handlers so
        // they can be handled by a subsequent promise.  The rejected
        // promises get added to this array when they are created, and
        // removed when they are handled.
        console.log("Should be empty:", errors);
    }
    errorsDisplayed = true;
}

Why not just check for the presence of console.log and displayErrors if there is an actual error?
The above is being called every time one rejects a promise which is not an error per se.

Apart from that.... I still don't understand why reject is being called twice. That smells like bug #148 to me. :)

Collaborator
domenic commented Dec 14, 2012

@kriskowal, there's been some impressive detective work here. But as @kaerus says, we're starting to get into the complicated internals of Q, and your expertise would probably help a lot here :).

pcottle commented Jan 11, 2013

Any progress on this? Sorry to revive a month-old thread, but the line

console.log("Should be empty", errors)

really just seems like a sanity check from the author. I get this almost every time I call .done() on a promise chain. Why not just check for the length of errors and then log if it's non-zero?

I'm just trying to clean up my console output :D

Owner

Thanks. With a fresh look at the example, the reason you’re getting the rejection is that Q displays the log at the first time anything is rejected.

@domenic and I were just thinking of an alternative view of nextTick that might be useful. We could postpone displaying the log until the next tick queue empties, which would make the pernicious appearance of the log happen less frequently at least.

As always, the real solution to this problem is to make extensions for all browsers and environments that shows a live view of all pending and rejected promises. We could detect the existence of such an extension and silence the log entirely.

walski commented Jan 14, 2013

That would be appreciated! 👍

I'm getting the same error with WinJS

Owner

We are not making progress on this issue. Perhaps when evergreen engines all have a promise inspector per #361 it will be practical to remove the console.log stopgap.

@kriskowal kriskowal closed this Oct 20, 2013
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment