$30 off During Our Annual Pro Sale. View Details »

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

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

ユーザーが Notes クライアントでアプリケーションを操作したときの Domino サーバーへ要求するコマンドをクライアント側で記録することで、どういった操作や設定がどれくらい遅くてどのように改善できたかを検証しています。

2019年6月13日開催の「のの会 第15回」で使用した資料です。

Haruyuki Nakano

September 08, 2022
Tweet

More Decks by Haruyuki Nakano

Other Decks in How-to & DIY

Transcript

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

  6. 取得したログの例
    [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]

    View Slide

  7. ログの見かた
    [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. [送信バイト数+受信バイト数=送受信バイト数]

    View Slide

  8. NRPC コマンド
    OPEN_DB DBを開く
    OPEN_COLLECTION ビュー(索引)を開く
    ※ビュー索引が無い場合、構築するまでに長時間またされる場合があ

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

    View Slide

  9. レプリカID、ノートID

    View Slide

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

    View Slide

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

    View Slide

  12. 郵便番号データベース

    View Slide

  13. フォーム
    (Notes クライアント)

    View Slide

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

    View Slide

  15. 検索用のビュー
    (Notes クライアント)

    View Slide

  16. 検索用のビュー
    (Domino Designer)

    View Slide

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

    View Slide

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

    View Slide

  19. 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開く

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

  24. 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開く

    View Slide

  25. 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]

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

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

    View Slide

  30. 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開く

    View Slide

  31. 抜群に効果を発揮!
    「索引にユニークなキーを作成する」
    無効
    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 も速くなりました

    View Slide

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

    View Slide

  33. 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

  34. 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

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

    View Slide

  36. 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開く

    View Slide

  37. 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件も閲覧できない状態としたため、受信バイト
    数がほぼ無い

    View Slide

  38. 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

  39. スライドの最後

    View Slide