伐採開発ガイドライン

GitLabログは管理者と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)

これらのログにはいくつかの問題があります：

タイムスタンプやその他のコンテキスト情報（例えば、プロジェクトIDやユーザー）が欠けていることが多い。
複数の行にまたがっている場合があり、Elasticsearchで検索するのが困難です。
これらは共通の構造を持たないため、LogstashやFluentdのようなログフォワーダーでは解析が困難です。また、検索も難しくなります。

現在 GitLab.com では、production.log のメッセージは膨大な量とノイズのために Elasticsearch ではインデックス化されていません。Google Stackdriver ではインデックスされますが、それでもログを検索するのは難しくなります。詳しくはGitLab.com logging documentationをご覧ください。

構造化された(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 ロギングの使用方法

プロジェクトインポーターで発生したイベントをログに記録したいとします。作成されたイシューやマージリクエストなどを、インポーターの進行に合わせてログに記録したいとします。どうすればよいでしょうか：

GitLab Logs のリストを見て、あなたのログメッセージが既存のログファイルのどれかに属するかどうかを確認します。
適切な場所がない場合は、新しいファイル名を作成することも検討しましょう。ただし、そうすることに意味があるかどうかはメンテナーに確認しましょう。ログファイルは、適切なログを一箇所で簡単に検索できるようにすべきです。例えば、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 = Gitlab::Import::Logger.build
end
```
  ログを記録するたびに新しいロガーが作成されると、ファイルがオープンされ、不要なオーバーヘッドが追加されるためです。
次に、ログメッセージをコードに挿入します。ログを追加するときは、すべてのコンテキストをキーと値のペアとして含めるようにしてください：
```
# BAD
logger.info("Unable to create project #{project.id}")
```
```
# GOOD
logger.info(message: "Unable to create project", project_id: project.id)
```
ログメッセージの共通の基本構造を作るようにしてください。例えば、全てのメッセージは、current_user_id とproject_id を持ち、ある時間のユーザーによるアクティビティを検索しやすくします。

JSONロギング用の暗黙のスキーマ

構造化されたログをインデックスするために Elasticsearch のようなものを使用する場合、各ログフィールドの型にはスキーマがあります（そのスキーマが暗黙的/推論的であっても）。フィールドの値の型に一貫性を持たせることが重要で、そうでなければ、フィールドの検索やフィルタリングができなくなったり、ログイベント全体が削除されたりする可能性があります。この節の多くは Elasticsearch 固有の言い回しになっていますが、構造化ログのインデックスを作成するために使用する多くのシステムで使用できる概念です。GitLab.com では Elasticsearch を使ってログのインデックスを作成しています。

フィールドの型が明示的にマップされていない限り、Elasticsearch はそのフィールドの値の最初のインスタンスから型を推測します。型が異なるフィールド値のそれ以降のインスタンスはインデックスに登録されないか、場合によっては（スカラーとオブジェクトの衝突）ログ行全体が削除されます。

GitLab.comのロギングElasticsearchは、ignore_malformed、単純なマッピングの衝突（例えば、数値/文字列）があっても、ドキュメントのインデックスを作成することができます。

例：

# GOOD
logger.info(message: "Import error", error_code: 1, error: "I/O failure")

# BAD
logger.info(message: "Import error", error: 1)
logger.info(message: "Import error", error: "I/O failure")

# WORST
logger.info(message: "Import error", error: "I/O failure")
logger.info(message: "Import error", error: { message: "I/O failure" })

リスト要素は同じ型でなければなりません：

# GOOD
logger.info(a_list: ["foo", "1", "true"])

# BAD
logger.info(a_list: ["foo", 1, true])

リソース：

クラス属性を含める

構造化されたログは、class コード内の特定の場所からログに記録されたすべてのエントリを検索可能にするために class、常に属性を含むべきです。class この class属性を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::LoggerLogger クラスを継承するクラスでなければなりません。例えば、Gitlab::Logger以下の例のユーザー定義ロガーは Gitlab::Logger、それぞれGitlab::JsonLogger をGitlab::Logger継承して Gitlab::Loggerいます。

としてロガーの 1 つを指定する必要がありますprimary_logger。この primary_loggerマルチデスティネーションロガーに関する情報がアプリケーションで表示されるとき（たとえば、Gitlab::Logger.read_latest メソッドを使用するとき）に使用されます。

次の例は、定義されたLOGGERS の 1 つを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
  # Similar to AppTextLogger
  class UnstructuredLogger < Gitlab::Logger
    ...
  end

  # Similar to AppJsonLogger
  class StructuredLogger < Gitlab::JsonLogger
    ...
  end
end

以下は、メッセージが両方のロガーでどのように処理されるかの例です。

文字列を渡す場合

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"}

ハッシュを渡す場合

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

私たちの HOWTO: Use Sidekiq metadata logsを参照してください。

コンテキストのフィールドは現在、Webリクエストを通じてトリガーされたSidekiqジョブに対してのみログに記録されます。詳細については、フォローアップ作業を参照してください。

コンテキストのメタデータのログ (ワーカーを通して)

ApplicationWorker#log_extra_metadata_on_done メソッドを使うことで、追加のメタデータをワーカーに添付できます。このメソッドを使用すると、実行されたジョブのペイロードと一緒に 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 メソッドの実行ごとに破棄されたアーティファクトの数をログに記録する例をご覧ください。

例外処理

例外をキャッチして、それを追跡したいことがよくあります。

例外の手動ロギングは禁止されていることに注意してください：

手動で記録された例外は機密データを漏洩する可能性があります、
手動で記録された例外は、しばしばバックトレースをきれいにする必要があります、
手動でログに記録された例外は、Sentryに追跡される必要があります、
手動でログに記録された例外はcorrelation_id を使わないので、リクエストやユーザー、例外が発生したコンテキストを特定するのが難しくなります、
手動でログに記録された例外は、複数のファイルにまたがって記録されることが多く、すべてのログファイルをスクレイピングする負担が増えます。

重複を避け、一貫した挙動を持つために、Gitlab::ErrorTracking は例外を追跡するヘルパーメソッドを提供します：

Gitlab::ErrorTracking.track_and_raise_exceptionこのメソッドはログを記録し、Sentry (設定されている場合) に例外を送信し、例外を再レイズします、
Gitlab::ErrorTracking.track_exceptionこのメソッドはログを記録し、(設定されていれば) Sentry に例外を送るだけです、
Gitlab::ErrorTracking.log_exceptionこのメソッドは例外をログに記録するだけで、Sentry に例外を送信しません、
Gitlab::ErrorTracking.track_and_raise_for_dev_exception: このメソッドはログを記録し、Sentry に例外を送信します (設定されている場合)。

以下の例では、Gitlab::ErrorTracking.track_and_raise_exception とGitlab::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

新しいログファイルによる追加手順

ログの保持設定を検討します。デフォルトでは、Omnibusは/var/log/gitlab/gitlab-rails/*.log のログを1時間ごとにローテーションし、最大30個の圧縮ファイルを保持します。GitLab.comでは、この設定は6つの圧縮ファイルのみです。ほとんどのユーザーはこの設定で十分でしょうが、Omnibus GitLabでは微調整が必要かもしれません。
GitLab.comでは、GitLab Railsによって生成されたすべての新しいJSONログファイルは、GitLab Rails Kubernetesポッド上のElasticsearchに自動的に転送されます（そしてKibanaで利用可能です）。Gitalyノードからファイルを転送する必要がある場合は、プロダクショントラッカーにイシューを提出するか、gitlab_fluentd プロジェクトにマージリクエストを提出してください。この例をご覧ください。
GitLab CE/EEドキュメントと GitLab.comランブックを必ず更新してください。

Kibanaで新しいログファイルを見つける（GitLab.comのみ）

GitLab.com では、GitLab Rails によって生成されたすべての新しい JSON ログファイルは、GitLab Rails Kubernetes ポッド上の Elasticsearch に自動的にシップされます（そして Kibana で利用できます）。json.subcomponent Kibana のフィールドでは、ログファイルの種類によってフィルタリング json.subcomponentすることができます。json.subcomponent 例えば json.subcomponent production_json.logから転送されたエントリはproduction_json になります。

また、Web/APIポッドからのログファイルは、Sidekiqポッドからのログファイルとは異なるインデックスに移動することも注目に値します。どこからログを記録するかによって、異なるインデックスパターンでログを見つけることができます。

ログの可視性の制御

ログが増加すると、未承認メッセージのバックログが増大する可能性があります。新しいログメッセージを追加するときは、ログ全体の量が10%以上増えないようにしてください。

非推奨のお知らせ

予想される非推奨通知の量が多い場合：

開発者環境でのみログを記録してください。
必要であれば、テスト環境でもログを記録してください。

伐採開発ガイドライン

使用しないでください`Rails.logger`

構造化された(JSON) ロギングを使う

JSON ロギングの使用方法

JSONロギング用の暗黙のスキーマ

クラス属性を含める

ログの持続時間

複数宛先ログ

マルチデスティネーションロギングの使い方

ロギングに文字列やハッシュを渡す場合

コンテキストのメタデータをログに記録する場合 (RailsまたはGrapeリクエストを通して)

属性の追加

コンテキストのメタデータのログ (ワーカーを通して)

例外処理

物件例

新しいログファイルによる追加手順

Kibanaで新しいログファイルを見つける（GitLab.comのみ）

ログの可視性の制御

非推奨のお知らせ

Help & feedback

Docs

Product

Feature availability and product trials

Get Help

伐採開発ガイドライン

使用しないでくださいRails.logger

構造化された(JSON) ロギングを使う

JSON ロギングの使用方法

JSONロギング用の暗黙のスキーマ

クラス属性を含める

ログの持続時間

複数宛先ログ

マルチデスティネーションロギングの使い方

ロギングに文字列やハッシュを渡す場合

コンテキストのメタデータをログに記録する場合 (RailsまたはGrapeリクエストを通して)

属性の追加

コンテキストのメタデータのログ (ワーカーを通して)

例外処理

物件例

新しいログファイルによる追加手順

Kibanaで新しいログファイルを見つける（GitLab.comのみ）

ログの可視性の制御

非推奨のお知らせ

Help & feedback

Docs

Product

Feature availability and product trials

Get Help

使用しないでください`Rails.logger`