2014/08/19

ConnectED 2015 のレジストレーション開始

今年ももうこんな時期に差し掛かってきたんですね。
ConnectED 2015 のレジストレーションがオープンしました。

来年のConnectはテクニカルセッションを中心に、1月25日から28日に開催されます。
フルカンファレンスの料金が、早期割引が10月3日までで $1,595 (約16万円)、以降 $1,795(約18万円)とアナウンスされています。

お申し込みはこちら
http://www-01.ibm.com/software/collaboration/events/connected/registrationoverview.html

2014/08/04

XPages Toolbox を使ってみる - ランタイムモニタリング編

XPages Toolbox の左から4番目のタブでは「ランタイムモニタリング」で
  • JVM で使用されるメモリ(空きと最大)
  • アクティブなモジュール(このモジュールはNSF)の数
  • セッションの数
を計測することができます。

「Take Snapshot Now!」ボタンをクリックすると、その時点の計測値が文書として保存されていきます。

「Remove All Documents」ボタンでこれまでの計測した結果の文書が削除されます。


2014/07/30

XPages Toolbox を使ってみる - バックエンドプロファイラー編

今回は、左から3つ目のタブにある「Backend Profiler」(バックエンドプロファイラー)についての説明になります。
操作方法は簡単です。
これからプロファイリングを始めたいときに、「Start Profiler」ボタンをクリックします。
その後、プロファイリング対象のアプリケーションを実際操作し、プロファイリング完了と思った時点で「Stop Profiler」のボタンを押します。すると、その下のビューに結果が表示されます。
また、プロファイリングが終了して結果の情報が不要になった場合に、「Remove All Documents」をクリックし、「Refresh」ボタンをクリックするとこれまでのプロファイリング結果をすべてクリアし、次のプロファイリングに備えます。

表示される結果ですが、このバックエンドプロファイラーで何がわかるかというと、XPage を操作している間に使われたバックエンドNotesクラスの
  • クラス
  • メソッド
  • 操作(Getなど)
  • コール数
  • 時間(ミリ秒)
が分かるようになっています。
上記の例では、文書(Document)のComputeWithFormメソッドで「781」ミリ秒使用したという結果が出ています。
実は今回プロファイリングしたこのXPage、ページを表示する前に、計算結果フィールドだけで約380程度のフィールドをフォームのフィールドにバインディングして「フォーム検証の実行」を指定し、初期値としてノーツのフォーム上のフィールドの省略値をそのまま計算して求めるという設定にしています。

計算結果フィールドの省略値として、ユーザー名を取得して、漢字アドレス帳から日本語名、所属部署名などをルックアップするなどページを表示する前にフィールドに値をセットする必要があるのですが、380フィールドで1秒もかからないのがわかったので(実際の経過時間は「2125」ミリ秒、約2秒)、まずは正常なパフォーマンスが得られるのではないかと推測します。

ひとつの XPage をプロファイルする際でも、部分更新(パーシャルリフレッシュ)が発生するとひとつの文書に出力するようです。

このように、Notesバックエンドクラスに対して、パフォーマンスに影響がでそうな処理(例えば、ビューを参照してループするなど)に対して、それぞれのメソッドに対して何度コールしどれぐらいの時間を消費したかを把握するのに便利なツールといえます。



2014/07/24

XPages Toolbox を使ってみる - コードプロファイリング編

今回は、みなさんが書いたサーバーサイド JavaScript のプロファイリングです。プロファリング手順に関しては、前回までの方法とまったく同じです。

自分の書いたサーバーサイド JavaScript に次の関数を追加することで、プロファイリング可能です。


今回、下のコードに対して(凄く簡単なスクリプトで申し訳ありません)プロファイリングしたい場合、
var d = getComponent("dialog1");
viewScope.put("SagyoTantoSelected","first");
d.show();

__profile() 関数を下のように追加します。
見にくいかもしれませんが、profile の前の「__」はアンダースコアを2つ続けます。
__profile("mycode","p1"){
var d = getComponent("dialog1");
viewScope.put("SagyoTantoSelected","first");
d.show();
}
ここで指定した「mycode」や「p1」は任意です。判別しやすい名前をつければ OK です。
 結果は上の画面のように出てきます。
Dojoダイアログをモーダル表示する処理で 16 ミリ秒使用したことがわかります。

この __profile() 関数の中に、別の __profile() として階層的に指定することも可能です。
バッチ処理的な SSJS で処理時間が気になるときには、このプロファイル関数を使用するとパフォーマンス改善の糸口が見えてくるかもしれませんね。

今回はこれで終了ですが、 次回はバックエンドプロファイラーを取り上げます。

2014/07/18

XPages Toolbox を使ってみる - CPU プロファイリング編

前回から始まった XPages Toolbox シリーズの第2弾は、CPU のプロファイリングです。

XPagesToolbox.nsf をブラウザで表示したところで前回は終わりました。
このアプリケーションには「Home」以外に、
  • CPU Profiler
  • Backend Profiler
  • Runtime Monitoring
  • Session Dumps
  • Periodic Snapshots
  • Threads
  • Logging
の7つのタブがあります。早速 CPU のプロファイリングのタブを開いてみましょう。

 

CPU タイムの計測

まずここで計測できるのは、CPU タイムになります。
一般的に CPU タイムは、CPU の負荷と言い換えれば分かりやすいかもしれません。処理演算によって使用される時間を計測して、どの処理が重いのかを計測するものです。ここで少し言葉の定義ですが、
  • CPU タイム (CPU Time) は、スレッドが実行時に実際に消費した時間
  • Wall タイム (Wall Time) は、スレッドにより消費された時間で、CPU タイムに加え、スリープや待ち時間を加えた時間
 をいいます。
また、プロファイリングした結果のことをスナップショット(Snapshot)という言い方をしています。


上の画面にはいくつかボタンがありますのでその説明から。

 

ボタンの説明

  • Start CPU Time Profiler:CPU Time のプロファイリング実行開始します
  • Start Wall Time Profiler:Wall Time のプロファイリング実行開始します
  • Stop Profiler:プロファイリングを終了し、プロファイリングの結果文書を作成します。(プロファイリングを開始していない場合は、グレイアウトしてクリックできません)
  • Reset Profiler:プロファイリングで収集したデータはメモリー上に残っていますが、このボタンを押してメモリー上のデータを消去します
  • Save Snapshot:プロファイリング継続中でも、今時点のスナップショットを作成します
  • Delete Snapshots:プロファイリングの結果の文書をすべて削除します

 

プロファイリング操作

プロファイリングの操作は、以下のとおりで簡単です。
1. 「Start CPU Time Profiler」ボタンか「Start Wall Time Profiler」のいづれかをクリックして開始します。
ステータスは 「Started」に変われば、開始しています。

2. 次に実際のアプリケーションを動かします。動かす対象によって、1ページだけとか1ファンクションだけとか、一連の処理だとかによって、自分のプロファイリングしたい場所の開始から終了を動かしてみます。

3. アプリケーションの操作が終了したら、XPagesToolbox.nsf に戻ってきて、「Stop Profiler」ボタンを押し、プロファイリングを終了します。


スナップショットの見方

計測の開始から終了までは大した事はありませんが、プロファイリングの結果をどうみるかが大変です。できるだけ、分かりやすく説明したいと思いますが、見るものが違えば当然結果も違ってきますから、ここでは Mastering XPages 2nd Edition で提供されているサンプルデータベースを使って説明します。
「Chp20Ed2.nsf」をブラウザから開くと、次のページが開きます。
赤い四角で囲ったリンクをクリックします。すると下のページが表示されるので、一番上の「Run CPU Intensive Task (clocking 'CPU Time')」ボタンを押します。
 その後、処理がバックエンドで始まりますが、しばらく経過すると終了します。このボタンを押す前と押して処理が完了するまでをプロファイリングした結果は、私の環境では次のようになります。

 スナップショット文書は、プロファイリング単位に日付時刻でカテゴライズされています。
さらに、「XPages Request」で呼び出した XPage (例では /Chp20Ed2.nsf/testCPUvsWallTime.xsp) ごとにカテゴライズされています。
時間はミリ秒でカウントされます。上の例では、「INVOKE_APPLICATION 5」のJSFフェーズで9秒かかかっていることがわかります。

私の手元にあるサンプルアプリケーション以外の実際のアプリケーション(新規XPage作成、単一のDomino文書にバインド、フィールド数約300)を開いた直後のものでは、次のような結果が出ました。


 特に目立った数値はありませんが、実際のアプリケーションでは「XSP:Create view root」を最初に注目したほうが良いかもしれません。Create view root は XPage(ページ)に各コンポーネントを階層的にぶら下げてビュー(ページ)を作成するのですが、約300程度の入力コンポーネントや計算結果フィールドといった様々なコンポーネントをツリー構造としてページを構成するのに、31ミリ秒かかかったということになります。

もうひとつ、実際のアプリケーションで時間がかかると想定されるのは、「RENDER_RESPONSE 6」のフェーズです。これはフィールド数が多くなればなるほど値が大きくなるのが予想されます。
いずれにしても、ひとつのXPaegs リクエスト(ページからページまでの表示の間)に何秒という基準(たとえば3秒)を決めておいて合計の時間が超えているかを確認しながら、超えている場合には、詳細にドリルダウンしていくのが実際的ではないかと思います。

※失敗談より
プロファイリングを行い、プロファイリングを停止してスナップショットが作成されますが、次のプロファイリングを行なう前に必ず「Reset Profiler」をしてください。メモリー上に前回のデータが残っていますので、これをせずに続けてプロファイリングを行なうとスナップショットの数値が2倍、3倍となっていきますので注意してください。

その他のビュー

スナップショットの結果から特にCPU時間を取っているものだけを見る事ができるビューも用意されています。
「Hierarchical Dominators」というビューで、顕著なCPUタイムの消費を確認できます。これは、アプリケーションをずーっと動かしぱなしのプロファイリングをしたときに特に有効ではないかと思います。
その他、呼び出したカウント数、合計時間、時間がかかった順、時間÷カウント数で計算した平均時間別などのビューがあります。
一度確認してみてください。

次回は、自分の書いた SSJS コードに対しての CPUタイムを計測する方法を紹介したいと考えています。お楽しみに。