Notesアプリの「遅い」を見てみよう

パフォーマンス小噺
アプリの「遅い」を見てみよう
中野晴幸 (Haruyuki Nakano)
@harunakano (Twitter)
harunakano.blogspot.com (blog)

View Slide

「遅い」を実感するタイミング
 データベース（デフォルトビュー）を開く
 文書を開く
 編集モードへ切り替える
 文書を保存する

View Slide

遅い実態を調べよう
NRPCログについて

View Slide

CLIENT_CLOCK=1
Notes/Domino のクライアントとサーバーとの NRPC コマンドの履歴を記録する
クライアントの notes.ini へ次の3行を追加する
 CLIENT_CLOCK=1
 CONSOLE_LOG_ENABLED=1
 DEBUG_THREADID=1

View Slide

NRPC のログ
記録先
 最新のログは、データディレクトリの IBM_TECHNICAL_SUPPORT フォルダへ
console.log が作成され、記録される
 過去のログは console__<開始日付>@<開始時刻>.log という名前に変更
される
Client Clock を使用したコンソールログの取得手順について
https://www-01.ibm.com/support/docview.wss?uid=swg21468085

View Slide

取得したログの例
[350C:0002-0D70] (1-11 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 3 ms.)
[350C:0002-0D70] (OPEN_SESSION: 2 ms)
[350C:0002-0D70] (Opened: REP492583B3:001C106D) 3 ms. [134+290=424]
[350C:0002-0D70] (2-11 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1154=1202]
[350C:0002-0D70] (3-11 [3]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000182,0040,4008): 1 ms. [78+34=112]
[350C:0002-0D70] (4-11 [4]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 3 ms. [76+1820=1896]
[350C:0002-0D70] (5-11 [5]) GET LAST INDEX TIME(REP492583B3:001C106D): 17 ms. [14+76=90] (Database is not full text indexed)
[350C:0002-0D70] (6-12 [6]) OPEN_NOTE(REP492583B3:001C106D-NT0007AD8E,02400036): 1 ms. [48+924=972]
[350C:0002-0D70] (7-12 [7]) DB_MODIFIED_TIME(REP492583B3:001C106D): 0 ms. [14+76=90]
[350C:0002-0D70] (8-12 [8]) OPEN_COLLECTION(REP492583B3:001C106D-NT0000018A,0000,0000): 2 ms. [42+34=76]
[350C:0002-0D70] (9-12 [9]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 2577 ms. [76+1502=1578]
[350C:0002-0D70] (13-19 [13]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 3 ms. [46+22=68]
[350C:0002-0D70] (18-27 [18]) GET_SERVER_STATS: 2 ms. [38+16=54]
[350C:0002-0D70] (23-35 [23]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 1 ms. [828+88=916]
[350C:0002-0D70] (25-36 [25]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 10:08:47): 1 ms. [140+1516=1656]
[350C:0002-0D70] (26-36 [26]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000182): 14 ms. [12+0=12]
[350C:0002-0D70] (27-37 [27]) CLOSE_COLLECTION(REP492583B3:001C106D-NT0000018A): 1 ms. [12+0=12]
[350C:0002-0D70] (29-37 [29]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]

View Slide

ログの見かた
スレッドID 350C:0002-0D70
シーケンス番号 2-11 [2]
NRPCコマンド OPEN_NOTE
レプリカID 492583B3:001C106D
ノートID FFFF0010
経過時間(ms) 1
送信バイト数 48
受信バイト数 1154
送受信バイト数 1202
[スレッドID] (シーケンス番号) NRPCコマンド(REPレプリカID-NTノートID): 経過時間 ms. [送信バイト数+受信バイト数=送受信バイト数]

View Slide

NRPC コマンド
OPEN_DB DBを開く
OPEN_COLLECTION ビュー（索引）を開く
※ビュー索引が無い場合、構築するまでに長時間またされる場合があ
る
READ_ENTRIES ビュー（索引：ページ）を読み込む
※ビューをスクロールしていくと次のビューの画面（ページ）を読み
込むため READ_ENTRIES をコールする
OPEN_NOTE 文書（設計要素）を開く
※サブフォームなど設計の中に埋め込まれた設計がある場合に何度も
発生する
UPDATE_NOTE 文書を更新する
CLOSE_COLLECTION ビューを閉じる
CLOSE_DB DBを閉じる
※今回の資料で扱う主なNRPCコマンドのみ記載

View Slide

レプリカID、ノートID

View Slide

体験会へようこそ
「遅い」を体感して、NRPCログで実態を探ってみよう

View Slide

郵便番号データ
郵便番号データダウンロード
https://www.post.japanpost.jp/zipcode/download.html

View Slide

郵便番号データベース

View Slide

フォーム
（Notes クライアント）

View Slide

フォーム
(Domino Designer)
２つの「ダイアログリスト」
フィールドで @DbColumn を使用
検索用のビューからキー
ワードリストを取得

View Slide

検索用のビュー
（Notes クライアント）

View Slide

(Domino Designer)

View Slide

 ビュー(state_kana)：カタカナの都道府県名リスト
✓ 列数:1、フィールド state_kana を参照
✓ サイズ：17,346,704
✓ エントリ数：125,263、トップカテゴリ数：47
✓ カテゴリ表示、カテゴリを閉じた状態がデフォルト
 ビュー(state_kanji)：漢字の都道府県名リスト
✓ 列数:1 、フィールド state_kanji を参照
✓ サイズ：17,346,704
✓ エントリ数：125,263、トップカテゴリ数：47
✓ カテゴリ表示、カテゴリを閉じた状態がデフォルト

View Slide

では、
「遅さ」を感じてください！
 DEMO
 データベースを開きます
 文書を開きます
 編集モードに切り替えます
 内容を編集して保存します
 文書を閉じます

View Slide

NRPCログ
「対策していない状態」
[350C:0002-0D70] (1-11 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 3 ms.)
[350C:0002-0D70] (OPEN_SESSION: 2 ms)
[350C:0002-0D70] (Opened: REP492583B3:001C106D) 3 ms. [134+290=424]
[350C:0002-0D70] (5-11 [5]) GET LAST INDEX TIME(REP492583B3:001C106D): 17 ms. [14+76=90] (Database is not full text indexed)
[350C:0002-0D70] (6-12 [6]) OPEN_NOTE(REP492583B3:001C106D-NT0007AD8E,02400036): 1 ms. [48+924=972]
[350C:0002-0D70] (8-12 [8]) OPEN_COLLECTION(REP492583B3:001C106D-NT0000018A,0000,0000): 2 ms. [42+34=76]
[350C:0002-0D70] (18-27 [18]) GET_SERVER_STATS: 2 ms. [38+16=54]
[350C:0002-0D70] (23-35 [23]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 1 ms. [828+88=916]
[350C:0002-0D70] (25-36 [25]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 10:08:47): 1 ms. [140+1516=1656]
[350C:0002-0D70] (27-37 [27]) CLOSE_COLLECTION(REP492583B3:001C106D-NT0000018A): 1 ms. [12+0=12]
[350C:0002-0D70] (29-37 [29]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]
文書を表示モードで開く
OPEN_NOTE : 1 ms. [48+924=972]
DB_MODIFIED_TIME : 0 ms. [14+76=90]
OPEN_COLLECTION : 2 ms. [42+34=76]
READ_ENTRIES : 2577 ms. [76+1502=1578]
READ_ENTRIES : 2575 ms. [76+1128=1204]
編集モードへ切り替える
NOTE LOCK/UNLOCK : 3 ms. [46+22=68]
READ_ENTRIES : 2553 ms. [76+1502=1578]
READ_ENTRIES : 2541 ms. [76+1128=1204]
保存する
READ_ENTRIES : 2489 ms. [76+1502=1578]
READ_ENTRIES : 2536 ms. [76+1128=1204]
UPDATE_NOTE : 1 ms. [828+88=916]
デフォルト
ビュー開く
文書を開く
編集モード
へ切替
文書を保存
文書閉じる
DB閉じる
DB開く

View Slide

READ_ENTRIES をコールするタイミング
1. 文書を表示モードで開いたときに @DbColumn が評価される
2. 編集モードに切り替えたときに @DbColumn が評価される
3. 保存するときに @DbColumn が評価される
評価
不要
評価
不要

View Slide

READ_ENTRIES のコールを抑制する
（１）編集時以外は式を評価しない
 「編集中」かどうかを調べる
@IsDocBeingEdited
1 (True) は文書が編集中であることを意味します
例）
@If(@IsDocBeingEdited; ""; @Return(@ThisName));
説明：文書が編集中のとき、次の処理へ、編集中でなければ式の実行を中止します

View Slide

READ_ENTRIES のコールを抑制する
（２）キャッシュの活用
 ビューのエントリをキャッシュする
@DbColumn( ””: ”NoCache”; …)
常に最新のリストを要求する場合に NoCache を指定します
ここで取得するデータは都道府県名のリストであり、変更する可能性が極めて低いと考えられ
ます。変更頻度が低い場合は積極的にキャッシュを活用します
@DbColumn( ””: ””; …)
省略するとキャッシュが有効になります

View Slide

では、
効果を感じてください！
DEMO
1. フォームを変更します
2. フォームを操作します
1. データベースを開きます
2. 文書を開きます
3. 編集モードに切り替えます
4. 編集して保存します
@If(@IsDocBeingEdited; ""; @Return(@ThisName));
@Unique(@DbColumn("":""; @DbName; "ビュー名"; 1))
@Unique(@DbColumn(“”:“NoCache”; @DbName; “ビュー名"; 1))
変更

View Slide

NRPCログ
「キャッシュ」「編集中のみ式を評価」
[1874:0002-0524] (1-12 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 1 ms.)
[1874:0002-0524] (OPEN_SESSION: 1 ms)
[1874:0002-0524] (Opened: REP492583B3:001C106D) 1 ms. [134+290=424]
[1874:0002-0524] (2-12 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1154=1202]
[1874:0002-0524] (3-13 [3]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000182,0040,4008): 2 ms. [78+34=112]
[1874:0002-0524] (4-13 [4]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 2 ms. [76+1820=1896]
[1874:0002-0524] (5-13 [5]) GET LAST INDEX TIME(REP492583B3:001C106D): 12 ms. [14+76=90] (Database is not full text indexed)
[1874:0002-0524] (6-15 [6]) OPEN_NOTE(REP492583B3:001C106D-NT0007AD8E,02400036): 6 ms. [48+908=956]
[1874:0002-0524] (7-15 [7]) OPEN_NOTE(REP492583B3:001C106D-NT000001CA,02400014): 1 ms. [48+8536=8584]
[1874:0002-0524] (8-16 [8]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 4 ms. [46+22=68]
[1874:0002-0524] (9-16 [9]) DB_MODIFIED_TIME(REP492583B3:001C106D): 0 ms. [14+76=90]
[1874:0002-0524] (10-16 [10]) OPEN_COLLECTION(REP492583B3:001C106D-NT0000018A,0000,0000): 4 ms. [42+34=76]
[1874:0002-0524] (11-16 [11]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 2623 ms. [76+1502=1578]
[1874:0002-0524] (12-19 [12]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90]
[1874:0002-0524] (13-19 [13]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000186,0000,0000): 4 ms. [42+34=76]
[1874:0002-0524] (14-19 [14]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2635 ms. [76+1128=1204]
[1874:0002-0524] (15-27 [15]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 2 ms. [812+88=900]
[1874:0002-0524] (16-27 [16]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 1 ms. [46+22=68]
[1874:0002-0524] (17-27 [17]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 09:05:30): 2 ms. [140+1516=1656]
[1874:0002-0524] (18-29 [18]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000182): 13 ms. [12+0=12]
[1874:0002-0524] (19-29 [19]) CLOSE_COLLECTION(REP492583B3:001C106D-NT0000018A): 1 ms. [12+0=12]
[1874:0002-0524] (20-29 [20]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000186): 1 ms. [12+0=12]
[1874:0002-0524] (21-29 [21]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]
文書を表示モードで開く
OPEN_NOTE : 6 ms. [48+908=956]
OPEN_NOTE : 1 ms. [48+8536=8584]
※上は文書（データ）、下はフォーム（設計）
READ_ENTRIES : 2623 ms. [76+1502=1578]
READ_ENTRIES : 2635 ms. [76+1128=1204]
保存する
UPDATE_NOTE : 2 ms. [812+88=900]
デフォルト
ビュー開く
文書を開く
編集モード
へ切替
文書を保存
文書閉じる
DB閉じる
DB開く

View Slide

READ_ENTRIES が2つで 5 秒は遅い
（サイズは1Kバイト強と小さいのに…）
READ_ENTRIES : 2623 ms. [76+1502=1578]
READ_ENTRIES : 2635 ms. [76+1128=1204]

View Slide

READ_ENTRIES が遅い理由
ビュー索引のサイズが大きい
➢ 設計の複雑さ：ビューには1列だけあり、複雑とは言えない
➢ 列の文字数：47 の都道府県名であり、多いとは言えない
➢ エントリの数：ビューに表示されるエントリは12万5千件

View Slide

ビューエントリを抑制する
「索引にユニークなキーを作成する」を有効にする
➢ 重複するエントリを除去（@Uniqueと同等）して値を取り出
している場合にこの機能を使用できます
➢ ビューの索引は、検出された文字列の最初のインスタンスだ
けを表示します
IBM Lotus Notes/Domino でのより速い検索のコーディング
https://www.ibm.com/developerworks/jp/lotus/library/notes-lookups/index.html

View Slide

ビューエントリを抑制する（続き）
「索引にユニークなキーを作成する」を有効にした結果
 ビューエントリの数
99.9%減 ( 125,263 から 94 へ )
 サイズ
98.7%減 ( 17,346,704 から 225,424 へ)

View Slide

では、
有効にして効果を感じてください！
DEMO
1. ビューのプロパティを変更します
2. ビュー索引を再構築します
3. フォームを操作します
1. データベースを開きます
2. 文書を開きます
3. 編集モードに切り替えます
4. 編集して保存します

View Slide

NRPCログ
「索引にユニークなキーを作成する」
[07C8:0002-3368] (1-12 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 3 ms.)
[07C8:0002-3368] (OPEN_SESSION: 2 ms)
[07C8:0002-3368] (Opened: REP492583B3:001C106D) 2 ms. [134+290=424]
[07C8:0002-3368] (2-12 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1154=1202]
[07C8:0002-3368] (3-12 [3]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000182,0040,4008): 4 ms. [78+34=112]
[07C8:0002-3368] (4-12 [4]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 3 ms. [76+1820=1896]
[07C8:0002-3368] (5-12 [5]) GET LAST INDEX TIME(REP492583B3:001C106D): 1 ms. [14+76=90] (Database is not full text indexed)
[07C8:0002-3368] (6-13 [6]) OPEN_NOTE(REP492583B3:001C106D-NT0007AD8E,02400036): 1 ms. [48+932=980]
[07C8:0002-3368] (7-13 [7]) OPEN_NOTE(REP492583B3:001C106D-NT000001CA,02400014): 1 ms. [48+8528=8576]
[07C8:0002-3368] (8-15 [8]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 5 ms. [46+22=68]
[07C8:0002-3368] (9-15 [9]) DB_MODIFIED_TIME(REP492583B3:001C106D): 0 ms. [14+76=90]
[07C8:0002-3368] (10-15 [10]) OPEN_COLLECTION(REP492583B3:001C106D-NT0000018A,0000,0000): 1 ms. [42+34=76]
[07C8:0002-3368] (11-15 [11]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 4 ms. [76+1502=1578]
[07C8:0002-3368] (12-15 [12]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90]
[07C8:0002-3368] (13-15 [13]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000186,0000,0000): 2 ms. [42+34=76]
[07C8:0002-3368] (14-15 [14]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 5 ms. [76+1128=1204]
[07C8:0002-3368] (15-20 [15]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 2 ms. [836+88=924]
[07C8:0002-3368] (16-20 [16]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 1 ms. [46+22=68]
[07C8:0002-3368] (17-20 [17]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 10:12:13): 4 ms. [140+1516=1656]
[07C8:0002-3368] (18-21 [18]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000182): 15 ms. [12+0=12]
[07C8:0002-3368] (19-21 [19]) CLOSE_COLLECTION(REP492583B3:001C106D-NT0000018A): 0 ms. [12+0=12]
[07C8:0002-3368] (20-21 [20]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000186): 0 ms. [12+0=12]
[07C8:0002-3368] (21-21 [21]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]
READ_ENTRIES : 4 ms. [76+1502=1578]
READ_ENTRIES : 5 ms. [76+1128=1204]
デフォルト
ビュー開く
文書を開く
編集モード
へ切替
文書を保存
文書閉じる
DB閉じる
DB開く

View Slide

抜群に効果を発揮！
「索引にユニークなキーを作成する」
無効
READ_ENTRIES : 2623 ms. [76+1502=1578]
READ_ENTRIES : 2635 ms. [76+1128=1204]
有効
READ_ENTRIES : 4 ms. [76+1502=1578]
READ_ENTRIES : 5 ms. [76+1128=1204]
※ 体感できませんが OPEN_COLLECTION も速くなりました

View Slide

他に方法は？
 ダイアログリストの代わりになる候補
➢ ホットスポット
➢ クリックした時だけ式が評価されるため、表示、モード切替、保存といった操作のパ
フォーマンスに影響しない
➢ @Prompt, @Picklist, NotesUIWorkspace.Dialogbox など
➢ プロフィール文書
➢ ビューと比較すると読み込みにかかるサーバー側の負荷が少なく速い
➢ キャッシュされるため2度目以降が高速

View Slide

NRPCログ
「ホットスポットへ変更」
[1DB8:0002-2DC4] (1-12 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 3 ms.)
[1DB8:0002-2DC4] (OPEN_SESSION: 1 ms)
[1DB8:0002-2DC4] (Opened: REP492583B3:001C106D) 2 ms. [134+290=424]
[1DB8:0002-2DC4] (2-12 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1154=1202]
[1DB8:0002-2DC4] (3-12 [3]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000182,0040,4008): 1 ms. [78+34=112]
[1DB8:0002-2DC4] (4-12 [4]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 2 ms. [76+3304=3380]
[1DB8:0002-2DC4] (5-12 [5]) GET LAST INDEX TIME(REP492583B3:001C106D): 17 ms. [14+76=90] (Database is not full text indexed)
[1DB8:0002-2DC4] (6-15 [6]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 11:59:15): 4 ms. [224+2530=2754]
[1DB8:0002-2DC4] (7-17 [7]) OPEN_NOTE(REP492583B3:001C106D-NT0007AD8E,02400036): 1 ms. [48+956=1004]
[1DB8:0002-2DC4] (8-20 [8]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 4 ms. [46+22=68]
[1DB8:0002-2DC4] (9-23 [9]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90]
[1DB8:0002-2DC4] (10-23 [10]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000186,0000,0000): 2 ms. [42+34=76]
[1DB8:0002-2DC4] (11-23 [11]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 4 ms. [76+1128=1204]
[1DB8:0002-2DC4] (12-27 [12]) GET_SERVER_STATS: 5 ms. [38+16=54]
[1DB8:0002-2DC4] (13-28 [13]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 3 ms. [860+88=948]
[1DB8:0002-2DC4] (14-28 [14]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 1 ms. [46+22=68]
[1DB8:0002-2DC4] (15-28 [15]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 11:59:15): 2 ms. [134+1516=1650]
[1DB8:0002-2DC4] (16-29 [16]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000182): 16 ms. [12+0=12]
[1DB8:0002-2DC4] (17-29 [17]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000186): 1 ms. [12+0=12]
[1DB8:0002-2DC4] (18-29 [18]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]
ホットスポットの式は、ク
リックするまで評価されない
デフォルト
ビュー開く
文書を開く
編集モードへ
文書を保存
文書閉じる
DB閉じる
DB開く
ホットス
ポット
v := @DbColumn("":""; @DbName; "(state_kanji)"; 1);
res := @Prompt([OkCancelList]:[NoSort];"選択" ; "都道府県を選択します"; ""; v);
FIELD state_kanji := res;
ホットスポットの式

View Slide

NRPCログ
「プロフィール文書へ変更」
[1B34:0002-1B58] (1-18 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 3 ms.)
[1B34:0002-1B58] (OPEN_SESSION: 1 ms)
[1B34:0002-1B58] (Opened: REP492583B3:001C106D) 2 ms. [134+290=424]
[1B34:0002-1B58] (2-18 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1154=1202]
[1B34:0002-1B58] (3-19 [3]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000182,0040,4008): 3 ms. [78+34=112]
[1B34:0002-1B58] (4-19 [4]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 3 ms. [76+1820=1896]
[1B34:0002-1B58] (5-19 [5]) GET LAST INDEX TIME(REP492583B3:001C106D): 19 ms. [14+76=90] (Database is not full text indexed)
[1B34:0002-1B58] (6-22 [6]) OPEN_NOTE(REP492583B3:001C106D-NT0007AD8E,02400036): 1 ms. [48+988=1036]
[1B34:0002-1B58] (7-22 [7]) OPEN_NOTE(REP492583B3:001C106D-NT000001CA,02400014): 1 ms. [48+8630=8678]
[1B34:0002-1B58] (8-24 [8]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 4 ms. [46+22=68]
[1B34:0002-1B58] (9-27 [9]) OPEN_NOTE_UNIDNAME_RQST(REP492583B3:001C106D-$profile_008getstate_common,00400020): 5 ms. [94+834=928]
[1B34:0002-1B58] (10-28 [10]) GET_SERVER_STATS: 5 ms. [38+16=54]
[1B34:0002-1B58] (11-34 [11]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 2 ms. [892+88=980]
[1B34:0002-1B58] (12-34 [12]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 1 ms. [46+22=68]
[1B34:0002-1B58] (13-34 [13]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 16:52:49): 1 ms. [140+1516=1656]
[1B34:0002-1B58] (14-35 [14]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000182): 16 ms. [12+0=12]
[1B34:0002-1B58] (15-35 [15]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]
デフォルト
ビュー開く
文書を開く
編集モードへ
文書を保存
文書閉じる
DB閉じる
DB開く
プロフィール文書
NRPC通信がコンパクトになる

View Slide

そのほか、遅くなる要因
 ビュー索引が無い（削除されている）
 しばらく閲覧されず Updall により削除されたり、ビューの削除オプションで「使用
後に削除」としているビューでは、索引が構築されるまで待ちになる
 読者フィールド
読者フィールドにより閲覧を制限している場合、サーバーはデータベース内の文書を最
初から調べ、ページを満たすデータ量になるか最後の文書まで調べあげて、クライアン
トへ送る
例えば10万文書のうちの数％しか閲覧できないユーザーは、すべて閲覧できるユーザー
に比べ、ビューの表示が非常に遅い

View Slide

NRPCログ
「ビュー索引が無い」
[07C4:0002-312C] (1-10 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 3 ms.)
[07C4:0002-312C] (OPEN_SESSION: 2 ms)
[07C4:0002-312C] (Opened: REP492583B3:001C106D) 2 ms. [134+290=424]
[07C4:0002-312C] (2-10 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1154=1202]
[07C4:0002-312C] (3-11 [3]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000182,0040,4008): 1 ms. [78+34=112]
[07C4:0002-312C] (4-11 [4]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 2 ms. [76+1820=1896]
[07C4:0002-312C] (5-11 [5]) GET LAST INDEX TIME(REP492583B3:001C106D): 18 ms. [14+76=90] (Database is not full text indexed)
[07C4:0002-312C] (6-12 [6]) OPEN_NOTE(REP492583B3:001C106D-NT0007AD8E,02400036): 3 ms. [48+948=996]
[07C4:0002-312C] (7-14 [7]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 5 ms. [46+22=68]
[07C4:0002-312C] (8-14 [8]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90]
[07C4:0002-312C] (9-14 [9]) OPEN_COLLECTION(REP492583B3:001C106D-NT0000018A,0000,0000): 6843 ms. [42+44=86]
[07C4:0002-312C] (10-21 [10]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 3 ms. [76+1502=1578]
[07C4:0002-312C] (11-21 [11]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90]
[07C4:0002-312C] (12-21 [12]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000186,0000,0000): 9905 ms. [42+44=86]
[07C4:0002-312C] (13-31 [13]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2 ms. [76+1128=1204]
[07C4:0002-312C] (14-33 [14]) GET_SERVER_STATS: 20 ms. [38+16=54]
[07C4:0002-312C] (15-39 [15]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 3 ms. [852+88=940]
[07C4:0002-312C] (16-39 [16]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 1 ms. [46+22=68]
[07C4:0002-312C] (17-39 [17]) READ_ENTRIES(REP492583B3:001C106D-NT00000182,Since:2019/06/11 11:41:37): 4 ms. [140+1516=1656]
[07C4:0002-312C] (18-41 [18]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000182): 17 ms. [12+0=12]
[07C4:0002-312C] (19-41 [19]) CLOSE_COLLECTION(REP492583B3:001C106D-NT0000018A): 0 ms. [12+0=12]
[07C4:0002-312C] (20-41 [20]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000186): 0 ms. [12+0=12]
[07C4:0002-312C] (21-41 [21]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]
索引が無いため構築待ちとなる
READ_ENTRIES : 3 ms. [76+1502=1578]
READ_ENTRIES : 2 ms. [76+1128=1204]
デフォルト
ビュー開く
文書を開く
編集モード
へ切替
文書を保存
文書閉じる
DB閉じる
DB開く

View Slide

NRPCログ
「読者フィールド」
[2078:0002-0AAC] (1-16 [1]) OPEN_DB(CN=xps13/O=v10!!PostalCodeJP.nsf): (Connect to xps13/v10: 0 ms) (Exch names: 0 ms)(Authenticate: 2 ms.)
[2078:0002-0AAC] (OPEN_SESSION: 2 ms)
[2078:0002-0AAC] (Opened: REP492583B3:001C106D) 2 ms. [134+290=424]
[2078:0002-0AAC] (2-16 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 2 ms. [48+1144=1192]
[2078:0002-0AAC] (3-16 [3]) OPEN_COLLECTION(REP492583B3:001C106D-NTFFFF0020,0000,1000): 2 ms. [42+758=800]
[2078:0002-0AAC] (4-16 [4]) READ_ENTRIES(REP492583B3:001C106D-NTFFFF0020): 3 ms. [170+19540=19710]
[2078:0002-0AAC] (5-16 [5]) CLOSE_COLLECTION(REP492583B3:001C106D-NTFFFF0020): 0 ms. [12+0=12]
[2078:0002-0AAC] (6-16 [6]) GET_NAMED_OBJECT_ID($PrivateDesign): 0 ms. [40+24=64]
[2078:0002-0AAC] (7-16 [7]) OPEN_COLLECTION(REP492583B3:001C106D-NT000001F6,0000,1000): 1 ms. [42+828=870]
[2078:0002-0AAC] (8-16 [8]) READ_ENTRIES(REP492583B3:001C106D-NT000001F6): 1 ms. [76+84=160]
[2078:0002-0AAC] (9-16 [9]) CLOSE_COLLECTION(REP492583B3:001C106D-NT000001F6): 0 ms. [12+0=12]
[2078:0002-0AAC] (10-16 [10]) DB_MODIFIED_TIME(REP492583B3:001C106D): 0 ms. [14+76=90]
[2078:0002-0AAC] (11-16 [11]) GET_MULT_NOTE_INFO_BY_UNID(REP492583B3:001C106D): 1 ms. [296+566=862]
[2078:0002-0AAC] (12-16 [12]) DB_REPLINFO_GET(REP492583B3:001C106D): 0 ms. [14+32=46]
[2078:0002-0AAC] (13-16 [13]) DB_INFO_GET(REP492583B3:001C106D): 0 ms. [14+140=154]
[2078:0002-0AAC] (14-16 [14]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1144=1192]
[2078:0002-0AAC] (15-16 [15]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000182,0040,4008): 1 ms. [78+34=112]
[2078:0002-0AAC] (16-16 [16]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 4312 ms. [76+92=168]
[2078:0002-0AAC] (19-28 [19]) GET LAST INDEX TIME(REP492583B3:001C106D): 17 ms. [14+76=90] (Database is not full text indexed)
[2078:0002-0AAC] (20-31 [20]) GET_SERVER_STATS: 20 ms. [38+16=54]
[2078:0002-0AAC] (21-31 [21]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000182): 20 ms. [12+0=12]
[2078:0002-0AAC] (22-32 [22]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]
閲覧可能なデータでビューの画面（ペー
ジ）が満たされるまで待ちとなる
READ_ENTRIES : 4312 ms. [76+92=168]
READ_ENTRIES : 2660 ms. [76+92=168]
READ_ENTRIES : 3664 ms. [76+92=168]
デフォルト
ビュー開く
DB閉じる
DB開く
デフォルトビューを開くまでの NRPC
通信が増えた
1件も閲覧できない状態としたため、受信バイト
数がほぼ無い

View Slide

NRPCログ取得のコツ
 シーケンス番号の間にある数字（下図：黄色の字）は、クライアント起動時か
らの経過時間？のようです。ユーザーが操作する場合、次の操作までの間を数
秒あけるとこの数字に反映するため、ログがより理解しやすくなります。
 ログの混乱を避けるため、「新規メールの通知」などサーバーへのアクセスが
発生する機能はクライアントの設定で一時的に無効にすることをお勧めします。
(1-18 [1]) OPEN_DB : 2 ms. [134+290=424]
(2-18 [2]) OPEN_NOTE : 1 ms. [48+1154=1202]
(3-19 [3]) OPEN_COLLECTION: 3 ms. [78+34=112]
(4-19 [4]) READ_ENTRIES : 3 ms. [76+1820=1896]
(5-19 [5]) GET LAST INDEX TIME : 19 ms. [14+76=90]
(6-22 [6]) OPEN_NOTE : 1 ms. [48+988=1036]
(7-22 [7]) OPEN_NOTE : 1 ms. [48+8630=8678]
(8-24 [8]) NOTE LOCK/UNLOCK : 4 ms. [46+22=68]
(9-27 [9]) OPEN_NOTE_UNIDNAME_RQST : 5 ms. [94+834=928]
(10-28 [10]) GET_SERVER_STATS : 5 ms. [38+16=54]
(11-34 [11]) UPDATE_NOTE : 2 ms. [892+88=980]
(12-34 [12]) NOTE LOCK/UNLOCK : 1 ms. [46+22=68]
(13-34 [13]) READ_ENTRIES : 1 ms. [140+1516=1656]
(14-35 [14]) CLOSE_COLLECTION : 16 ms. [12+0=12]
(15-35 [15]) CLOSE_DB : 0 ms. [14+0=14]
※不要な情報を除去しています

View Slide

スライドの最後

View Slide

Notesアプリの「遅い」を見てみよう

Notesアプリの「遅い」を見てみよう

Haruyuki Nakano

More Decks by Haruyuki Nakano

Other Decks in How-to & DIY

Featured

Transcript