• Rails.logger 사용 금지
• 구조화된 (JSON) 로깅 사용
  • JSON 로깅 사용 방법
    • JSON 로깅을 위한 암시적 스키마
    • 클래스 속성 포함
    • 로깅 기간
• 다중 대상 로깅
  • 다중 대상 로깅 사용법
  • 로깅에 문자열 또는 해시 전달
  • 로깅 컨텍스트 메타데이터(Rails 또는 Grape 요청을 통해)
    • 속성 추가
  • 로깅 컨텍스트 메타데이터(작업자를 통해)
• 예외 처리
  • 예제
• 새 로그 파일 추가 단계
• 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
...
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!를 호출해야 합니다.

   3. 로그를 남기고 싶은 클래스 내에서 로거를 인스턴스 변수로 초기화할 수 있습니다:

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

      로거를 메모이제이션하는 것이 유용합니다. 로그를 남길 때마다 새 로거를 만들면 불필요한 오버헤드가 발생합니다.

3. 이제 코드에 로그 메시지를 삽입하세요. 로그를 추가할 때는 모든 문맥을 키-값 쌍으로 포함해야 합니다.

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

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

4. 로그 메시지의 공통 기본 구조를 만들어야 합니다. 예를 들어, 모든 메시지에는 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])

자료:

• Elasticsearch 매핑 - 유형의 함정 회피
• Elasticsearch 매핑 유형

클래스 속성 포함

구조화된 로그에는 코드에서 특정 위치에서 로그된 모든 항목을 찾을 수 있도록 항상 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).

로그에서 시간 추적을 쉽게하기 위해 로그 키에는 이름에 duration를 포함하고 _s를 접미사로 가져야 합니다(예: 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

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

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

Entry point는 다음에서 볼 수 있습니다:

• ApplicationController
• External API
• Internal API

속성 추가

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

• with_context(또는 push) 메서드를 통해 해시 내에서 전달합니다 (메서드 또는 변수가 즉시 평가되지 않아야하는 경우 Proc를 전달해야 함)
• Gitlab::ApplicationContext가 이러한 새 값들을 수락하도록 바꿉니다
• 새로운 속성이 Labkit::Context에서 수락되는지 확인합니다.

자세한 내용은 HOWTO: Use Sidekiq metadata logs를 참조하여 Kibana에서 시각화를 작성하는 데 도움을 얻을 수 있습니다.

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

로깅 컨텍스트 메타데이터(작업자를 통해)

추가적인 메타데이터는 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 실행 시에 얼마나 많은 artifact가 소멸되었는지 로그하는 이 예제를 참조하십시오.

예외 처리

예외를 catch하고 추적하고 싶은 경우가 많습니다.

수동으로 예외를 로깅하는 것은 허용되지 않는데, 그 이유는:

1. 수동으로 로깅된 예외는 기밀 데이터를 유출시킬 수 있습니다.
2. 수동 로깅된 예외는 매우 자주 백트래이스를 정리해야 하므로 뼈대가 줄어듭니다.
3. 매뉴얼로 로깅된 예외는 대개 Sentry로 추적되어야 합니다.
4. 수동으로 로깅된 예외는 correlation_id를 사용하지 않으므로 해당 예외가 발생한 요청, 사용자 및 컨텍스트를 식별하기가 어렵습니다.
5. 수동으로 로깅된 예외는 종종 여러 파일에 존재하여 모든 로깅 파일을 스크랩하는 부담을 늘립니다.

중복을 피하고 일관된 동작을 갖기 위해, Gitlab::ErrorTracking은 다음과 같은 helper 메서드를 제공합니다:

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로 보내며(구성되어 있는 경우), 개발 및 테스트 환경에서 예외를 다시 발생시킵니다.

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

예제

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

새 로그 파일 추가 단계

1. 로그 보유 설정을 고려하세요. 기본적으로 Omnibus는 /var/log/gitlab/gitlab-rails/*.log의 로그를 매 시간 로테이션하고 압축된 파일을 최대 30개 유지합니다. GitLab.com에서는 해당 설정이 압축된 파일 6개로만 제한됩니다. 이 설정은 대부분의 사용자에게 적합하지만, Omnibus GitLab에서 조정이 필요할 수 있습니다.

2. GitLab.com에서 GitLab Rails에 의해 생성된 모든 새 JSON 로그 파일은 자동으로 GitLab Rails Kubernetes pod의 Elasticsearch로 전송됩니다(Kibana에서 사용 가능). Gitaly 노드에서 파일을 전달받아야 하는 경우, 프로덕션 트래커에 이슈를 제출하거나 gitlab_fluentd 프로젝트에 병합 요청을 제출하세요. 이 예시를 참조하세요.

3. GitLab CE/EE 문서 및 GitLab.com runbook를 반드시 업데이트하세요.

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

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

Web/API pod의 로그 파일과 Sidekiq pod의 로그 파일은 서로 다른 인덱스에 저장됩니다. 로그를 남기는 위치에 따라 다른 인덱스 패턴에서 로그를 찾을 수 있습니다.

로깅 가시성 제어

로그의 증가로 미확인 메시지의 백로그가 생성될 수 있습니다. 새로운 로그 메시지를 추가할 때 전체 로깅 양이 10% 이상 증가하지 않도록 주의하세요.

폐지 공지사항

폐지 공지사항의 예상되는 양이 크다면:

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