Help us learn about your current experience with the documentation. Take the survey.

使用 jq 解析 GitLab 日志

  • Tier: Free, Premium, Ultimate
  • Offering: GitLab Self-Managed

我们建议尽可能使用日志聚合和搜索工具,如 Kibana 和 Splunk, 但如果这些工具不可用,您仍然可以使用 jq 快速解析 JSON 格式的 GitLab 日志

特别是为了汇总错误事件和基本使用统计信息, GitLab 支持团队提供了专门的 fast-stats 工具

什么是 JQ?

正如其手册中所述,jq 是一个命令行 JSON 处理器。以下示例 包括针对解析 GitLab 日志文件的用例。

解析日志

下面列出的示例通过其相对的 Linux 包安装路径和默认文件名来寻址各自的日志文件。 在 GitLab 日志部分 中找到相应的完整路径。

压缩日志

当日志文件被轮转时,它们会以 Unix 时间戳格式重命名并使用 gzip 压缩。生成的文件名看起来像 @40000000624492fa18da6f34.s。这些文件在解析前必须与较新的日志文件不同处理:

  • 要解压缩文件,请使用 gunzip -S .s @40000000624492fa18da6f34.s,将 文件名替换为您的压缩日志文件名。
  • 要直接读取或管道传输文件,请使用 zcatzless
  • 要搜索文件内容,请使用 zgrep

通用命令

将彩色化的 jq 输出管道传输到 less

jq . <FILE> -C | less -R

搜索术语并漂亮打印所有匹配行

grep <TERM> <FILE> | jq .

跳过无效的 JSON 行

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

默认情况下,当 jq 遇到无效 JSON 的行时会报错。 这会跳过所有无效行并解析其余部分。

打印 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.loggitlab-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>

查找 Gitaly 调用超过 5 次的所有项目请求

grep <PROJECT_NAME> <FILE> | jq 'select(.gitaly_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

打印顶级 API 用户代理

jq --raw-output '
  select(.remote_ip != "127.0.0.1") | [
    (.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H…")),
    ."meta.caller_id", .username, .ua
  ] | @tsv' api_json.log | sort | uniq -c \
  | grep --invert-match --extended-regexp '^\s+\d{1,3}\b'

示例输出:

 1234 …01-12T01…  GET /api/:version/projects/:id/pipelines  some_user  # plus browser details; OK
54321 …01-12T01…  POST /api/:version/projects/:id/repository/files/:file_path/raw  some_bot
 5678 …01-12T01…  PATCH /api/:version/jobs/:id/trace gitlab-runner     # plus version details; OK

此示例显示自定义工具或脚本导致意外的高请求率 (>15 RPS)。 这种情况下的用户代理可以是专门的第三方客户端, 或通用工具如 curl

按小时聚合有助于:

您也可以使用 fast-stats top(见页面顶部)来提取这些用户或机器人的性能统计信息。

解析 gitlab-rails/importer.log

要排查项目导入迁移问题,请运行以下命令:

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

有关常见问题,请参阅故障排除

解析 gitlab-workhorse/current

打印顶级 Workhorse 用户代理

jq --raw-output '
  select(.remote_ip != "127.0.0.1") | [
    (.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H…")),
    .remote_ip, .uri, .user_agent
  ] | @tsv' current |
  sort | uniq -c

API ua 示例类似, 此输出中的许多意外用户代理表示未优化的脚本。 预期的用户代理包括 gitlab-runnerGitLab-Shell 和浏览器。

通过增加 check_interval 设置 可以减少运行器检查新作业的性能影响。

解析 gitlab-rails/geo.log

查找最常见的 Geo 同步错误

如果 geo:status Rake 任务 反复报告某些项目从未达到 100%, 以下命令有助于关注最常见的错误。

jq --raw-output 'select(.severity == "ERROR") | [
  (.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H…%M…")),
  .class, .id, .message, .error
  ] | @tsv' geo.log \
  | sort | uniq -c

有关特定错误消息的建议,请参阅我们的 Geo 故障排除页面

解析 gitaly/current

使用以下示例来排查 Gitaly 问题

查找从 Web 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'
  ...

用户和项目活动概览类型

jq --raw-output '[
    (.time | split(".")[0] | strptime("%Y-%m-%dT%H:%M:%S") | strftime("…%m-%dT%H…")),
    .username, ."grpc.method", ."grpc.request.glProjectPath"
  ] | @tsv' current | sort | uniq -c \
  | grep --invert-match --extended-regexp '^\s+\d{1,3}\b'

示例输出:

 5678 …01-12T01…     ReferenceTransactionHook  # Praefect operation; OK
54321 …01-12T01…  some_bot   GetBlobs    namespace/subgroup/project
 1234 …01-12T01…  some_user  FindCommit  namespace/subgroup/project

此示例显示自定义工具或脚本导致 Gitaly 上意外的高请求率 (>15 RPS)。 按小时聚合有助于:

您也可以使用 fast-stats top(见页面顶部)来提取这些用户或机器人的性能统计信息。

查找受致命 Git 问题影响的所有项目

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

解析 gitlab-shell/gitlab-shell.log

用于通过 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