0

The strangest thing just happened to me. I have some javascript that appears to be being executed in the wrong order. This is freaking me out! Observe:

the code

    handleKeyDown: function (e) {
        console.log("handleKeyDown");
        var key = e.which;
        var text = this.ui.$input.val();

        if (_.isFunction(this[key])) {
            // call the appropriate handler method
            this[key](text, e);
           
            console.log("before announceEdits");
            this.announceEdits();
        }

        if (key === ENTER || key === ESC) {
            console.log("fired field:key:down");
            this.trigger("field:key:down", { editable: this, restore: (key === ESC) });
        }
    },

    announceEdits: function () {
        console.log("announceEdits");
        var edits = this.getEdits();

        console.log("edits: %o", edits.data);
        console.log("fired field:edits");
        this.trigger("field:edits", edits);
    },

    /* gather all the existing taggies */
    getEdits: function () {
        var data = this.$taggies().map(function (index, taggy) {
            return $(taggy).data("value");
        }).toArray();

        var edits = {
            attribute: "tags",
            data: data
        };

        return edits;
    },

When I run this code, the functions appear to be being executed out of order. This is the output in firefox's console of the above code:

the output

Firefox console output

Notice that we get before announceEdits long before we get announceEdits, which is the first line in the annouceEdits function... my understanding of the world leads me to believe this is wrong.

what I've done

Now, I have considered the following:

  1. The console statements could be being buffered or some such, causing them to appear out of order.
  2. This could have something to do with the way MarionetteJS handles events.

Believing that this might be evented weirdness, I tried removing the calls to trigger (just by commenting out the lines that trigger the events). After removing the triggers, the log statements still appear out of order. So it doesn't seem to be cause by MarionetteJS's implementation of events (which is to say, BackboneJS's implementation of events ^o^//).

I'm also lead to believe that this isn't a log statement buffer issue, because the events are themselves handled out of order (i.e. the data I expect to have after the handling of the first event is not in order by the time the second event is handled). This causes the code to "not work" in the way I would like (however, see below).

In my explorations, I've tried to narrow things down a bit. I modified the code thusly, in order to simplify the code:

    if (_.isFunction(this[key])) {
        // call the appropriate handler method
        this[key](text, e);

        console.log("before announceEdits");
        console.log("announceEdits");
        var edits = this.getEdits();

        console.log("edits: %o", edits.data);
        console.log("fired field:edits");
        this.trigger("field:edits", edits);
    }

This way I am not descending into a subroutine. Running this code, the console statements appear in the right order. What's more interesting is that, in this case, the events are also fired and handled in the order I expect! This code works, but the one with the subroutine doesn't.

I tried to create a fiddle of this code, but jsfiddle doesn't appear to like Backbone (I tried including the library as an external library, but that didn't seem to work). I did create this fiddle, just to reassure myself that somewhere in the world there is still a rock of normality.

update: I changed the fiddle so that the main function is itself a handler. Everything still works fine in the fiddle.

how I thought the world worked

Functions create stack-frames that execute to completion. If a function calls another function, a new stack-frame is pushed to the stack. If a function triggers an event, it creates a message, which is pushed onto a message queue. Whenever (and I'm unclear on this) the stack is empty, the next message in the queue is popped off, and all handlers for this message are then invoked.

In this model, without question, the events should happen in the order that I expect (the order from the second listing). We should first descend into announceEdits, push the field:edits message to the queue, and then pop back out and push the field:key:down message. Then the handlers for field:edits should run, and finally those for field:key:down.

the question

Is there anything that could be causing these functions to be being executed out of order? Or more likely: is there anything that could be causing these functions to appear to be being executed out of order?

If this is a problem with my understanding: where did I go wrong?

If this ends up being something that was caused by a typo, please bear in mind that we are all programmers, and that we have all torn out hair and bellowed at shadows at times.

Community
  • 1
  • 1
Ziggy
  • 21,845
  • 28
  • 75
  • 104
  • `handleKeyDown`? I suspect that's where the problem is; you're adding an event. Try adding a `setTimeout` with just 1ms around `this.announceEdits()` – elclanrs Jan 16 '14 at 18:10
  • There's a good explanation here http://stackoverflow.com/questions/12051769/why-are-some-javascript-developers-using-settimeout-for-one-millisecond. Ironically, the worst answer is mine, and got accepted, but the second answer has some good insight. – elclanrs Jan 16 '14 at 18:14
  • Ah! I _am_ handling an event! Oh man guys! I was looking all around where I was standing, searching for the answer that was directly under my feet! OK tell me more! – Ziggy Jan 16 '14 at 18:15
  • @elclanrs, are functions called within a handler not put on the stack? – Ziggy Jan 16 '14 at 18:18
  • @elclanrs I updated the fiddle so that the outermost function is itself a handler... but the code still runs as expected. Check out the fiddle. – Ziggy Jan 16 '14 at 18:23
  • 1
    Hard to say what's going on, really. It might be the `trigger` or the `keyDown` event, or some async code... Not sure, but I will try tracing the callstack; put some breakpoints and see what the order of execution really is, and try putting 1ms timeout as you're debugging to see if you get the right order. Once you found the culprit it would be easier to solve the issue. – elclanrs Jan 16 '14 at 18:30
  • 1
    You probably didn't include Underscore with your fiddle, you need Underscore then Backbone: http://jsfiddle.net/ambiguous/RRXnK/ – mu is too short Jan 17 '14 at 00:16
  • So helpful! I hadn't included Underscore. – Ziggy Jan 17 '14 at 08:35

1 Answers1

0

lesson

Sleep on it. In the heat of the moment, every bug is a mysterious force from another world. Step back from the problem, start from the beginning. Everything will become clear.

I came in this morning, put a debugger at the beginning of handleKeyDown and immediately saw what was wrong. It isn't in the code I gave above, naturally, and it isn't a problem with how javascript works (clearly!). I had wrapped announceEdits in a debounce earlier, to relieve a head-ache I had been having.

Good news is, my understanding of how event handling works does not appear to be in question.

Ziggy
  • 21,845
  • 28
  • 75
  • 104