How does console.log work?

Question

First Example:

In the following example: http://jsfiddle.net/maniator/ScTAW/4/
I have this js:

var storage = (function () {
    var store = [];
    return {
        "add": function (item) {
            store.push(item);
        },
        "get": function () {
            return store;
        }
    };
}());

storage.add('hi there')
console.log(storage, storage.get(), storage.add('hi there #2'));

And here is what gets printed to the console:

Object ["hi there", "hi there #2"] undefined

One would think that the console should only say:

Object ["hi there"] undefined

becase the second push did not happen until after the value was logged, therefore it should not be displayed.

---

Second Example:

In the following example: http://jsfiddle.net/maniator/ScTAW/5/

I am using the same storage variable but I log like so:

storage.add('hi there')
console.log(storage, storage.get(), (function() {
    storage.add('hi there #2');
    console.log('TESTING');
})());

What gets printed to the console is:

TESTING
Object ["hi there", "hi there #2"] undefined

hmmmm well that is odd now isnt it? One could expect to see:

Object ["hi there"] undefined
TESTING

Why is this happening? What is going on behind the scenes of the console logging mechanism?

Answer 1

In most (if not all) imperative programming languages, any arguments passed to a function call have to be evaluated before the function can be called (so called Eager evaluation). Also, they are in general evaluated in order from left to right (for C for instance it's undefined), however in both examples the order in which the arguments are evaluated does not matter. This should be pretty obvious when looking at what happens in detail:

As mentioned, before console.log can be called, storage.get() has to be executed first, returning the store array. Then storage.add('hi there #2') will be executed (or the other way round), so its result (in this case undefined, since add does not return anything) can be passed as the third argument to console.log. This means that the once console.log will be called with the arguments (storage, storage.store, undefined), the store array already contains "hi there #2", hence producing the results you observe.

In the second example the reasoning is again the same, the function call is just a bit more obscured. On first look it looks there is a function passed as a 3rd argument to the console.log function; but it's actually a function call (observer the () at the end). So storage.add('hi there #2') will be executed, then console.log('TESTING') and then the undefined result from the anonymous function execution will be again passed to console.log.

If you did actually pass a function to console.log, it would print that function definition, and not execute anything. So:

storage.add('hi there')
console.log(storage, storage.get(), (function() {
    storage.add('hi there #2');
    console.log('TESTING');
}));

, without the () at the end, results in:

Object
 ["hi there"] function () {
    storage.add('hi there #2');
    console.log('TESTING');
}

I hope this makes things a bit clearer.

Answer 2

When you're calling console.log like this

console.log(storage, storage.get(), storage.add('hi there #2'));

storage.add('hi there #2') is evaluated and the return value is passed to console.log. Evaluating it causes the array item to be added to store immediately.

Same thing with storage.get() -> store. So effectively, the statement becomes:

console.log(storage, store, [return value of add which is undefined]);

When it prints, store is evaluated and its content are output which is why you see ["hi there", "hi there #2"]

---

In your second example also, the anonymous function is evaluated first and the results are passed on.

Answer 3

All arguments to console.log will first be iterated and evaluated in order to assemble the output. As it is iterating the arguments you've passed, changes are made to objects and functions are called. After the logger has iterated the arguments, it outputs the data.

Because objects are byRef, your "second argument" changes to the storage.store object are reflected in the console output. Because the arguments are iterated, the function call in your last argument is called before the output is assembled, so you see the output from your function call before you see the output of the first console.log call.

It is worth noting, then, that the output of console.log is not going to show you objects as they exist at the time of the call to console.log. What you actually get, in the case of objects, is a reference handle to the object. Thus, any changes to the object made after the handle has been added to console.log's output will still be reflected in the object itself. Since the handle only points to the object itself, you are not getting output showing the state of the object as it was when you called the function, but rather a live link to the object as it is now.