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?

Solution 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.

Solution 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.

Solution 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.

Solution 4

Your storage adding function is completely evaluated before console.log is called because it's a parameter.

This is not specific to console.log, this is how every imperative programming language works.

View more solutions

Comments

[Blindy]

It's the same, your inner function gets evaluated first.

[Naftali]

When params are passed it is usually not by reference, unless you tell it to. therefore the 2nd param should remain the same.

[Mrchief]

@Blindy: Thanks. I was about to add that to my answer.

[Naftali]

See my comment to @Blindy's answer.

[Chris Baker]

All objects are byRef in js. Primitives are byVal.

[Blindy]

What's your point? The function still gets evaluated and the return value still gets passed down to console.log. There is literally nothing magic happening here, it's the same as console.log(gettime()) if you had a function that returned the current time as a string.

[Mrchief]

@Neal: and blindy's comment says it all. You're not passing a reference. You're passing the result of an evaluation.

[Naftali]

@Blindy -- yes, but would u expenct for your function to be volatile like: console.log(gettime(), setTime('+1 days')) and it would display the next day as the log, even though you wanted to see the current day???

[Blindy]

Yes, I would. What you want doesn't matter, only your ability to express yourself clearly does.

[Blindy]

@Neal, then I suggest either reading a book on the internals of how functions get called (for example, books on Assembler or compiler design explain this), or simply taking our word for it.

[Naftali]

@Blindy complilers??? javascript dont need no stinking compilers (lol), but seriously, js is a script, it goes from top to bottom, there is no reason why something in the right should affect something before it.

[Blindy]

Noted; you're wrong. If you don't care about why, then don't ask why.

[Chris Baker]

Agree with @Blindy, every answer here explains the concept in a slightly different way. You've been answered, but you seem to reject the facts for some reason.

[Janick Bernet]

@Blindly: I downvoted you because it is not how every programming language works. For instance Haskell does not: en.wikipedia.org/wiki/Lazy_evaluation. I think if you wrote "how every imperative programming language works" it would be fine, but I would not even be 100% sure on that - there might be some obscure one out there that does not.