ユーザーが Notes クライアントでアプリケーションを操作したときの Domino サーバーへ要求するコマンドをクライアント側で記録することで、どういった操作や設定がどれくらい遅くてどのように改善できたかを検証しています。
2019年6月13日開催の「のの会 第15回」で使用した資料です。
パフォーマンス小噺アプリの「遅い」を見てみよう中野晴幸 (Haruyuki Nakano)@harunakano (Twitter)harunakano.blogspot.com (blog)
View Slide
「遅い」を実感するタイミング データベース(デフォルトビュー)を開く 文書を開く 編集モードへ切り替える 文書を保存する
遅い実態を調べようNRPCログについて
CLIENT_CLOCK=1Notes/Domino のクライアントとサーバーとの NRPC コマンドの履歴を記録するクライアントの notes.ini へ次の3行を追加する CLIENT_CLOCK=1 CONSOLE_LOG_ENABLED=1 DEBUG_THREADID=1
NRPC のログ記録先 最新のログは、データディレクトリの IBM_TECHNICAL_SUPPORT フォルダへconsole.log が作成され、記録される 過去のログは console__<開始日付>@<開始時刻>.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)2つの「ダイアログリスト」フィールドで @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 のコールを抑制する(1)編集時以外は式を評価しない 「編集中」かどうかを調べる@IsDocBeingEdited1 (True) は文書が編集中であることを意味します例)@If(@IsDocBeingEdited; ""; @Return(@ThisName));説明:文書が編集中のとき、次の処理へ、編集中でなければ式の実行を中止します
READ_ENTRIES のコールを抑制する(2)キャッシュの活用 ビューのエントリをキャッシュする@DbColumn( ””: ”NoCache”; …)常に最新のリストを要求する場合に NoCache を指定しますここで取得するデータは都道府県名のリストであり、変更する可能性が極めて低いと考えられます。変更頻度が低い場合は積極的にキャッシュを活用します@DbColumn( ””: ””; …)省略するとキャッシュが有効になります
では、効果を感じてください!DEMO1. フォームを変更します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 へ)
では、有効にして効果を感じてください!DEMO1. ビューのプロパティを変更します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]※不要な情報を除去しています
スライドの最後