audit-sumツールの使用

audit-sumツールを使用すると、書き込み、読み取り、HEAD、および削除の監査メッセージをカウントしたり、それぞれの最小、最大、平均時間(またはサイズ)を表示したりできます。

開始する前に

タスク概要

audit-sumツールはプライマリ管理ノードで使用でき、ログに記録された書き込み、読み取り、削除の処理数と、それらの処理に要した時間を取得できます。

注意: audit-sumツールは、主にトラブルシューティング処理の際にテクニカル サポートが使用することを目的としたものです。audit-sumクエリの処理には大量のCPUパワーが消費される可能性があるため、StorageGRIDの処理に影響を及ぼすことがあります。

次の例は、audit-sumツールからの典型的な出力を示しています。この例は、プロトコル処理に要した時間を示しています。

  message group           count     min(sec)        max(sec)    average(sec)
  =============           =====     ========        ========    ============
  IDEL                      274 
  SDEL                   213371        0.004          20.934           0.352
  SGET                   201906        0.010        1740.290           1.132
  SHEA                    22716        0.005           2.349           0.272
  SPUT                  1771398        0.011        1770.563           0.487
audit-sumツールは、監査ログ内の次のS3 / Swift / ILM監査メッセージの数と時間を取得します。
コード 説明 参照先
ARCT Archive Retrieve from Cloud-Tier ARCT:Archive Retrieve from Cloud-Tier
ASCT Archive Store Cloud-Tier ASCT:Archive Store Cloud-Tier
IDEL ILM Initiated Delete:ILMがオブジェクトを削除する処理を開始すると記録されます。 IDEL:ILM Initiated Delete
SDEL S3 DELETE:オブジェクトまたはバケットを削除するトランザクションの成功をログに記録します。 SDEL:S3 DELETE
SGET S3 GET:バケット内のオブジェクトを読み出しまたはリストアップするトランザクションの成功をログに記録します。 SGET:S3 GET
SHEA S3 HEAD:オブジェクトまたはバケットの存在を確認するトランザクションの成功をログに記録します。 SHEA:S3 HEAD
SPUT S3 PUT:オブジェクトまたはバケットを新規に作成するトランザクションの成功をログに記録します。 SPUT:S3 PUT
WDEL Swift DELETE:オブジェクトまたはコンテナを削除するトランザクションの成功をログに記録します。 WDEL:Swift DELETE
WGET Swift GET:コンテナ内のオブジェクトを読み出しまたはリストアップするトランザクションの成功をログに記録します。 WGET:Swift GET
WHEA Swift HEAD:オブジェクトまたはコンテナの存在を確認するトランザクションの成功をログに記録します。 WHEA:Swift HEAD
WPUT Swift PUT:オブジェクトまたはコンテナを新規に作成するトランザクションの成功をログに記録します。 WPUT:Swift PUT

audit-sumツールは、プレーン形式または圧縮形式の監査ログを処理できます。次に例を示します。

audit-sum audit.log
audit-sum 2019-08-12.txt.gz
audit-sumツールは、複数のファイルを一度に処理することもできます。次に例を示します。
audit-sum audit.log 2019-08-12.txt.gz 2019-08-13.txt.gz
audit-sum /var/local/audit/export/*
最後に、audit-sumツールはパイプ入力も受け入れます。そのため、grepコマンドまたはその他の方法を使用して、入力をフィルタリングおよび前処理することができます。次に例を示します。
grep WGET audit.log | audit-sum
grep bucket1 audit.log | audit-sum
grep SPUT audit.log | grep bucket1 | audit-sum
注: このツールは、圧縮ファイルをパイプ付き入力として受け入れません。圧縮ファイルを処理するには、ファイル名をコマンドライン引数として指定するか、zcatツールを使用して最初にファイルを解凍します。次に例を示します。
audit-sum audit.log.gz
zcat audit.log.gz | audit-sum

コマンドライン オプションを使用して、バケットに対する処理をオブジェクトに対する処理とは別にまとめたり、メッセージの概要をバケット名、期間、ターゲット タイプ別にグループ化したりできます。デフォルトでは、概要には最小、最大、平均の処理時間が表示されますが、size(-s)オプションを使用してオブジェクト サイズを表示することもできます。

使用可能なオプションを確認するには、help(-h)オプションを使用します。次に例を示します。
$ audit-sum -h

手順

  1. プライマリ管理ノードにログインします。
    1. 次のコマンドを入力します:ssh admin@primary_Admin_Node_IP
    2. Passwords.txtファイルに含まれているパスワードを入力します。
  2. 書き込み、読み取り、HEAD、削除の処理に関連するすべてのメッセージを分析するには、次の手順を実行します。
    1. 次のコマンドを入力します。/var/local/audit/export/audit.logは、分析するファイルの名前と場所を表します。$ audit-sum /var/local/audit/export/audit.log
      次の例は、audit-sumツールからの典型的な出力を示しています。この例は、プロトコル処理に要した時間を示しています。
        message group           count     min(sec)        max(sec)    average(sec)
        =============           =====     ========        ========    ============
        IDEL                      274 
        SDEL                   213371        0.004          20.934           0.352
        SGET                   201906        0.010        1740.290           1.132
        SHEA                    22716        0.005           2.349           0.272
        SPUT                  1771398        0.011        1770.563           0.487

      この例では、平均処理時間ではSGET(S3 GET)処理が1.13秒と最も長い一方で、最大処理時間ではSGET処理とSPUT(S3 PUT)処理がどちらも約1,770秒と一番長くなっています。

    2. 最も時間がかかった読み出し処理を10件表示するには、grepコマンドを使用してSGETメッセージだけを選択し、long出力オプション(-l)を追加してオブジェクト パスを含めます。grep SGET audit.log | audit-sum -l
      結果にはタイプ(オブジェクトまたはバケット)とパスが含まれます。この情報を使用して、監査ログをgrepしてこれらのオブジェクトに関連する他のメッセージを出力できます。
      Total:          201906 operations
          Slowest:      1740.290 sec
          Average:         1.132 sec
          Fastest:         0.010 sec
          Slowest operations:
              time(usec)       source ip         type      size(B) path
              ========== =============== ============ ============ ====
              1740289662   10.96.101.125       object   5663711385 backup/r9O1OaQ8JB-1566861764-4519.iso
              1624414429   10.96.101.125       object   5375001556 backup/r9O1OaQ8JB-1566861764-6618.iso
              1533143793   10.96.101.125       object   5183661466 backup/r9O1OaQ8JB-1566861764-4518.iso
                   70839   10.96.101.125       object        28338 bucket3/dat.1566861764-6619
                   68487   10.96.101.125       object        27890 bucket3/dat.1566861764-6615
                   67798   10.96.101.125       object        27671 bucket5/dat.1566861764-6617
                   67027   10.96.101.125       object        27230 bucket5/dat.1566861764-4517
                   60922   10.96.101.125       object        26118 bucket3/dat.1566861764-4520
                   35588   10.96.101.125       object        11311 bucket3/dat.1566861764-6616
                   23897   10.96.101.125       object        10692 bucket3/dat.1566861764-4516

      この出力例からは、最も時間がかかった3個のS3 GET要求が、他のオブジェクトよりもはるかに大きい約5GBのオブジェクトに対して実行されたことがわかります。サイズが読み出し時間が長くなった原因です。

  3. グリッドに取り込まれているオブジェクトとグリッドから読み出されているオブジェクトのサイズを特定するには、sizeオプション(-s)を使用します。audit-sum -s audit.log
      message group           count       min(B)          max(B)      average(B)
      =============           =====     ========        ========    ============
      IDEL                      274        0.004        5000.000        1654.502
      SDEL                   213371        0.000          10.504           1.695
      SGET                   201906        0.000        5000.000          14.920
      SHEA                    22716        0.001          10.504           2.967
      SPUT                  1771398        0.000        5000.000           2.495

    この例では、SPUTの平均オブジェクト サイズは2.5バイト未満ですが、SGETの平均サイズははるかに大きいことがわかります。SPUTメッセージの数はSGETメッセージの数よりもはるかに多く、ほとんどのオブジェクトが読み出されていないことを示しています。

  4. 前日の読み出しに時間がかかっていたかどうかを確認するには、次の手順を実行します。
    1. 該当する監査ログに対して、group-by-timeオプション(-gt)と期間(例:15M、1H、10S)を指定してコマンドを実行します。grep SGET audit.log | audit-sum -gt 1H
        message group           count     min(sec)        max(sec)    average(sec)
        =============           =====     ========        ========    ============
        2019-09-05T00            7591        0.010        1481.867           1.254
        2019-09-05T01            4173        0.011        1740.290           1.115
        2019-09-05T02           20142        0.011        1274.961           1.562
        2019-09-05T03           57591        0.010        1383.867           1.254
        2019-09-05T04          124171        0.013        1740.290           1.405
        2019-09-05T05          420182        0.021        1274.511           1.562
        2019-09-05T06         1220371        0.015        6274.961           5.562
        2019-09-05T07          527142        0.011        1974.228           2.002
        2019-09-05T08          384173        0.012        1740.290           1.105
        2019-09-05T09           27591        0.010        1481.867           1.354

      上記の結果は、06:00と07:00の間にS3 GETトラフィックが急増したことを示しています。この時間帯は最大時間と平均時間もかなり長くなっていますが、メッセージ数の増加に伴って徐々に長くなっているわけでもありません。このことから、ネットワークまたはグリッドによる要求の処理機能のどこかでキャパシティを超えた可能性があります。

    2. どのようなサイズのオブジェクトが前日に読み出されていたかを1時間単位で確認するには、コマンドにsizeオプション(-s)を追加します。grep SGET audit.log | audit-sum -gt 1H -s
        message group           count       min(B)          max(B)      average(B)
        =============           =====     ========        ========    ============
        2019-09-05T00            7591        0.040        1481.867           1.976
        2019-09-05T01            4173        0.043        1740.290           2.062
        2019-09-05T02           20142        0.083        1274.961           2.303
        2019-09-05T03           57591        0.912        1383.867           1.182
        2019-09-05T04          124171        0.730        1740.290           1.528
        2019-09-05T05          420182        0.875        4274.511           2.398
        2019-09-05T06         1220371        0.691  5663711385.961          51.328
        2019-09-05T07          527142        0.130        1974.228           2.147
        2019-09-05T08          384173        0.625        1740.290           1.878
        2019-09-05T09           27591        0.689        1481.867           1.354

      この結果から、読み出しトラフィックの量が最大に達したときに、非常に大容量の読み出しが発生したことがわかります。

    3. 詳細を確認するには、audit-explainツールを使用して、対象時間中のすべてのSGET処理を確認します。grep 2019-09-05T06 audit.log | grep SGET | audit-explain | less
      grepコマンドの出力行数が大量になると予想される場合は、lessコマンドを追加して、監査ログ ファイルの内容を1ページ(1画面)ずつ表示します。
  5. バケットに対するSPUT処理にオブジェクトに対するSPUT処理よりも時間がかかっているかどうかを確認するには、次の手順を実行します。
    1. 最初に、-goオプションを使用します。このオプションはオブジェクト処理とバケット処理でメッセージをグループ化します。grep SPUT sample.log | audit-sum -go
        message group           count     min(sec)        max(sec)    average(sec)
        =============           =====     ========        ========    ============
        SPUT.bucket                 1        0.125           0.125           0.125
        SPUT.object                12        0.025           1.019           0.236

      上記の結果から、バケットに対するSPUT処理とオブジェクトに対するSPUT処理でパフォーマンス特性が異なることがわかります。

    2. SPUT処理に最も時間がかかっているバケットを特定するには、-gbオプションを使用します。このオプションはバケットごとにメッセージをグループ化します。grep SPUT audit.log | audit-sum -gb
        message group                  count     min(sec)        max(sec)    average(sec)
        =============                  =====     ========        ========    ============
        SPUT.cho-non-versioning        71943        0.046        1770.563           1.571
        SPUT.cho-versioning            54277        0.047        1736.633           1.415
        SPUT.cho-west-region           80615        0.040          55.557           1.329
        SPUT.ldt002                  1564563        0.011          51.569           0.361
    3. SPUTオブジェクトのサイズが最も大きいバケットを特定するには、-gbオプションと-sオプションを使用します。grep SPUT audit.log | audit-sum -gb -s
        message group                  count       min(B)          max(B)      average(B)
        =============                  =====     ========        ========    ============
        SPUT.cho-non-versioning        71943        2.097        5000.000          21.672
        SPUT.cho-versioning            54277        2.097        5000.000          21.120
        SPUT.cho-west-region           80615        2.097         800.000          14.433
        SPUT.ldt002                  1564563        0.000         999.972           0.352