非同期処理時におけるconsole.logのちょっとしたトラップ

たまにひっかかる。

var a = {};

setTimeout(function(){
	a.hoge = "Hello world!";
},1000);

console.log("output a ->", a); // output-> { hoge:"Hello world" }
console.log("output a.hoge ->", a.hoge); // output-> undefined

var a = {};

setTimeout(function(){

a.hoge = "Hello world!";

},1000);

console.log("output a ->", a); // output-> { hoge:"Hello world" }

console.log("output a.hoge ->", a.hoge); // output-> undefined

上記コードは、変数aに対してsetTimeoutで1秒後にhogeプロパティを設定しています。setTimeoutは非同期処理であるので、その下に書かれているconsole.log(a)がhogeプロパティが設定される前に実行されます。
したがって、console.log実行時にはa.hogeプロパティは存在していないはずなのですが、JavaScriptコンソールではあたかもa.hogeプロパティが存在しているかのように出力される場合があります。しかも同じタイミングで実行したはずのconsole.log(a.hoge)では「undefined」が出力されるという矛盾した出力結果になっています。

console.log trap

画面が表示が終わり非同期処理を含むJavaScriptコードが実行された後にコンソールを起動すると、この現象が発生します。
ちなみに、初めからJavaScriptコンソール起動しておいてリロードすると下記の通り空のオブジェクトとして正しく出力されます。

console.log trap

どうも、console.log実行時にコンソールが存在しないとコンソール起動時のタイミングで出力が行われるらしいのですが、デバッグの際にこの現象に引っかかると混乱するので注意しましょう。

テスト用ページ

ちなみに、ChromeとFirefoxでこの現象が発生するのは確認、IEはそもそもページが表示されてから開発者ツールを起動した場合コンソールへの出力を行わないので発生しないです。

投稿者: shimizu