• Rails.logger를 사용하지 마십시오
• 구조화된 (JSON) 로깅 사용
  • JSON 로깅 사용 방법
    • JSON 로깅을 위한 암시적 스키마
    • 클래스 속성 포함
    • 시간 기록
• 다중 대상 로깅
  • 다중 대상 로깅 사용 방법
  • 로깅에 문자열 또는 해시 전달
  • Rails 또는 Grape 요청을 통한 로깅 컨텍스트 메타데이터
    • 속성 추가
  • Worker를 통한 로깅 컨텍스트 메타데이터
• 예외 처리
  • 예시
• 새로운 로그 파일과 관련된 추가 단계
• 키바나(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)

이러한 로그에는 여러 문제가 있습니다:

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: "정보")

이 메시지는 FancyMultiLogger.loggers에 등록된 각 로거에 의해 기록됩니다.

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

MultiDestinationLogger에 문자열이나 해시를 전달할 때 지정된 LOGGERS 종류에 따라 로그 라인이 다양하게 포맷되어 처리될 수 있습니다.

예를 들어, 이전 예제의 로거를 일부로 정의하는 방법은 다음과 같습니다:

module Gitlab
  # AppTextLogger와 유사합니다
  class UnstructuredLogger < Gitlab::Logger
    ...
  end
  
  # AppJsonLogger와 유사합니다
  class StructuredLogger < Gitlab::JsonLogger
    ...
  end
end

1. 문자열 전달 시

FancyMultiLogger.info("정보")

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

# StructuredLogger
{:severity=>"INFO", :time=>"2020-01-13T11:02:41.559Z", :correlation_id=>"b1701f7ecc4be4bcd4c2d123b214e65a", :message=>"정보"}

1. 해시 전달 시

FancyMultiLogger.info({:message=>"내 메시지입니다", :project_id=>123})

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

# StructuredLogger
{:severity=>"INFO", :time=>"2020-01-13T11:06:09.851Z", :correlation_id=>"d7e0886f096db9a8526a4f89da0e45f6", :message=>"내 메시지입니다", :project_id=>123}

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

Gitlab::ApplicationContext는 요청 수명주기에서 메타데이터를 저장하고, 이후 웹 요청 또는 Sidekiq 로그에 추가할 수 있습니다.

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

Entry point는 다음에서 확인할 수 있습니다:

• ApplicationController
• 외부 API
• 내부 API

속성 추가

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

• with_context (또는 push) 메서드에 해시 내에서 전달합니다 (메서드 또는 변수가 즉시 평가되지 않도록 Proc를 전달하세요)
• Gitlab::ApplicationContext에서 이러한 새 값들을 허용하도록 변경합니다
• 새로운 속성이 Labkit::Context에서 허용되도록 합니다

Kibana에서 시각화를 작성하는 방법에 대한 자세한 내용은 HOWTO: Use Sidekiq metadata logs에서 확인하세요.

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

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

추가적인 메타데이터는 ApplicationWorker#log_extra_metadata_on_done 메서드를 사용하여 worker에 첨부할 수 있습니다. 이 메서드를 사용하면 나중에 작업 페이로드가 Kibana에 로그로 기록됩니다.

class MyExampleWorker
  include ApplicationWorker
  
  def perform(*args)
    # Worker가 작업을 수행함
    # ...
    
    # value의 내용은 `json.extra.my_example_worker.my_key`에 표시됩니다
    log_extra_metadata_on_done(:my_key, value)
  end
end

ExpireArtifactsWorker 실행 시 소멸된 artifacts 수를 기록하는 이 예제를 확인하세요.

예외 처리

예외가 발생하고 추적하고자 하는 경우가 많습니다.

매뉴얼 로깅된 예외는 허가되지 않으며 다음과 같은 이유 때문입니다:

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에 전송하며 개발 및 테스트 환경에서 예외를 다시 발생시킵니다.

각 추적된 예외에 대한 추가 추가 매개변수를 고려하세요.

예시

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

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

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 노드에서 해당 파일을 전달해야 하는 경우 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 필드를 사용하여 다양한 유형의 로그 파일을 필터링할 수 있습니다. 예를 들어, json.subcomponent는 production_json.log에서 전달된 항목의 경우 production_json이 될 것입니다.

또한 웹/API pod의 로그 파일과 Sidekiq pod의 로그 파일은 서로 다른 인덱스로 이동합니다. 로그를 기록하는 위치에 따라 로그를 다른 인덱스 패턴에서 찾을 수 있습니다.

로깅 가시성 제어

로그의 증가는 미확인 메시지의 증가된 누적으로 이어질 수 있습니다. 새로운 로그 메시지를 추가할 때, 전체 로깅 양이 10% 이상 증가하지 않도록 주의하십시오.

사용 중단 공지

사용 중단 공지의 예상 양이 많은 경우:

• 개발 환경에서만 기록합니다.
• 필요한 경우 테스트 환경에서도 기록합니다.