Rails.logger
를 사용하지 마세요- 구조화된 (JSON) 로깅 사용하기
- 다중 대상 로깅
- 예외 처리
- 새 로그 파일과 관련된 추가 단계
- Kibana에서 새로운 로그 파일 찾기 (GitLab.com 전용)
- 로깅 가시성 제어
로깅 개발 가이드라인
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 로깅 문서를 참조하십시오.
구조화된 (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 로그 디렉터리을 참조하십시오. 여러분의 로그 메시지가 이미 있는 로그 파일 중 하나에 속할 수 있는지 확인하십시오.
- 좋은 장소가 없는 경우 새로운 파일을 생성하는 것도 고려할 수 있지만, 관리자에게 확인해야 합니다. 로그 파일은 사람들이 한 곳에서 관련 로그를 쉽게 검색할 수 있도록 해야 합니다. 예를 들어
geo.log
에는 GitLab Geo와 관련된 모든 로그가 포함되어 있습니다.- 새 파일을 만들려면:
- 파일 이름을 선택합니다 (예:
importer_json.log
). -
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!
클래스 메소드를 호출해야 합니다.- 로그를 기록하려는 클래스에서 로거를 인스턴스 변수로 초기화합니다:
attr_accessor :logger def initialize @logger = Gitlab::Import::Logger.build end
이것을 메모이즈하는 것이 유용합니다. 매번 로거를 만드는 것은 파일을 열어서 불필요한 오버헤드를 추가합니다.
- 파일 이름을 선택합니다 (예:
- 새 파일을 만들려면:
-
이제 코드에 로그 메시지를 삽입합니다. 로그를 추가할 때 모든 컨텍스트를 키-값 쌍으로 포함하는지 확인하십시오.
# 나쁨 logger.info("Unable to create project #{project.id}")
# 좋음 logger.info(message: "Unable to create project", project_id: project.id)
- 로그 메시지의 공통 기본 구조를 만드는 것이 중요합니다. 모든 메시지에
current_user_id
와project_id
등이 있으면 시간별로 사용자의 활동을 검색하기가 쉬워집니다.
JSON 로깅의 암묵적 스키마
구조화된 로그를 색인화하기 위해 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: "정보")
이 메시지는 FancyMultiLogger.loggers
에 등록된 각 로거에 의해 로깅됩니다.
로깅에 문자열 또는 해시 전달
문자열 또는 해시를 MultiDestinationLogger
에 전달할 때 로그 라인은 설정된 LOGGERS
의 종류에 따라 다르게 포맷됩니다.
예를 들어, 이전 예제에서 로그러를 부분적으로 정의하면 다음과 같습니다:
module Gitlab
# AppTextLogger와 유사
class UnstructuredLogger < Gitlab::Logger
...
end
# AppJsonLogger와 유사
class StructuredLogger < Gitlab::JsonLogger
...
end
end
- 문자열 전달 시
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=>"정보"}
- 해시 전달 시
FancyMultiLogger.info({: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=>"이것은 내 메시지입니다", :project_id=>123}
로깅 컨텍스트 메타데이터(웹 요청 및 Sidekiq을 통해)
Gitlab::ApplicationContext
는 요청 수명 주기에 메타데이터를 저장하고 나중에 웹 요청이나 Sidekiq 로그에 추가할 수 있습니다.
API, Rails 및 Sidekiq 로그에는 이 컨텍스트 정보가 포함된 meta.
로 시작하는 필드가 있습니다.
진입점은 다음 위치에서 볼 수 있습니다.
속성 추가
새로운 속성을 추가할 때는 with_context
(또는 push
) 메서드에 해시 내에서 전달하고, 새 값이 표현식이 아니면 Proc를 전달하세요.
Gitlab::ApplicationContext
를 변경하여 이러한 새로운 값이 허용되고 새로운 속성이 Labkit::Context
에서 사용되도록 확인하세요.
Kibana에서 시각화를 만드는 방법에 대해 알아보려면 HOWTO: Use Sidekiq metadata logs를 참조하세요.
현재 컨텍스트의 필드는 웹 요청을 통해 트리거된 Sidekiq 작업에 대해서만 로깅됩니다. 자세한 내용은 후속 작업을 참조하세요.
로깅 컨텍스트 메타데이터(작업자를 통해)
작업자에 추가 메타데이터를 첨부하는 데는 ApplicationWorker#log_extra_metadata_on_done
메서드를 사용할 수 있습니다. 이 방법을 사용하면 완료된 작업 페이로드를 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
의 실행별로 파기된 아티팩트 수를 기록하는 이 예제를 참조하세요.
예외 처리
예외를 catch하고 추적하려는 일이 종종 발생합니다.
매뉴얼으로 예외를 로깅하는 것은 허용되지 않습니다. 왜냐하면:
- 매뉴얼으로 로깅된 예외는 기밀 데이터를 누설시킬 수 있습니다.
- 매뉴얼 로깅된 예외는 매우 자주 백트레이스를 정리해야 하므로 보일러플레이트가 줄어듭니다.
- 매우 자주 매뉴얼으로 로깅된 예외는 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(구성된 경우)에 예외를 전송하고 개발 및 테스트 환경에서 예외를 다시 발생시킵니다.
모든 추적된 예외에 대해 추가적인 extra 매개변수를 고려해 보세요.
예시
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
의 모든 로그를 매 시간 돌려 사용하고, 압축된 파일을 최대 30개 유지합니다. GitLab.com에서는 해당 설정이 압축된 파일 6개로만 설정되어 있습니다. 이 설정은 대부분의 사용자에게 적합하지만, Omnibus GitLab에서 세부적으로 조정해야 할 수도 있습니다. -
GitLab.com에서 GitLab Rails에 의해 생성된 모든 새 JSON 로그 파일은 자동으로 GitLab Rails Kubernetes pod의 Elasticsearch로 전송됩니다(그리고 Kibana에서 사용 가능합니다). Gitaly 노드로부터 파일을 전달받아야 하는 경우 프로덕션 추적기에 이슈를 제출하거나
gitlab_fluentd
프로젝트에 MR(Merge Request)를 제출하세요. 이 예시를 확인하세요. -
GitLab CE/EE 문서 및 GitLab.com 런북를 반드시 업데이트하세요.
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% 이상 증가하지 않도록 주의하세요.
사양 변경 알림
사양 변경 알림의 예상되는 양이 많은 경우:
- 개발 환경에서만 로그를 남기세요.
- 필요한 경우, 테스트 환경에 로그를 기록하세요.