JavaScriptが、エラー吐いてるんですけど

プログラムがバグったら!?!!

怒られます。めっちゃ怒られます。

そして、バグ対(策)のついでに仕変(仕様変更)をこっそり(無料で)やらされます(当然ながら、文句を言える立場ではありません)。

さて、1時間経っても原因不明の場合は、どうなるでしょう。

お前らなんぞ、ゴミだ糞だと、めちゃくちゃ言われます。もちろん、上司は客に言われたイライラを10倍にして部下に投げつけます。

このようなことを繰り返すうち、いつしか精神を病み、人生をリタイアすることになるのです。

怖いですね〜。

このような惨事を避けるのは簡単です。バグのないプログラムを作れば良いのです。<無理!(常識あるものの声)

どんな状況であれ、仕様書に記述されている内容は、全て網羅し正しく動作するプログラムです。<不可能!(デスマーチを歩んだものの声)

仕様書に記述されていない内容も、全てが顧客が使いやすいように、熟慮の結果実装されているのです。<出来っこない(真実を知るものの声)

起こりうるシステム上の問題点も、全て考慮して作れば...(パン)...乾いた破裂音が、室内に響き渡った。

バグのないプログラムなど作れるわけが無いので(努力はしますよもちろん)、次善の策を考えます。

どこ?

原因究明の第一歩は、そう「どこ?」です。

それさえわかれば、「俺が作ったとこじゃないから関係ないんで、お先に!」と言って帰れるかもしれません。

それさえわかれば、何が原因となって問題が起きたかを、判別できるかもしれません。逆に、「どこ?」が分からないと、原因の判別は...

どこ?を見つける、その前に

JavaScriptの例外についておさらい

JavaScriptでエラーが発生して(というより、エラーの状態になって)処理を続行できない場合、例外を投げて処理を終了させます。

JavaScriptで例外

通常は、これをキャッチして、「何らかの対処」をします。

JavaScriptで例外

特定の環境での解決

で「何らかの処理」とは、何が出来るのでしょう。私の環境(Firefox)では、次のようなコードで、エラーが発生した箇所を特定できます。

例外が発生した箇所を見つける

e.nameは、投げられた例外のタイプです。ECMAScriptでは、Error以外にも、以下のようないくつかの例外クラスを用意しており、そのクラス名が格納されています。

EvalError
eval()関数に関するエラーです。
RangeError
数値変数の有効範囲に関連するエラーです。
ReferenceError
不正な参照の読み出しで発生するエラーです。
SyntaxError
eval()関数内のコードの構文エラーで発生するエラーです。
TypeError
変数の型不正などで発生するエラーです
URIError
URIの処理を行う関数に、有効ではないURIを渡した時などに発生するエラーです。

※エラー内容の説明は、Mozilla Developer Networkを参考にさせて頂きました。

e.messageは、Error作成時に指定したメッセージです。

e.fileNamee.lineNumbere.columnNumberは、それぞれErrorを作成したスクリプトコードのファイルパスと行番号とカラム数です。

e.stackは、Errorを作成するまでのスタックトレースです。

これだけの情報があれば、エラーが発生した場所の特定はできるので完璧です。少なくとも私の環境であれば。

しかし、標準としてサポートされているのはnamemessageだけなので、どこで発生したErrorなのかを特定することは、標準の機能だけではできません(尤も、stackはほぼ全てのWebブラウザがサポートしていますが)。

全般的な環境での解決

これには、ほぼ完璧な解決策があります。window.onerrorイベントをハンドリングすることです。

window.onerrorイベントのハンドリング

これは、スクリプト中の全てのキャッチしていない例外を検知して通知してくれるので便利です。引数として渡されるのは、Error作成時に指定したメッセージ・エラーが発生したファイルパス・行番号・カラム数・発生したエラーオブジェクトです。

このハンドラからtrueを返すことで、Webブラウザに対してデフォルトのエラー処理(エラーが発生したというダイアログの表示や、コンソールへのエラーログの出力等)を抑止させることができます。

この処理方式は、主なWebブラウザの最近のバージョンであれば、ほぼ適用できます。先にも述べましたが、標準ではありませんが、error.stackはほぼ全てのWebブラウザがサポートしています。

行番号に関するご注意

但し、取得できる行番号については注意が必要です。

HTMLサンプル1(error1.html)

上記コードでは、殆どのWebブラウザが、エラー発生行に11が設定されます。

しかし、下記のように一旦キャッチした例外を再度スローしているケースでは、問題があります。

HTMLサンプル2(error2.html)

当然、エラー発生行には15が設定されて欲しいのですが、そうは問屋が下ろしません(死語?)。

FirefoxとGoogle chromeは15を設定してくれるのですが、Internet Explorerは11を設定します。このようなときだけは、Google chromeの高い占有率が頼もしいものです。

「殆どのWebブラウザで、大丈夫です。」と言えるのですから。

閑話休題

実は、上記の一文は、このコンテンツの以前のバージョンでは、下記のような内容でした。

IEとFirefoxをSafariは、16を設定してくれるのですが、Google chromeは12、Operaは6を設定します。このようなときだけは、IEの高い占有率が頼もしいものです。

「殆どのWebブラウザで、大丈夫です。」と言えるのですから。

サンプルコードの内容が若干異なるので、行数に関しては少し違いますが、内容が間違っていたわけではありません。

いろいろな意味で、皮肉なものです。

スタックトレースがあれば、怖いものなし

行番号に関して解説してきましたが、実のところ、スタックトレースが使えればどこでエラーになったかは、一目瞭然です。

以下は、上記の「HTMLサンプル2(error2.html)」でFirefoxが出力したダイアログに表示された内容です。

ReferenceError: errfunc3 is not defined
http://work.yscjp.com/neweb/error/error2.html:15:17
errfunc2@http://work.yscjp.com/neweb/error/error2.html:15:17
errfunc1@http://work.yscjp.com/neweb/error/error2.html:9:21
onclick@http://work.yscjp.com/neweb/error/error2.html:1:1

3行目以降がスタックトレースで、先頭行がエラーの発生箇所、それ以降は関数の呼び出し箇所です。出力フォーマットは、Webブラウザによって多少異なりますが、出ている情報はほぼ同じです。

どこ?の次は

これで、殆どのWebブラウザで、エラーが発生した箇所を見つけることが出来るようになりました。

しかし、これだけでは情報が少なすぎます。例えば、共通のチェックメソッドでエラーになったことが判ったとしても、何をチェックしたのかが判らなければ、意味がありません。

どのようにしてエラーとなるに至ったかを、知る必要があるのです。

我を呼び出したのは誰じゃ

何か問題が発生した場合、ログを出力します。このとき、共通的なログ出力関数を使いたいときが、ままあります。

しかし、window.consoleに出力した場合、全てのログの出力箇所が、共通関数のファイルパスと行数になってしまうため、実際にどこで出力したログか、わからなくなってしまいます。

また、エラーの情報をサーバに送信するために、メモリ上にログを出力する場合は、そもそもどこで出力したかの情報が存在しません。

ここで活躍するのが、先にも出てきたError.stackです。

呼び出し元を取得するサンプルコード

下記コードの肝は18行目から始まる関数です。

19行目でErrorのインスタンスを作成します。20行目から26行目は、Internet Explorer対策で、Errorをスローしないとstackが初期化されない仕様に対応しています。

27行目からのtry〜catch節は、何かの不具合で例外が発生した時に、出力すべきmessageが無くなってしまうのを防ぐためで、最悪49行目でmessageをログに出力します。

stackは改行で区切られた単なる文字列なので、28行目で改行で分割して配列に格納します。

その配列から、出力している関数名が存在する行を検索します。関数名を_____log_____などとしているのは、予期せぬ箇所に関数名と同じ文字列が出現して、正しい情報が取得できなくなることを避けるためです。

31行目で、_____log_____の出現位置から、実際にログを出力しているstackを取得します。

後は、stackのフォーマットに応じて、ファイル名と行数を取得してログに出力します。ファイル名と行数を取得する箇所は、stackのフォーマットに左右されるコードとなっているので、もう少しスマートな方法を考えたほうが良いかもしれません。

ログの出力位置を取得する

出力されるログは、以下のようになります。

(errorlog.html:9:13) [ERR] エラー出ました           errorlog.html:42:25
(errorlog.html:10:13) [DBG] デバッグしてます        errorlog.html:42:25
  

stackは重いとよく言われます。しかし、実際にJavaScriptのErrorをインスタンス化してstackを取得するという処理を10000回繰り返しても、20ミリ秒程度(Linux上のFirefox)なので、エラー発生時のログ出力程度であれば、特に問題ないかと思われます(Internet Explorerの場合は、まあ、なんというか...)。

いかなる運命によりこの地に至ったのか

スタックトレースは便利ですが、出力されるのは直近の呼び出し関係のみです。しかし、エラーの内容によっては、もっと以前の状況を知りたいということもあります。

そこで活躍するのがメソッドトレースです。

カスタムクラスにメソッドトレースを実装するサンプル

29行目で、引数で渡されたオブジェクトのメソッドを、新しいメソッドで上書きします。

新しいメソッドは、34行目で開始メッセージをログに出力し、35行目でメソッド自身を実行し、41行目で終了メッセージをログに出力します。

内部で例外を検知したときは、終了メッセージにその旨を追加します。

メソッドトレースを取得する

出力されるログは、以下のようになります。

--- Clazz1#func01 START(1000001) ---
--- Clazz1#func02 START(1000002) ---
--- Clazz1#func03 START(1000003) ---
--- Clazz1#func04 START(1000004) ---
--- Clazz1#func05 START(1000005) ---
--- Clazz1#func06 START(1000006) ---
--- Clazz1#func06 END(1000006) ---
--- Clazz1#func05 END(1000005) ---
--- Clazz1#func04 END(1000004) ---
--- Clazz1#func03 END(1000003) ---
--- Clazz1#func02 END(1000002) ---
--- Clazz1#func01 END(1000001) ---
--- Clazz1#func04 START(1000007) ---
--- Clazz1#func05 START(1000008) ---
--- Clazz1#func05 END(1000008) ---TypeError: Clazz1.func06 is not a function
--- Clazz1#func04 END(1000007) ---TypeError: Clazz1.func06 is not a function

コンストラクタを持ち、prototypeにもメソッドがあるクラスの場合は、46行目を以下のように変更します。

prototypeにもメソッドがあるクラスの場合

この例では、コンソールに出力していますが、エラーが発生した時点で何らかの方法で収集できなければならないことを考えると、配列に格納して専用のページに表示するような方式を考慮する必要があります。

また、ログの出力時にミリ秒単位の時間を出力すれば、性能面で問題が有った場合に、比較的簡単に時間がかかる箇所が判明するかもしれません(まあ、プロファイラを使うべきかもしれませんが)。

スマホって、マジめんどくさい!

コンテンツを作成・修正すると、当然スマホでもチェックするのですが、何故かスマホだけうまく表示されないことがある。

こんな時、ログを見てみたいんだど、ご存知の通りAndroid用Webブラウザには、PC版に有るような単体で使用できる開発者ツールとかは見当たりません(iPhoneとかも同じですよね)。

ググってみると、「めっちゃ簡単」とか書いてあるけど、実はUSB経由でのデバッグだったりします。

いやいや、ちょっとログが見てみたいだけなんですけど。

スマホの現状を予想したわけではありませんが、幸い当社のスクリプトには、出力したログをメモリ上で管理する機能があるので、表示エリアさえ用意すれば、簡単にログを表示できます。

もちろん、ゼロから実装するのは大変なので、こんな方法も有るよ、という参考程度です。実際にはUSB経由でのデバッグも考慮してください。

ただ、最近GPS関連のWebアプリのチェックで、フィールドに出ることがあるのですが、そんなときはその場でログが見えて、めっちゃ便利です。

通常は、デバッグログなどが出ないような設定でコンテンツを公開するのですが、当コンテンツはデバッグログ垂れ流しの状態で、公開しています(^^;

このモードでは、右上の「目次」をクリックして表示されるメニューの一番下に、コンソールログとトレースログが現れます。それらをクリクすると、画面にそれぞれのログが表示されます。

デバッグ用の機能なので、多少の不具合は目をつぶってくださいね。

ご参考までに、スクリプトへのリンクを貼っておきます。興味があればご覧ください。

jswebutilities.js

ほんの簡単な使い方など

(1)ログを出力する

下記のコードでログが出力できます。デフォルトでは、メモリ上に格納すると同時に、Webブラウザのコンソールにも出力します。

com.yscjp.jsapp.util.Log.debug('デバッグ用のメッセージ');
com.yscjp.jsapp.util.Log.info('インフォメーションメッセージ');
com.yscjp.jsapp.util.Log.warning('チョットヤバイかも');
com.yscjp.jsapp.util.Log.error('アッ、まじい');
com.yscjp.jsapp.util.Log.fetal('帰ろ帰ろ');

(2)ログを表示する

下記のコードでログを指定のIDの要素上に表示できます。

com.yscjp.jsapp.util.Log.printAppLog(id);