Rails.logger를 사용하지 마십시오
구조화된(JSON) 로깅 사용
- JSON 로깅 사용 방법
다중 대상 로깅
예외 처리
- 예시
기본 로깅 위치
- Omnibus GitLab 로그 처리
- 클라우드 네이티브 GitLab 로그 처리
새로운 로그 파일과 관련된 추가 단계
Kibana에서 새로운 로그 파일 찾기 (GitLab.com 전용)
로깅 가시성 제어
- 폐지 공지

로깅 개발 가이드라인

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)

이러한 로그는 여러 문제점을 가지고 있습니다:

대부분의 경우 타임스탬프나 다른 맥락 정보(예: 프로젝트 ID 또는 사용자)가 부족합니다.
여러 줄에 걸쳐 있어 Elasticsearch를 통해 찾기 어렵습니다.
공통 구조가 없어 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 로깅 사용 방법

예를 들어 프로젝트 가져오기 중에 발생하는 이벤트를 로그로 기록하려고 합니다. 만들어진 이슈, 병합 요청 등이 프로젝트 가져오기가 진행됨에 따라 로그로 남길 것입니다. 이렇게 하려면 다음과 같이 하십시오:

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 = ::Import::Framework::Logger.build
end
```
  매번 로깅할 때마다 새로운 로거를 만드는 것은 불필요한 오버헤드를 추가하므로 로거를 메모이제하는 것이 유용합니다.

이제 코드에 로그 메시지를 삽입하십시오. 로그를 추가할 때 모든 맥락을 키-값 쌍으로 포함하도록 하십시오:

# 나쁨
logger.info("프로젝트를 만들 수 없음 #{project.id}")

# 좋음
logger.info(message: "프로젝트를 만들 수 없음", project_id: project.id)

로그 메시지의 공통 기본 구조를 만드는 것이 중요합니다. 예를 들어, 모든 메시지는 current_user_id 및 project_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::Logger 및 Gitlab::JsonLogger를 상속하고 있을 수 있습니다.

primary_logger 중 하나를 지정해야 합니다. primary_logger는 이 다중 대상 로거에 대한 정보를 애플리케이션에서 표시할 때(예: Gitlab::Logger.read_latest 메서드를 사용하는 등) 사용됩니다.

다음 예제에서는 정의된 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

문자열을 전달할 때

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는 요청 수명 주기에서 메타데이터를 저장하며, 이후에 웹 요청 또는 Sidekiq 로그에 추가할 수 있습니다.

API, Rails 및 Sidekiq 로그에는 이 컨텍스트 정보로 시작하는 필드가 포함됩니다.

진입점은 다음에서 확인할 수 있습니다:

속성 추가

새로운 속성을 추가할 때, 해당 속성이 위의 진입점 컨텍스트에서 노출되도록하고 다음을 확인하세요:

with_context (또는 push) 메소드에 해시 내부에서 전달(메소드 또는 변수가 즉시 평가되지 않도록 Proc를 전달해야 함)
Gitlab::ApplicationContext에서 이러한 새로운 값들을 받아들이도록 변경
새로운 속성이 Labkit::Context에서 허용되도록 확인

더 많은 정보를 얻으려면 HOWTO: Use Sidekiq metadata logs를 참조하여 Kibana에서 시각화를 생성하세요.

현재 컨텍스트의 필드는 웹 요청을 통해 트리거된 Sidekiq 작업에 대해서만 로그가 기록됩니다. 자세한 내용은 후속 작업을 참조하세요.

Worker를 통한 로깅 컨텍스트 메타데이터

작업자(worker)에 추가 메타데이터를 첨부할 수 있으며, 이는 ApplicationWorker#log_extra_metadata_on_done 메소드를 사용하여 구현됩니다. 이 방법을 사용하면 작업 완료 페이로드와 함께 Kibana에 로그된 메타데이터가 추가됩니다.

class MyExampleWorker
  include ApplicationWorker

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

    # value의 내용은 `json.extra.my_example_worker.my_key` 아래에 Kibana에서 표시됩니다.
    log_extra_metadata_on_done(:my_key, value)
  end
end

ExpireArtifactsWorker를 실행하는 동안 모든 환경에서 ExpireArtifactsWorker 실행 당 파기된 Artifact의 수를 기록하는 예시를 참조하세요.

예외 처리

예외를 catch하고 추적(track)하려는 경우가 많습니다.

수동으로 예외를 로깅하는 것은 허용되지 않으며, 그 이유는 다음과 같습니다:

수동으로 기록된 예외는 비밀 데이터를 유출시킬 수 있음,
수동으로 기록된 예외는 매우 자주 백트레이스를 정리해야 하므로 번거로움이 높음,
수동으로 기록된 예외는 종종 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로 예외를 전송하며, 개발 및 테스트 환경에서 예외를 다시 발생시킵니다.

각 추적된 예외에 대해 더 많은 컨텍스트를 제공하기 위해 추가적인 추가 매개변수를 고려하세요.

예시

class MyService < ::BaseService
  def execute
    project.perform_expensive_operation

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

    error('예외가 발생했습니다')
  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

기본 로깅 위치

Self-Managed 사용자 및 GitLab.com을 위해, GitLab은 두 가지 방식으로 배포됩니다:

Omnibus GitLab
Cloud Native GitLab는 Helm Chart를 통해 배포됩니다.

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
...

위 예시에서 볼 수 있듯이, 다음 구성 요소는 다음 디렉터리에 로그를 저장합니다:

구성 요소	로그 디렉터리
GitLab Rails	`/var/log/gitlab/gitlab-rails`
Gitaly	`/var/log/gitlab/gitaly`
Sidekiq	`/var/log/gitlab/sidekiq`

GitLab Rails 디렉터리는 아마도 위의 Ruby 코드와 함께 사용되는 로그 파일을 찾을 수 있는 곳입니다.

logrotate은 모든 *.log 파일을 감시하기 위해 사용됩니다.

클라우드 네이티브 GitLab 로그 처리

클라우드 네이티브 GitLab pod는 추가 하위 디렉터리를 생성하지 않고 /var/log/gitlab에 직접 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의 모든 파일을 tail합니다. 각 로그 라인은 필요에 따라 JSON으로 변환되어 stdout로 전송되어 kubectl logs를 통해 볼 수 있습니다.

새로운 로그 파일과 관련된 추가 단계

로그 유지 정책을 고려하세요. 기본적으로 Omnibus는 /var/log/gitlab/gitlab-rails/*.log의 로그를 매 시간 로테이션하고 압축된 파일을 최대 30개 유지합니다. GitLab.com에서는 해당 설정이 압축된 파일을 6개만 유지하도록 되어 있습니다. 이 설정은 대부분의 사용자에게 적합하지만 Omnibus GitLab에서 이를 조정해야 할 수 있습니다.
GitLab.com에서 GitLab Rails에 의해 생성된 모든 새로운 JSON 로그 파일은 자동으로 Elasticsearch로 전송되어 (Kibana에서 사용 가능) GitLab Rails Kubernetes pod에서 사용할 수 있습니다. Gitaly 노드에서 파일을 전달해야 하는 경우 프로덕션 추적기에 이슈를 제출하거나 gitlab_fluentd 프로젝트에 병합 요청을 제출하세요. 이 예제를 참조하세요.
GitLab CE/EE documentation 및 GitLab.com runbooks을 업데이트하세요.

Kibana에서 새로운 로그 파일 찾기 (GitLab.com 전용)

GitLab.com에서 GitLab Rails에 의해 생성된 모든 새로운 JSON 로그 파일은 자동으로 Elasticsearch로 전송되어 (Kibana에서 사용 가능) GitLab Rails Kubernetes pod에서 사용할 수 있습니다. Kibana의 json.subcomponent 필드를 사용하여 다양한 종류의 로그 파일로 필터링할 수 있습니다. 예를 들어 json.subcomponent는 production_json.log로부터 전달된 항목에 대해 production_json이 될 것입니다.

또한 로그 파일은 Web/API pod에서 Sidekiq pod로 이동하는 다른 인덱스에 있음을 주목할 가치가 있습니다. 로깅 위치에 따라 로그를 다른 인덱스 패턴에서 찾을 수 있습니다.

로깅 가시성 제어

로깅의 증가는 확인되지 않은 메시지의 증가된 대기열을 유발할 수 있습니다. 새로운 로그 메시지를 추가할 때 전체 로깅 양이 10% 이상 증가하지 않도록 주의하세요.

폐지 공지

예상되는 폐지 공지의 양이 많은 경우:

개발 환경에서만 로그를 남기세요.
필요한 경우 테스트 환경에서 로그를 남기세요.

로깅 개발 가이드라인

`Rails.logger`를 사용하지 마십시오

구조화된(JSON) 로깅 사용

JSON 로깅 사용 방법

JSON 로깅의 암시적 스키마

클래스 속성 포함

로깅 기간

다중 대상 로깅

다중 대상 로깅 사용 방법

로깅에 문자열 또는 해시 전달

Rails 또는 Grape 요청을 통한 로깅 컨텍스트 메타데이터

속성 추가

Worker를 통한 로깅 컨텍스트 메타데이터

예외 처리

예시

기본 로깅 위치

Omnibus GitLab 로그 처리

클라우드 네이티브 GitLab 로그 처리

새로운 로그 파일과 관련된 추가 단계

Kibana에서 새로운 로그 파일 찾기 (GitLab.com 전용)

로깅 가시성 제어

폐지 공지

도움말

기능 사용 가능성과 제품 평가판

도움받기

로깅 개발 가이드라인

Rails.logger를 사용하지 마십시오

구조화된(JSON) 로깅 사용

JSON 로깅 사용 방법

JSON 로깅의 암시적 스키마

클래스 속성 포함

로깅 기간

다중 대상 로깅

다중 대상 로깅 사용 방법

로깅에 문자열 또는 해시 전달

Rails 또는 Grape 요청을 통한 로깅 컨텍스트 메타데이터

속성 추가

Worker를 통한 로깅 컨텍스트 메타데이터

예외 처리

예시

기본 로깅 위치

Omnibus GitLab 로그 처리

클라우드 네이티브 GitLab 로그 처리

새로운 로그 파일과 관련된 추가 단계

Kibana에서 새로운 로그 파일 찾기 (GitLab.com 전용)

로깅 가시성 제어

폐지 공지

도움말

기능 사용 가능성과 제품 평가판

도움받기

`Rails.logger`를 사용하지 마십시오