읽을 수 없는 엉망이 되지 않도록 로그 유지

이상하고 해결할 수 없는 것처럼 보이는 버그가 발생하면 로깅을 개선하는 것이 최선의 조치가 될 수 있습니다. 훌륭한 로깅은 전체 버그 클래스를 감지하고 수정하는 가장 쉬운 방법입니다. 충분한 정보를 기록하면 요청 중에 데이터가 어떻게 변경되는지 확인할 수 있습니다. 다른 서비스에 대한 호출을 추적하고 응답을 조사할 수 있습니다. 사실, 디버거가 실패했을 때 로깅은 내가 겪었던 가장 어려운 버그를 수정하는 데 도움이 되었습니다.

하지만 너무 많이 기록하면 로그 파일이 순식간에 읽을 수 없고 도움이 되지 않는 메시지로 뒤죽박죽이 됩니다. 데이터 더미에서 관심 있는 정보만 잘라낼 수 있는 방법은 무엇입니까? 나중에 필터링하기 쉬운 방식으로 메시지를 인쇄할 수 있습니까?

로그 메시지 표시

Rails에는 관련 로그 메시지를 빠르게 분류하는 데 도움이 되는 TaggedLogging이 포함되어 있습니다. 로거에 태그를 지정하면 메시지 시작 부분에 마커가 표시됩니다. 따라서 다음 대신:

Finding people...
  Person Load (0.3ms)  SELECT "people".* FROM "people"
Found 0 people!

Rails 로거에 태그를 지정할 수 있습니다.

logger.tagged("People") do
  logger.debug "Finding people..."
  @people = Person.all
  logger.debug "Found #{@people.length} people!"
end

다음과 같은 내용이 표시됩니다.

[People] Finding people...
[People]   Person Load (0.3ms)  SELECT "people".* FROM "people"
[People] Found 0 people!

이제 서로 다른 것에 관심이 있는 로그 메시지를 볼 수 있습니다. 다릅니다.

태그가 지정된 일부 로거의 예

더 자주 기록하고 더 복잡한 것을 기록할수록 해당 태그가 메시지를 더 명확하게 만드는 영역을 자연스럽게 알게 될 것입니다. 하지만 태그가 있는 로깅이 특히 도움이 된다고 생각한 곳이 몇 군데 있습니다. 보통 바로 태그하겠습니다.

다른 API에 대한 요청을 기록할 수 있습니다.

logger.tagged("GitHub API") do
  uri = URI("https://api.github.com/repos/rails/rails/tags")

  logger.info { "Fetching #{uri}" }
  tags = JSON.parse(Net::HTTP.get(uri))
  logger.info { "First tag: #{tags.first["name"]}" }
end

[GitHub API] Fetching https://api.github.com/repos/rails/rails/tags
[GitHub API] First tag: v4.2.4.rc1

이렇게 하면 앱이 해당 API와 통신하는 방법과 시기를 쉽게 확인할 수 있습니다.

(이는 Faraday 미들웨어 또는 게이트웨이를 통해서만 서버와 통신하는 경우에 특히 잘 작동합니다.)

백그라운드 작업은 태그가 지정된 로깅에서도 잘 작동합니다.

require "active_support/tagged_logging"

Resque.logger = ActiveSupport::TaggedLogging.new(Resque.logger)

module LoggedJob
  def around_perform_log_job(*args)
    logger.tagged(name) do
      logger.info { "Performing #{name} with #{args.inspect}" }
      yield
    end
  end
end

class MyJob
  extend LoggedJob

  def self.perform(*args)
    ...
  end
end

이제 LoggedJob을 확장하는 모든 작업에는 해당 작업의 클래스 이름으로 태그가 지정된 모든 로그 메시지가 있습니다.

로그인한 사용자가 있는 경우 사용자 ID로 메시지에 태그를 지정할 수 있습니다.

logger.tagged(current_user_id ? "user-#{current_user_id}" : "user-anonymous") do
  logger.debug "Finding people..."
  @people = Person.all
  logger.debug "Found #{@people.length} people!"
end

[user-123] Finding people...
[user-123]   Person Load (0.3ms)  SELECT "people".* FROM "people"
[user-123] Found 0 people!

마지막으로 config/environments/production.rb에 한 줄을 추가하면 (또는 development.rb ), Rails가 자동으로 메시지에 태그를 지정하도록 할 수 있습니다.

config.log_tags = [ :subdomain, :uuid ]

log_tags 모든 Rails 로그 항목의 시작 부분에 표시하려는 태그를 나열합니다. 각 기호는 ActionDispatch::Request의 메서드를 참조하므로 :uuid request.uuid를 의미합니다. .

request을 받는 Proc를 전달할 수도 있습니다. 개체:

config.log_tags = [ :subdomain, :uuid, lambda { |request| request.headers["User-Agent"] } ]

하지만 그렇게 자주 보지는 않습니다.

다음과 같은 기본 태그가 좋습니다. uuid 하나의 요청에서 발생하는 모든 로그 항목을 함께 묶을 수 있으며 서버에 세션을 유지하는 경우 세션 ID도 유용합니다. 이러한 태그와 충분한 메시지를 사용하면 앱에서 매우 복잡한 경로를 추적할 수 있습니다. 그리고 일반적으로 이것이 어떻게 끔찍한 버그가 발생했는지 알아내는 데 필요한 것입니다.

앱에서 Rails 로거를 얼마나 사용하십니까? 태그 로깅을 시도했습니까? 그렇지 않은 경우 장소를 찾으십시오. 사용자가 수행한 작업에 태그를 지정하는 것이 좋습니다. 다음에 미친 다단계 버그를 디버깅해야 할 때 도움이 될 것입니다.

로깅 및 기타 디버깅 기술에 대해 더 자세히 알고 싶다면 앱을 만들 때 마주하게 될 오류를 찾고 수정하는 데 전체 장을 할애했습니다. 여기에서 첫 번째 챕터를 무료로 받아보세요.