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

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

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

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

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

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

取得したログの例 [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] (10-15 [10]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (11-15 [11]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000186,0000,0000): 2 ms. [42+34=76] [350C:0002-0D70] (12-15 [12]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2575 ms. [76+1128=1204] [350C:0002-0D70] (13-19 [13]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 3 ms. [46+22=68] [350C:0002-0D70] (14-19 [14]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (15-19 [15]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 2553 ms. [76+1502=1578] [350C:0002-0D70] (16-21 [16]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (17-21 [17]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2541 ms. [76+1128=1204] [350C:0002-0D70] (18-27 [18]) GET_SERVER_STATS: 2 ms. [38+16=54] [350C:0002-0D70] (19-30 [19]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (20-30 [20]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 2489 ms. [76+1502=1578] [350C:0002-0D70] (21-33 [21]) DB_MODIFIED_TIME(REP492583B3:001C106D): 0 ms. [14+76=90] [350C:0002-0D70] (22-33 [22]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2536 ms. [76+1128=1204] [350C:0002-0D70] (23-35 [23]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 1 ms. [828+88=916] [350C:0002-0D70] (24-36 [24]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 1 ms. [46+22=68] [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] (28-37 [28]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000186): 0 ms. [12+0=12] [350C:0002-0D70] (29-37 [29]) CLOSE_DB(REP492583B3:001C106D): 0 ms. [14+0=14]

ログの見かた [350C:0002-0D70] (2-11 [2]) OPEN_NOTE(REP492583B3:001C106D-NTFFFF0010,03000400): 1 ms. [48+1154=1202] スレッド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. [送信バイト数+受信バイト数=送受信バイト数]

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

レプリカID、ノートID

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

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

郵便番号データベース

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

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

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

検索用のビュー (Domino Designer)

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

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

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] (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] (10-15 [10]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (11-15 [11]) OPEN_COLLECTION(REP492583B3:001C106D-NT00000186,0000,0000): 2 ms. [42+34=76] [350C:0002-0D70] (12-15 [12]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2575 ms. [76+1128=1204] [350C:0002-0D70] (13-19 [13]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 3 ms. [46+22=68] [350C:0002-0D70] (14-19 [14]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (15-19 [15]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 2553 ms. [76+1502=1578] [350C:0002-0D70] (16-21 [16]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (17-21 [17]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2541 ms. [76+1128=1204] [350C:0002-0D70] (18-27 [18]) GET_SERVER_STATS: 2 ms. [38+16=54] [350C:0002-0D70] (19-30 [19]) DB_MODIFIED_TIME(REP492583B3:001C106D): 1 ms. [14+76=90] [350C:0002-0D70] (20-30 [20]) READ_ENTRIES(REP492583B3:001C106D-NT0000018A): 2489 ms. [76+1502=1578] [350C:0002-0D70] (21-33 [21]) DB_MODIFIED_TIME(REP492583B3:001C106D): 0 ms. [14+76=90] [350C:0002-0D70] (22-33 [22]) READ_ENTRIES(REP492583B3:001C106D-NT00000186): 2536 ms. [76+1128=1204] [350C:0002-0D70] (23-35 [23]) UPDATE_NOTE(REP492583B3:001C106D-NT0007AD8E,00000000): 1 ms. [828+88=916] [350C:0002-0D70] (24-36 [24]) NOTE LOCK/UNLOCK(REP492583B3:001C106D): 1 ms. [46+22=68] [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] (28-37 [28]) CLOSE_COLLECTION(REP492583B3:001C106D-NT00000186): 0 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] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 2 ms. [42+34=76] READ_ENTRIES : 2575 ms. [76+1128=1204] 編集モードへ切り替える NOTE LOCK/UNLOCK : 3 ms. [46+22=68] DB_MODIFIED_TIME : 1 ms. [14+76=90] READ_ENTRIES : 2553 ms. [76+1502=1578] DB_MODIFIED_TIME : 1 ms. [14+76=90] READ_ENTRIES : 2541 ms. [76+1128=1204] 保存する DB_MODIFIED_TIME : 1 ms. [14+76=90] READ_ENTRIES : 2489 ms. [76+1502=1578] DB_MODIFIED_TIME : 0 ms. [14+76=90] READ_ENTRIES : 2536 ms. [76+1128=1204] UPDATE_NOTE : 1 ms. [828+88=916] デフォルトビュー開く文書を開く編集モードへ切替文書を保存文書閉じる DB閉じる DB開く

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

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

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

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

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] ※上は文書（データ）、下はフォーム（設計）編集モードへ切り替える NOTE LOCK/UNLOCK : 4 ms. [46+22=68] DB_MODIFIED_TIME : 0 ms. [14+76=90] OPEN_COLLECTION : 4 ms. [42+34=76] READ_ENTRIES : 2623 ms. [76+1502=1578] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 4 ms. [42+34=76] READ_ENTRIES : 2635 ms. [76+1128=1204] 保存する UPDATE_NOTE : 2 ms. [812+88=900] デフォルトビュー開く文書を開く編集モードへ切替文書を保存文書閉じる DB閉じる DB開く

READ_ENTRIES が2つで 5 秒は遅い（サイズは1Kバイト強と小さいのに…）編集モードへ切り替える NOTE LOCK/UNLOCK : 4
ms. [46+22=68] DB_MODIFIED_TIME : 0 ms. [14+76=90] OPEN_COLLECTION : 4 ms. [42+34=76] READ_ENTRIES : 2623 ms. [76+1502=1578] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 4 ms. [42+34=76] READ_ENTRIES : 2635 ms. [76+1128=1204]

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

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

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

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

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] 編集モードへ切り替える NOTE LOCK/UNLOCK : 5 ms. [46+22=68] DB_MODIFIED_TIME : 0 ms. [14+76=90] OPEN_COLLECTION : 1 ms. [42+34=76] READ_ENTRIES : 4 ms. [76+1502=1578] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 2 ms. [42+34=76] READ_ENTRIES : 5 ms. [76+1128=1204] デフォルトビュー開く文書を開く編集モードへ切替文書を保存文書閉じる DB閉じる DB開く

抜群に効果を発揮！「索引にユニークなキーを作成する」無効 NOTE LOCK/UNLOCK : 4 ms. [46+22=68] DB_MODIFIED_TIME
: 0 ms. [14+76=90] OPEN_COLLECTION : 4 ms. [42+34=76] READ_ENTRIES : 2623 ms. [76+1502=1578] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 4 ms. [42+34=76] READ_ENTRIES : 2635 ms. [76+1128=1204] 有効 NOTE LOCK/UNLOCK : 5 ms. [46+22=68] DB_MODIFIED_TIME : 0 ms. [14+76=90] OPEN_COLLECTION : 1 ms. [42+34=76] READ_ENTRIES : 4 ms. [76+1502=1578] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 2 ms. [42+34=76] READ_ENTRIES : 5 ms. [76+1128=1204] ※ 体感できませんが OPEN_COLLECTION も速くなりました

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

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; ホットスポットの式

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通信がコンパクトになる

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

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] 索引が無いため構築待ちとなる NOTE LOCK/UNLOCK : 5 ms. [46+22=68] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 6843 ms. [42+44=86] READ_ENTRIES : 3 ms. [76+1502=1578] DB_MODIFIED_TIME : 1 ms. [14+76=90] OPEN_COLLECTION : 9905 ms. [42+44=86] READ_ENTRIES : 2 ms. [76+1128=1204] デフォルトビュー開く文書を開く編集モードへ切替文書を保存文書閉じる DB閉じる DB開く

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] (17-21 [17]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 3660 ms. [76+92=168] [2078:0002-0AAC] (18-24 [18]) READ_ENTRIES(REP492583B3:001C106D-NT00000182): 3664 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件も閲覧できない状態としたため、受信バイト数がほぼ無い

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] ※不要な情報を除去しています

スライドの最後

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

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

More Decks by Haruyuki Nakano

Other Decks in How-to & DIY

Featured

Transcript