Rails의 서버 처리 시간을 Server Timing을 사용하여 시각화

소개

개발 환경의 Rails 서버 처리 시간을 손쉽게 시각화하는 방법으로 ActiveSupport::Notifications를 사용하여 서버의 처리 속도를 측정하고 Server Timing을 사용하여 시각화하는 방법을 소개합니다.

대상 독자

Rails 사용

Chrome과 같은 유효성 검사 도구를 사용하고 있습니다

서버 처리 속도를 손쉽게 측정하고 시각화하고 싶습니다.

완성되는 것

Chrome 유효성 검사 도구에서 대상 통신을 선택하고 Timing 탭을 선택하면 아래 그림과 같이 Server Timing을 볼 수 있습니다.


이는 데이터베이스 쿼리를 처리하는 데 4.26ms, 뷰를 빌드하는 데 22.63ms, UserController#index로 총 35.22ms가 걸렸음을 나타냅니다.

ActiveSupport::Notifications란?

Ruby용 측정 API를 제공하는 라이브러리입니다.
이벤트의 계측과 계측 결과를 구독하는 구조가 준비되어 있어, 이러한 느낌으로 간단하게 이용할 수 있습니다.

# 購読
ActiveSupport::Notifications.subscribe("my.event") do |name, start, finish, id, payload|
  name    # => イベント名: "my.event"
  start   # => 計測開始時刻: 2020-10-18 12:34:56 +0900
  finish  # => 計測終了時刻: 2020-10-18 12:34:56 +0900
  id      # => ユニークなイベントのID: "xxxxxxxxxxxxx"
  payload # => ペイロード・追加情報(ハッシュ): {data: :hoge}
end

# 計測
ActiveSupport::Notifications.instrument("my.event", data: :hoge) do
  # イベントを実行
end

Server Timing이란?

서버 측의 처리 시간을 HTTP 헤더를 통해 통신하는 구조입니다.
응답 헤더의 Server-Timing 헤더 필드에 측정 시간과 같은 정보를 추가하면 유효성 검사 도구가 자동으로 시각화됩니다.

기법

기본형: 名前;desc=説明文;dur=計測時間

측정 시간의 합계를 나타낼 때 이름을 total로 함

둘 이상이면 쉼표로 구분하십시오

결합하다

우선, 서버의 처리 시간을 계측할 필요가 있습니다만, 실은 Rails 에서는 벌써 그 계측이 process_action.action_controller 라고 하는 이름으로 행해지고 있습니다. 그러므로, 구독하는 부분으로부터 작성하면 됩니다.

config/initializer에 다음과 유사한 파일을 만듭니다.

config/initializers/server_timing.rb

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |*args|
  # ActiveSupport::Notifications::Event は引数をそのまま受け渡すと、いい感じにデータを加工してくれます
  event = ActiveSupport::Notifications::Event.new(*args)

  duration = event.duration   # 処理時間
  payload = event.payload     # ペイロード

  controller_name = payload.controller # コントローラ名
  action_name = payload.action         # アクション名
  db_runtime = payload.db_runtime      # データベースへのクエリ実行にかかった時間
  view_runtime = payload.view_runtime  # ビューにかかった合計時間
  server_timing = "total;desc=\"#{controller_name}\##{action_name}\";dur=#{duration}, " \
           "db;dur=#{db_runtime}" \
           "view;dur=#{view_runtime}"
end

"process_action.action_controller"의 페이로드 내용은 아래에 설명되어 있습니다.
h tps : // / ls lgus s. jp/あcちゔぇ_쑥 rt_인 st 루멘들 온. html # p 로세 s - 아 c 치 온 - 아 c 치 온 - t t ro r

이것으로 서버에서의 처리 시간의 취득이 완료되었습니다.
그런 다음 Server-Timing 헤더에 server_timing를 등록하기 만하면됩니다.

Rails에서는 전역 변수를 많이 사용하지는 않지만 다른 좋은 방법을 모르기 때문에 이번에는 전역 변수를 사용합니다. 컨트롤러로부터 취득할 수 있는 response 오브젝트를 글로벌 변수에 격납해, 방금전의 구독 처리중에 response 오브젝트에 Server-Timingヘッダ 를 덧붙입니다.

app/controllers/application_controller.rb

class ApplicationController < ActionController::Base
  prepend_before_action { $response = response }
end

config/initializers/server_timing.rb

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |*args|
  # ...
  # 省略
  # ...
  response = $response
  response.headers["Server-Timing"] = server_timing
end

구현은 이상입니다.

이제 Server-Timing 헤더 필드에 다음과 같은 값이 부여되어 Chrome 유효성 검사 도구가 좋은 느낌으로 시각화됩니다.

Server-Timing: total;desc="UsersController#index";dur=17.167, db;dur=0.5440000677481294, view;dur=15.272999997250736

마지막으로

저는 ActiveSupport::Notifications와 Server Timing을 처음 사용했지만 서버의 어느 곳에서 시간이 오래 걸리는지 쉽게 시각화 할 수있어 편리하다고 생각했습니다. ActiveSupport::Notifications는 ActiveRecord에서 생성된 인스턴스의 수와 SQL에서 캐시를 사용했는지 등을 알기 때문에 궁리에 따라 보다 자세한 정보를 알 수 있습니다. 또, 기회가 있으면 상세 정보도 가시화해 보고 싶습니다.

참고

ActiveSupport::Notifications

Active Support의 Instrumentation 기능

Server-Timing - MDN

Server Timing - W3C