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

日志开发指南

GitLab Logs 对管理员和 GitLab 团队成员来说都至关重要, 能够帮助他们在生产环境中诊断问题。

不要使用 Rails.logger

目前所有 Rails.logger 调用都会保存到 production.log 中,该文件混合了 Rails 的日志 和开发者在代码库中插入的其他调用。例如:

Started GET "/gitlabhq/yaml_db/tree/master" for 168.111.56.1 at 2015-02-12 19:34:53 +0200
Processing by Projects::TreeController#show as HTML
  Parameters: {"project_id"=>"gitlabhq/yaml_db", "id"=>"master"}

  ...

  Namespaces"."created_at" DESC, "namespaces"."id" DESC LIMIT 1 [["id", 26]]
  CACHE (0.0ms) SELECT  "members".* FROM "members"  WHERE "members"."source_type" = 'Project' AND "members"."type" IN ('ProjectMember') AND "members"."source_id" = $1 AND "members"."source_type" = $2 AND "members"."user_id" = 1  ORDER BY "members"."created_at" DESC, "members"."id" DESC LIMIT 1  [["source_id", 18], ["source_type", "Project"]]
  CACHE (0.0ms) SELECT  "members".* FROM "members"  WHERE "members"."source_type" = 'Project' AND "members".
  (1.4ms) SELECT COUNT(*) FROM "merge_requests"  WHERE "merge_requests"."target_project_id" = $1 AND ("merge_requests"."state" IN ('opened','reopened')) [["target_project_id", 18]]
  Rendered layouts/nav/_project.html.haml (28.0ms)
  Rendered layouts/_collapse_button.html.haml (0.2ms)
  Rendered layouts/_flash.html.haml (0.1ms)
  Rendered layouts/_page.html.haml (32.9ms)
Completed 200 OK in 166ms (Views: 117.4ms | ActiveRecord: 27.2ms)

这些日志存在以下问题:

  1. 它们通常缺少时间戳或其他上下文信息(例如项目 ID 或用户)
  2. 它们可能跨越多行,这使得通过 Elasticsearch 查找变得困难
  3. 它们缺乏统一的结构,使得 Logstash 或 Fluentd 等日志转发器难以解析。 这也使得日志搜索变得困难

目前在 GitLab.com 上,由于 production.log 的巨大数量和噪音,其中的任何消息 都不会被 Elasticsearch 索引。这些日志最终会出现在 Google Stackdriver 中, 但在那里搜索仍然更加困难。更多详情请参阅 GitLab.com 日志文档

使用结构化(JSON)日志

结构化日志解决了这些问题。考虑来自 API 请求的示例:

{"time":"2018-10-29T12:49:42.123Z","severity":"INFO","duration":709.08,"db":14.59,"view":694.49,"status":200,"method":"GET","path":"/api/v4/projects","params":[{"key":"action","value":"git-upload-pack"},{"key":"changes","value":"_any"},{"key":"key_id","value":"secret"},{"key":"secret_token","value":"[FILTERED]"}],"host":"localhost","ip":"::1","ua":"Ruby","route":"/api/:version/projects","user_id":1,"username":"root","queue_duration":100.31,"gitaly_calls":30}

在单行中,我们包含了用户理解发生了什么所需的所有信息:时间戳、HTTP 方法和路径、 用户 ID 等。

如何使用 JSON 日志

假设您想记录项目导入器中发生的事件。您希望在导入器进行过程中记录创建的问题、 合并请求等。以下是操作步骤:

  1. 查看 GitLab Logs 列表,看看您的日志消息 是否可能属于现有的某个日志文件

  2. 如果没有合适的位置,考虑创建一个新文件名,但请与维护者确认这样做是否合理。 日志文件应该让人们能够在一个地方轻松搜索相关日志。例如,geo.log 包含所有 与 GitLab Geo 相关的日志。要创建新文件:

    1. 选择一个文件名(例如 importer_json.log

    2. 创建 Gitlab::JsonLogger 的新子类:

      module Gitlab
        module Import
          class Logger < ::Gitlab::JsonLogger
            def self.file_name_noext
              'importer'
            end
          end
         end
      end

      默认情况下,Gitlab::JsonLogger 会在日志条目中包含应用程序上下文元数据。 如果您的日志记录器预期在应用程序请求之外被调用(例如在 rake 任务中), 或者被可能参与构建应用程序上下文的底层代码调用(例如数据库连接代码), 您应该为您的日志记录器类调用类方法 exclude_context!,如下所示:

      module Gitlab
        module Database
          module LoadBalancing
            class Logger < ::Gitlab::JsonLogger
              exclude_context!
      
              def self.file_name_noext
                'database_load_balancing'
              end
            end
          end
        end
      end
    3. 在您想要记录日志的类中,可以将日志记录器初始化为实例变量:

      attr_accessor :logger
      
      def initialize
        @logger = ::Import::Framework::Logger.build
      end

      将日志记录器记忆化(memoize)很有用,因为每次记录日志时创建新的日志记录器 会打开文件并增加不必要的开销。

  3. 现在在您的代码中插入日志消息。添加日志时,确保将所有上下文作为键值对包含:

    # 不好的做法
    logger.info("Unable to create project #{project.id}")
    # 好的做法
    logger.info(message: "Unable to create project", project_id: project.id)
  4. 确保为您的日志消息创建一个通用的基础结构。例如,所有消息可能都包含 current_user_idproject_id,以便更容易按用户和时间搜索活动。

JSON 日志的隐式模式

当使用 Elasticsearch 等工具来索引结构化日志时,每个日志字段都有其类型模式 (即使该模式是隐式的/推断的)。保持字段值类型的一致性非常重要,否则可能会 破坏在这些字段上搜索/过滤的能力,甚至导致整个日志事件被丢弃。虽然本节中的 许多内容是以 Elasticsearch 特定的方式表述的,但这些概念应该适用于您可能用来 索引结构化日志的许多系统。GitLab.com 使用 Elasticsearch 来索引日志数据。

除非明确映射字段类型,否则 Elasticsearch 会根据它看到的该字段值的第一个实例 推断类型。后续具有不同类型的该字段值实例要么无法被索引,要么在某些情况下 (标量/对象冲突),整个日志行会被丢弃。

GitLab.com 的日志 Elasticsearch 设置了 ignore_malformed, 这允许在存在较简单的映射冲突(例如数字/字符串)时仍然索引文档, 尽管受影响字段的索引会失效。

示例:

# 好的做法
logger.info(message: "Import error", error_code: 1, error: "I/O failure")

# 不好的做法
logger.info(message: "Import error", error: 1)
logger.info(message: "Import error", error: "I/O failure")

# 最差的做法
logger.info(message: "Import error", error: "I/O failure")
logger.info(message: "Import error", error: { message: "I/O failure" })

列表元素必须是相同类型:

# 好的做法
logger.info(a_list: ["foo", "1", "true"])

# 不好的做法
logger.info(a_list: ["foo", 1, true])

资源:

包含类属性

结构化日志应始终包含一个 class 属性,以便从代码特定位置记录的所有条目都可以被找到。 要自动添加 class 属性,您可以包含 Gitlab::Loggable 模块 并使用 build_structured_payload 方法。

class MyClass
  include ::Gitlab::Loggable

  def my_method
    logger.info(build_structured_payload(message: 'log message', project_id: project_id))
  end

  private

  def logger
    @logger ||= Gitlab::AppJsonLogger.build
  end
end

记录持续时间

与时区类似,选择正确的时间单位进行日志记录可能会带来不必要的开销。因此, 当需要在秒、毫秒或其他单位之间进行选择时,优先选择秒作为浮点数 (具有微秒精度,即 Gitlab::InstrumentationHelper::DURATION_PRECISION)。

为了更轻松地在日志中跟踪时间,确保日志键以 _s 作为后缀,并在名称中包含 duration(例如 view_duration_s)。

多目标日志记录

GitLab 已从结构化日志过渡到 JSON 日志。然而,通过多目标日志记录,日志可以 以多种格式记录。

如何使用多目标日志记录

创建一个新的日志记录器类,继承自 MultiDestinationLogger,并将日志记录器数组 添加到 LOGGERS 常量中。这些日志记录器应该是继承自 Gitlab::Logger 的类。 例如,以下示例中的用户定义日志记录器可以继承自 Gitlab::LoggerGitlab::JsonLogger

您必须将其中一个日志记录器指定为 primary_logger。当在应用程序中显示 此多目标日志记录器的信息时(例如使用 Gitlab::Logger.read_latest 方法), 会使用 primary_logger

以下示例将定义的 LOGGERS 之一设置为 primary_logger

module Gitlab
  class FancyMultiLogger < Gitlab::MultiDestinationLogger
    LOGGERS = [UnstructuredLogger, StructuredLogger].freeze

    def self.loggers
      LOGGERS
    end

    def primary_logger
      UnstructuredLogger
    end
  end
end

您现在可以在这个多日志记录器上调用常规的日志记录方法。例如:

FancyMultiLogger.info(message: "Information")

此消息由 FancyMultiLogger.loggers 中注册的每个日志记录器记录。

传递字符串或哈希进行日志记录

当向 MultiDestinationLogger 传递字符串或哈希时,根据设置的 LOGGERS 类型, 日志行的格式可能会有所不同。

例如,让我们部分定义前一个示例中的日志记录器:

module Gitlab
  # 类似于 AppTextLogger
  class UnstructuredLogger < Gitlab::Logger
    ...
  end

  # 类似于 AppJsonLogger
  class StructuredLogger < Gitlab::JsonLogger
    ...
  end
end

以下是消息如何被两个日志记录器处理的示例。

  1. 传递字符串时
FancyMultiLogger.info("Information")

# UnstructuredLogger
I, [2020-01-13T18:48:49.201Z #5647]  INFO -- : Information

# StructuredLogger
{:severity=>"INFO", :time=>"2020-01-13T11:02:41.559Z", :correlation_id=>"b1701f7ecc4be4bcd4c2d123b214e65a", :message=>"Information"}
  1. 传递哈希时
FancyMultiLogger.info({:message=>"This is my message", :project_id=>123})

# UnstructuredLogger
I, [2020-01-13T19:01:17.091Z #11056]  INFO -- : {"message"=>"Message", "project_id"=>"123"}

# StructuredLogger
{:severity=>"INFO", :time=>"2020-01-13T11:06:09.851Z", :correlation_id=>"d7e0886f096db9a8526a4f89da0e45f6", :message=>"This is my message", :project_id=>123}

日志记录上下文元数据(通过 Rails 或 Grape 请求)

Gitlab::ApplicationContext 在请求生命周期中存储元数据,然后可以将其添加到 Web 请求或 Sidekiq 日志中。

API、Rails 和 Sidekiq 日志包含以 meta. 开头的字段,其中包含此上下文信息。

入口点可以在以下位置看到:

添加属性

添加新属性时,确保它们在上面的入口点上下文中可用,并且:

  • 在传递给 with_context(或 push)方法的哈希中传递它们(如果方法或变量 不应该立即求值,请确保传递一个 Proc)
  • 修改 Gitlab::ApplicationContext 以接受这些新值
  • 确保新属性在 Labkit::Context 中被接受

有关在 Kibana 中创建可视化的更多知识,请参阅我们的 HOWTO: 使用 Sidekiq 元数据日志

目前,上下文字段仅在通过 Web 请求触发的 Sidekiq 作业中被记录。更多信息请参阅 后续工作

日志记录上下文元数据(通过 workers)

可以通过使用 ApplicationWorker#log_extra_metadata_on_done 方法将额外的元数据附加到 worker。使用此方法会添加元数据,这些元数据稍后会在 Kibana 中与完成的作业负载一起记录。

class MyExampleWorker
  include ApplicationWorker

  def perform(*args)
    # Worker performs work
    # ...

    # The contents of value will appear in Kibana under `json.extra.my_example_worker.my_key`
    log_extra_metadata_on_done(:my_key, value)
  end
end

请参阅此示例, 它记录了每次运行 ExpireArtifactsWorker 时销毁的工件数量。

异常处理

经常发生的情况是您捕获异常并想要跟踪它。

需要注意的是,不允许手动记录异常,因为:

  1. 手动记录的异常可能会泄露敏感数据
  2. 手动记录的异常通常需要清理回溯信息,这减少了样板代码
  3. 手动记录的异常通常也需要跟踪到 Sentry
  4. 手动记录的异常不使用 correlation_id,这使得很难将它们与引发异常的请求、 用户和上下文关联起来
  5. 手动记录的异常通常分布在多个文件中,这增加了扫描所有日志文件的负担

为了避免重复并保持行为一致,Gitlab::ErrorTracking 提供了跟踪异常的辅助方法:

  1. Gitlab::ErrorTracking.track_and_raise_exception:此方法记录异常, 将异常发送到 Sentry(如果已配置),然后重新引发异常
  2. Gitlab::ErrorTracking.track_exception:此方法仅记录异常 并将异常发送到 Sentry(如果已配置)
  3. Gitlab::ErrorTracking.log_exception:此方法仅记录异常, 不将异常发送到 Sentry
  4. Gitlab::ErrorTracking.track_and_raise_for_dev_exception:此方法记录异常, 将异常发送到 Sentry(如果已配置),然后重新引发异常 用于开发和测试环境

建议仅使用 Gitlab::ErrorTracking.track_and_raise_exceptionGitlab::ErrorTracking.track_exception,如下面的示例所示。

考虑添加额外的额外参数,为每个跟踪的异常提供更多上下文。

示例

class MyService < ::BaseService
  def execute
    project.perform_expensive_operation

    success
  rescue => e
    Gitlab::ErrorTracking.track_exception(e, project_id: project.id)

    error('Exception occurred')
  end
end
class MyService < ::BaseService
  def execute
    project.perform_expensive_operation

    success
  rescue => e
    Gitlab::ErrorTracking.track_and_raise_exception(e, project_id: project.id)
  end
end

默认日志位置

对于 GitLab Self-Managed 和 GitLab.com,GitLab 通过两种方式部署:

Omnibus GitLab 日志处理

Omnibus GitLab 在 /var/log/gitlab 内的组件特定目录中记录日志:

# ls -al /var/log/gitlab
total 200
drwxr-xr-x 27 root              root        4096 Apr 29 20:28 .
drwxrwxr-x 19 root              syslog      4096 Aug  5 04:08 ..
drwx------  2 gitlab-prometheus root        4096 Aug  6 04:08 alertmanager
drwx------  2 root              root        4096 Aug  6 04:08 crond
drwx------  2 git               root        4096 Aug  6 04:08 gitaly
drwx------  2 git               root        4096 Aug  6 04:08 gitlab-exporter
drwx------  2 git               root        4096 Aug  6 04:08 gitlab-kas
drwx------  2 git               root       45056 Aug  6 13:18 gitlab-rails
drwx------  2 git               root        4096 Aug  5 04:18 gitlab-shell
drwx------  2 git               root        4096 May 24  2023 gitlab-sshd
drwx------  2 git               root        4096 Aug  6 04:08 gitlab-workhorse
drwxr-xr-x  2 root              root       12288 Aug  1 00:20 lets-encrypt
drwx------  2 root              root        4096 Aug  6 04:08 logrotate
drwx------  2 git               root        4096 Aug  6 04:08 mailroom
drwxr-x---  2 root              gitlab-www 12288 Aug  6 00:18 nginx
drwx------  2 gitlab-prometheus root        4096 Aug  6 04:08 node-exporter
drwx------  2 gitlab-psql       root        4096 Aug  6 15:00 pgbouncer
drwx------  2 gitlab-psql       root        4096 Aug  6 04:08 postgres-exporter
drwx------  2 gitlab-psql       root        4096 Aug  6 04:08 postgresql
drwx------  2 gitlab-prometheus root        4096 Aug  6 04:08 prometheus
drwx------  2 git               root        4096 Aug  6 04:08 puma
drwxr-xr-x  2 root              root       32768 Aug  1 21:32 reconfigure
drwx------  2 gitlab-redis      root        4096 Aug  6 04:08 redis
drwx------  2 gitlab-redis      root        4096 Aug  6 04:08 redis-exporter
drwx------  2 registry          root        4096 Aug  6 04:08 registry
drwx------  2 gitlab-redis      root        4096 May  6 06:30 sentinel
drwx------  2 git               root        4096 Aug  6 13:05 sidekiq

您可以在上面的示例中看到,以下组件将日志存储在以下目录中:

组件 日志目录
GitLab Rails /var/log/gitlab/gitlab-rails
Gitaly /var/log/gitlab/gitaly
Sidekiq /var/log/gitlab/sidekiq
GitLab Workhorse /var/log/gitlab/gitlab-workhorse

GitLab Rails 目录可能是您想要查找与上述 Ruby 代码一起使用的日志文件的地方。

logrotate 用于监视所有 *.log 文件

Cloud Native GitLab 日志处理

Cloud Native GitLab pod 直接将 GitLab 日志写入 /var/log/gitlab,而不创建额外的子目录。 例如,webservice pod 在一个容器中运行 gitlab-workhorse,在另一个容器中运行 puma。 后者的日志文件目录如下:

git@gitlab-webservice-default-bbd9647d9-fpwg5:/$ ls -al /var/log/gitlab
total 181420
drwxr-xr-x 2 git  git       4096 Aug  2 22:58 .
drwxr-xr-x 4 root root      4096 Aug  2 22:57 ..
-rw-r--r-- 1 git  git          0 Aug  2 18:22 .gitkeep
-rw-r--r-- 1 git  git   46524128 Aug  6 20:18 api_json.log
-rw-r--r-- 1 git  git      19009 Aug  2 22:58 application_json.log
-rw-r--r-- 1 git  git        157 Aug  2 22:57 auth_json.log
-rw-r--r-- 1 git  git       1116 Aug  2 22:58 database_load_balancing.log
-rw-r--r-- 1 git  git         67 Aug  2 22:57 grpc.log
-rw-r--r-- 1 git  git          0 Aug  2 22:57 production.log
-rw-r--r-- 1 git  git  138436632 Aug  6 20:18 production_json.log
-rw-r--r-- 1 git  git         48 Aug  2 22:58 puma.stderr.log
-rw-r--r-- 1 git  git        266 Aug  2 22:58 puma.stdout.log
-rw-r--r-- 1 git  git         67 Aug  2 22:57 service_measurement.log
-rw-r--r-- 1 git  git         67 Aug  2 22:57 sidekiq_client.log
-rw-r--r-- 1 git  git     733809 Aug  6 20:18 web_exporter.log

gitlab-logger 用于跟踪 /var/log/gitlab 中的所有文件。每条日志行在必要时会转换为 JSON, 然后发送到 stdout,以便通过 kubectl logs 查看。

新日志文件的额外步骤

  1. 考虑日志保留设置。默认情况下,Omnibus 每小时轮换 /var/log/gitlab/gitlab-rails/*.log 中的 任何日志,并最多保留 30 个压缩文件。 在 GitLab.com 上,该设置只有 6 个压缩文件。这些设置对大多数用户来说应该足够了, 但您可能需要在 Omnibus GitLab 中调整它们。

  2. 在 GitLab.com 上,由 GitLab Rails 生成的所有新 JSON 日志文件会自动发送到 Elasticsearch(并在 Kibana 中可用),这些文件位于 GitLab Rails Kubernetes pod 上。 如果您需要从 Gitaly 节点转发该文件,请向 production tracker 提交问题,或向 gitlab_fluentd 项目提交合并请求。请参阅 此示例

  3. 确保更新 GitLab CE/EE 文档GitLab.com runbooks

在 Kibana 中查找新日志文件(仅限 GitLab.com)

在 GitLab.com 上,由 GitLab Rails 生成的所有新 JSON 日志文件会自动发送到 Elasticsearch(并在 Kibana 中可用),这些文件位于 GitLab Rails Kubernetes pod 上。 Kibana 中的 json.subcomponent 字段将允许您按不同类型的日志文件进行过滤。 例如,从 production_json.log 转发的条目的 json.subcomponent 将是 production_json

值得注意的是,来自 Web/API pod 的日志文件与来自 Sidekiq pod 的日志文件会进入不同的索引。 根据您记录日志的位置,您会在不同的索引模式中找到日志。

控制日志可见性

日志量的增加可能会导致未确认消息的积压增加。添加新日志消息时,确保它们不会使 日志总体量增加超过 10%。

弃用通知

如果预期的弃用通知量很大:

  • 仅在开发环境中记录它们
  • 如果需要,在测试环境中记录它们