jq を使った GitLab ログの解析

可能な限り Kibana や Splunk のようなログ集約・検索ツールを使うことをお勧めしますが、それらが使えない場合でも、jq を使えば JSON 形式（GitLab 12.0 以降のデフォルト）のGitLab ログを素早く解析することができます。

note
特にエラーイベントや基本的な使用統計を要約するために、GitLab サポートチームは特別なツールfast-stats を提供しています。

JQとは何ですか？

手動で説明されているように、jq はコマンドライン JSON プロセッサです。以下の例では、GitLab ログファイルの解析を対象としています。

ログの解析

以下の例では、Linux パッケージの相対インストールパスとデフォルトファイル名でそれぞれのログファイルをアドレスしています。それぞれのフルパスはGitLab logs セクションで見つけてください。

一般的なコマンド

カラー化されたjq 出力を次のようにパイプします。less 

jq . <FILE> -C | less -R

用語を検索し、一致する行をすべて pretty-print します。 

grep <TERM> <FILE> | jq .

JSONの無効な行をスキップ 

jq -cR 'fromjson?' file.json | jq <COMMAND>

デフォルトでは、jq 、有効なJSONでない行に遭遇するとエラーになります。これは無効な行をすべてスキップし、残りを解析します。

cat log.json | (head -1; tail -1) | jq '.time'

ファイルが回転および圧縮されている場合は、zcat ：

zcat @400000006026b71d1a7af804.s | (head -1; tail -1) | jq '.time'

zcat some_json.log.25.gz | (head -1; tail -1) | jq '.time'

複数の JSON ログの相関 ID のアクティビティを時系列で取得します。 

grep -hR <correlationID> | jq -c -R 'fromjson?' | jq -C -s 'sort_by(.time)'  | less -R

gitlab-rails/production_json.log の解析とgitlab-rails/api_json.log

5XXステータスコードを持つすべてのリクエストを検索 

jq 'select(.status >= 500)' <FILE>

最も遅いリクエストトップ10 

jq -s 'sort_by(-.duration_s) | limit(10; .[])' <FILE>

grep <PROJECT_NAME> <FILE> | jq .

合計時間が5秒を超えるすべてのリクエストの検索 

jq 'select(.duration_s > 5000)' <FILE>

5回以上のRuggedコールを含むすべてのプロジェクトリクエストを検索します。 

grep <PROJECT_NAME> <FILE> | jq 'select(.rugged_calls > 5)'

Gitalyの持続時間が10秒を超えるすべてのリクエストを検索します。 

jq 'select(.gitaly_duration_s > 10000)' <FILE>

キューの持続時間が10秒を超えるすべてのリクエストを検索します。 

jq 'select(.queue_duration_s > 10000)' <FILE>

Gitaly呼び出し回数上位10リクエスト 

jq -s 'map(select(.gitaly_calls != null)) | sort_by(-.gitaly_calls) | limit(10; .[])' <FILE>

特定の時間範囲を出力 

jq 'select(.time >= "2023-01-10T00:00:00Z" and .time <= "2023-01-10T12:00:00Z")' <FILE>

解析gitlab-rails/production_json.log 

jq -s -r 'group_by(.controller+.action) | sort_by(-length) | limit(3; .[]) | sort_by(-.duration_s) | "CT: \(length)\tMETHOD: \(.[0].controller)#\(.[0].action)\tDURS: \(.[0].duration_s),  \(.[1].duration_s),  \(.[2].duration_s)"' production_json.log

出力例

CT: 2721   METHOD: SessionsController#new  DURS: 844.06,  713.81,  704.66
CT: 2435   METHOD: MetricsController#index DURS: 299.29,  284.01,  158.57
CT: 1328   METHOD: Projects::NotesController#index DURS: 403.99,  386.29,  384.39

解析gitlab-rails/api_json.log 

jq -s -r 'group_by(.route) | sort_by(-length) | limit(3; .[]) | sort_by(-.duration_s) | "CT: \(length)\tROUTE: \(.[0].route)\tDURS: \(.[0].duration_s),  \(.[1].duration_s),  \(.[2].duration_s)"' api_json.log

出力例

CT: 2472 ROUTE: /api/:version/internal/allowed   DURS: 56402.65,  38411.43,  19500.41
CT: 297  ROUTE: /api/:version/projects/:id/repository/tags       DURS: 731.39,  685.57,  480.86
CT: 190  ROUTE: /api/:version/projects/:id/repository/commits    DURS: 1079.02,  979.68,  958.21

jq --raw-output '[.route, .ua] | @tsv' api_json.log | sort | uniq -c | sort -n

出力例

  89 /api/:version/usage_data/increment_unique_users  # plus browser details
 567 /api/:version/jobs/:id/trace       gitlab-runner # plus version details
1234 /api/:version/internal/allowed     GitLab-Shell

このサンプル・レスポンスは典型的なものと思われます。カスタムツールやスクリプトが高負荷を引き起こしている可能性があります：

また、、fast-stats top を使ってパフォーマンス統計を抽出することもできます。

解析gitlab-rails/importer.log

プロジェクトのインポートや マイグレーションのトラブルシューティングを行うには、次のコマンドを実行します：

jq 'select(.project_path == "<namespace>/<project>").error_messages' importer.log

よくあるイシューについては、トラブルシューティングを参照してください。

解析gitlab-workhorse/current 

jq --raw-output '[.uri, .user_agent] | @tsv' current | sort | uniq -c | sort -n

出力例

  89 /api/graphql # plus browser details
 567 /api/v4/internal/allowed   GitLab-Shell
1234 /api/v4/jobs/request       gitlab-runner # plus version details

APIua データ と同様に、この一般的な順序からの逸脱は、最適化できるスクリプトを示している可能性があります。

新しいジョブをチェックするRunnerのパフォーマンスへの影響は、 check_interval の設定 を増やすことなどで減らすことができます。

解析gitlab-rails/geo.log

最も一般的なGeo同期エラーの検索

geo:status Rake タスク で、一部のアイテムが 100% に達しないというレポーターが繰り返し表示される場合、次のコマンドを使用すると、最も一般的なエラーに焦点を絞ることができます。

jq --raw-output 'select(.severity == "ERROR") | [.project_path, .class, .message, .error] | @tsv' geo.log | sort | uniq -c | sort | tail

特定のエラーメッセージに関するアドバイスについては、Geo トラブルシューティングのページを参照してください。

解析gitaly/current

Gitalyのトラブルシューティングには、以下の例を使用してください。

ウェブUIから送信されたすべてのGitalyリクエストの検索 

jq 'select(."grpc.meta.client_name" == "gitlab-web")' current

失敗したGitalyリクエストの検索 

jq 'select(."grpc.code" != null and ."grpc.code" != "OK")' current

30秒以上かかったリクエストの検索 

jq 'select(."grpc.time_ms" > 30000)' current

jq --raw-output --slurp '
  map(
    select(
      ."grpc.request.glProjectPath" != null
      and ."grpc.request.glProjectPath" != ""
      and ."grpc.time_ms" != null
    )
  )
  | group_by(."grpc.request.glProjectPath")
  | sort_by(-length)
  | limit(10; .[])
  | sort_by(-."grpc.time_ms")
  | [
      length,
      .[0]."grpc.time_ms",
      .[1]."grpc.time_ms",
      .[2]."grpc.time_ms",
      .[0]."grpc.request.glProjectPath"
    ]
  | @sh' current \
| awk 'BEGIN { printf "%7s %10s %10s %10s\t%s\n", "CT", "MAX DURS", "", "", "PROJECT" }
  { printf "%7u %7u ms, %7u ms, %7u ms\t%s\n", $1, $2, $3, $4, $5 }'

出力例

   CT    MAX DURS                              PROJECT
  206    4898 ms,    1101 ms,    1032 ms      'groupD/project4'
  109    1420 ms,     962 ms,     875 ms      'groupEF/project56'
  663     106 ms,      96 ms,      94 ms      'groupABC/project123'
  ...

Git の致命的な問題に影響されたすべてのプロジェクトを探します 

grep "fatal: " current | \
    jq '."grpc.request.glProjectPath"' | \
    sort | uniq

解析gitlab-shell/gitlab-shell.log

GitLab12.10のSSH経由でのGit呼び出しの調査用。

プロジェクト別、ユーザー別に上位20の呼び出しを検索します：

jq --raw-output --slurp '
  map(
    select(
      .username != null and
      .gl_project_path !=null
    )
  )
  | group_by(.username+.gl_project_path)
  | sort_by(-length)
  | limit(20; .[])
  | "count: \(length)\tuser: \(.[0].username)\tproject: \(.[0].gl_project_path)" ' \
  gitlab-shell.log

プロジェクト、ユーザー、コマンド別に上位20コールを検索します：

jq --raw-output --slurp '
  map(
    select(
      .command  != null and
      .username != null and
      .gl_project_path !=null
    )
  )
  | group_by(.username+.gl_project_path+.command)
  | sort_by(-length)
  | limit(20; .[])
  | "count: \(length)\tcommand: \(.[0].command)\tuser: \(.[0].username)\tproject: \(.[0].gl_project_path)" ' \
  gitlab-shell.log