https://speakerdeck.com/k0kubun/number-ginzarb の資料作成のためのnewrelic_rpmのコードリーディングメモ。バージョンはv4.3.0。
Railtie→Agent#start まで
require 'newrelic_rpm'でRailtieが作られる
まずRailsの場合、普通にGemfileにgem 'newrelic_rpm'を書くと、Bundler.requireされた時にNewRelic::Railtieが定義される。
if Rails::VERSION::MAJOR.to_i >= 3
module NewRelic
class Railtie < Rails::Railtie
initializer "newrelic_rpm.start_plugin" do |app|
NewRelic::Control.instance.init_plugin(:config => app.config)
end
end
end
else
Railsのinitializerの発火
config/environment.rb でrequire File.expand_path('../application', __FILE__)された時にBundler.requireされた後、Rails.application.initialize!でRailtieのinitializerが発火される。
上述のinitializerの中で、シングルトンのNewRelic::Control.instanceが作られ、NewRelic::Control::InstanceMethods#init_pluginが呼ばれる。
#init_plugin
このメソッドの最後で、agentがまだ起動してない時、NewRelic::Agent.agent.startする。
if Agent.config[:agent_enabled] && !NewRelic::Agent.instance.started?
start_agent
install_instrumentation
elsif !Agent.config[:agent_enabled]
def start_agent
@started_in_env = self.env
NewRelic::Agent.agent.start
end
NewRelic::Agent#start
forkをしない場合はここでstartする。unicornやpumaなど、forkを使う"dispatcher"を使う場合、このメソッドではstartをしない。
def start
return unless agent_should_start?
log_startup
check_config_and_start_agent
log_version_and_pid
events.subscribe(:finished_configuring) do
log_ignore_url_regexes
end
end
def check_config_and_start_agent
return unless monitoring? && has_correct_license_key?
return if using_forking_dispatcher?
setup_and_start_agent
end
def using_forking_dispatcher?
if [:puma, :passenger, :rainbows, :unicorn].include? Agent.config[:dispatcher]
::NewRelic::Agent.logger.info "Deferring startup of agent reporting thread because #{Agent.config[:dispatcher]} may fork."
true
else
false
end
end
forkをする場合のAgentの起動パス
では、productionでよく使うであろうunicornやpumaではいつどのように起動されるのか。
#init_plugin
if Agent.config[:agent_enabled] && !NewRelic::Agent.instance.started?
start_agent
install_instrumentation
elsif !Agent.config[:agent_enabled]
start_agentでの起動をスキップしたあと、install_instrumentationというのが呼ばれている。
install_instrumentation
def install_instrumentation
_install_instrumentation
end
private
def _install_instrumentation
return if @instrumented
@instrumented = true
# Instrumentation for the key code points inside rails for monitoring by NewRelic.
# note this file is loaded only if the newrelic agent is enabled (through config/newrelic.yml)
instrumentation_path = File.expand_path(File.join(File.dirname(__FILE__), '..', 'agent','instrumentation'))
@instrumentation_files <<
File.join(instrumentation_path, '*.rb') <<
File.join(instrumentation_path, app.to_s, '*.rb')
@instrumentation_files.each { | pattern | load_instrumentation_files pattern }
DependencyDetection.detect!
::NewRelic::Agent.logger.info "Finished instrumentation"
end
DependencyDetection.detect!という奴が呼ばれる。
DependencyDetection
DependencyDetection.defer do
named :rack
depends_on do
defined?(::Rack) && defined?(::Rack::Builder)
end
executes do
::NewRelic::Agent::Instrumentation::RackHelpers.instrument_builder ::Rack::Builder
end
end
DependencyDetection.detect!は、こういうDSLを書いておくと、depends_onを満たす時にexecutesを実行するようだ。なので、::NewRelic::Agent::Instrumentation::RackHelpers.instrument_builder ::Rack::Builderが呼ばれる。
instrument_builder
def self.instrument_builder builder_class
::NewRelic::Agent.logger.info "Installing deferred #{builder_class} instrumentation"
builder_class.class_eval do
class << self
attr_accessor :_nr_deferred_detection_ran
end
self._nr_deferred_detection_ran = false
include ::NewRelic::Agent::Instrumentation::RackBuilder
alias_method :to_app_without_newrelic, :to_app
alias_method :to_app, :to_app_with_newrelic_deferred_dependency_detection
if ::NewRelic::Agent::Instrumentation::RackHelpers.middleware_instrumentation_enabled?
::NewRelic::Agent.logger.info "Installing #{builder_class} middleware instrumentation"
alias_method :run_without_newrelic, :run
alias_method :run, :run_with_newrelic
alias_method :use_without_newrelic, :use
alias_method :use, :use_with_newrelic
end
end
def self.instrument_url_map url_map_class
url_map_class.class_eval do
alias_method :initialize_without_newrelic, :initialize
def initialize(map = {})
traced_map = ::NewRelic::Agent::Instrumentation::RackURLMap.generate_traced_map(map)
initialize_without_newrelic(traced_map)
end
end
end
end
このメソッドはRack::Builderにモンキーパッチをやりまくる。見ておく必要があるのは、include ::NewRelic::Agent::Instrumentation::RackBuilderとかalias_method :run, :run_with_newrelicのあたり。
Rack::Builder#run
config.ruにrunというDSLが書いてあるのをご存知だろうか。それがRack::Builder#runである。Rackサーバーを起動するとこれが評価されてRackアプリケーションがビルドされる。詳細は僕の別の記事をどうぞ。
Rackとは何か
で、重要なのはinstrument_builderでこの#runがモンキーパッチされて::NewRelic::Agent::Instrumentation::RackBuilder#run_with_newrelicが呼びだされること。
module RackBuilder
def run_with_newrelic(app, *args)
if ::NewRelic::Agent::Instrumentation::RackHelpers.middleware_instrumentation_enabled?
wrapped_app = ::NewRelic::Agent::Instrumentation::MiddlewareProxy.wrap(app, true)
run_without_newrelic(wrapped_app, *args)
else
run_without_newrelic(app, *args)
end
end
ここで、Rackアプリケーションを::NewRelic::Agent::Instrumentation::MiddlewareProxyというRackミドルウェアでラップしている。
NewRelic::Agent::Instrumentation::MiddlewareTracing#call
NewRelic::Agent::Instrumentation::MiddlewareProxyはNewRelic::Agent::Instrumentation::MiddlewareTracingをincludeしていて、#callの実装はそっちにある。
RackサーバーはRackアプリケーションでリクエストを処理するために#callを呼ぶので、最初にリクエストが来た時にNewRelic::Agent::Instrumentation::MiddlewareTracing#callが呼ばれることになる。
def call(env)
first_middleware = note_transaction_started(env)
state = NewRelic::Agent::TransactionState.tl_get
begin
Transaction.start(state, category, build_transaction_options(env, first_middleware))
events.notify(:before_call, env) if first_middleware
result = (target == self) ? traced_call(env) : target.call(env)
if first_middleware
capture_response_attributes(state, result)
events.notify(:after_call, env, result)
end
result
rescue Exception => e
NewRelic::Agent.notice_error(e)
raise e
ensure
Transaction.stop(state)
end
end
ここでTransaction.startが呼ばれる。
Transaction.start
def self.start(state, category, options)
category ||= :controller
txn = state.current_transaction
if txn
txn.create_nested_frame(state, category, options)
else
txn = start_new_transaction(state, category, options)
end
txn
rescue => e
NewRelic::Agent.logger.error("Exception during Transaction.start", e)
nil
end
def self.start_new_transaction(state, category, options)
txn = Transaction.new(category, options)
state.reset(txn)
txn.state = state
txn.start(state)
txn
end
def start(state)
return if !state.is_execution_traced?
transaction_sampler.on_start_transaction(state, start_time)
sql_sampler.on_start_transaction(state, start_time, request_path)
NewRelic::Agent.instance.events.notify(:start_transaction)
NewRelic::Agent::BusyCalculator.dispatcher_start(start_time)
ignore! if user_defined_rules_ignore?
create_initial_segment @default_name
end
NewRelic::Agent.instance.events.notify(:start_transaction)が呼ばれる。
NewRelic::Agent::Harvester#on_transactionの発火
最初にAgentのインスタンスが作られる時、NewRelic::Agent::Agent#initializeで、NewRelic::Agent::Harvesterのインスタンスが作られる。
@harvester = NewRelic::Agent::Harvester.new(@events)
で、これのインスタンス生成時にeventをsubscribeする。
def initialize(events, after_forker=NewRelic::Agent)
# We intentionally don't set our pid as started at this point.
# Startup routines must call mark_started when they consider us set!
@starting_pid = nil
@after_forker = after_forker
if events
events.subscribe(:start_transaction, &method(:on_transaction))
end
end
なので、NewRelic::Agent.instance.events.notify(:start_transaction)で#on_transactionが呼ばれる。
def on_transaction(*_)
return unless restart_in_children_enabled? &&
needs_restart? &&
harvest_thread_enabled?
restart_harvest_thread
end
def restart_harvest_thread
@after_forker.after_fork(:force_reconnect => true)
end
@after_forkerにはNewRelic::Agentが入っているので、NewRelic::Agent::InstanceMethods#after_forkが呼ばれることになる。
NewRelic::Agent::InstanceMethods#after_fork
def after_fork(options={})
needs_restart = false
@after_fork_lock.synchronize do
needs_restart = @harvester.needs_restart?
@harvester.mark_started
end
return if !needs_restart ||
!Agent.config[:agent_enabled] ||
!Agent.config[:monitor_mode] ||
disconnected?
::NewRelic::Agent.logger.debug "Starting the worker thread in #{Process.pid} (parent #{Process.ppid}) after forking."
channel_id = options[:report_to_channel]
install_pipe_service(channel_id) if channel_id
# Clear out locks and stats left over from parent process
reset_objects_with_locks
drop_buffered_data
setup_and_start_agent(options)
end
def setup_and_start_agent(options={})
@started = true
@harvester.mark_started
unless in_resque_child_process?
generate_environment_report
install_exit_handler
@harvest_samplers.load_samplers unless Agent.config[:disable_samplers]
end
connect_in_foreground if Agent.config[:sync_startup]
start_worker_thread(options)
end
start_worker_threadが呼ばれることがわかる。
start_worker_thread
def start_worker_thread(connection_options = {})
if disable = NewRelic::Agent.config[:disable_harvest_thread]
NewRelic::Agent.logger.info "Not starting Ruby Agent worker thread because :disable_harvest_thread is #{disable}"
return
end
::NewRelic::Agent.logger.debug "Creating Ruby Agent worker thread."
@worker_thread = NewRelic::Agent::Threading::AgentThread.create('Worker Loop') do
deferred_work!(connection_options)
end
end
ハイ。というわけで、pumaやunicornを使っていると、最初にリクエストが来た時にスレッドが立ち上がり、そのスレッドはdeferred_work!をやる、という挙動になっている。
NewRelicのワーカースレッドは何をやっているか
AgentThread.create
中では普通にThread.new { deferred_work!(connection_options) }のようなことが起きる。
deferred_work!
def deferred_work!(connection_options)
catch_errors do
NewRelic::Agent.disable_all_tracing do
connect(connection_options)
if connected?
create_and_run_event_loop
# never reaches here unless there is a problem or
# the agent is exiting
else
::NewRelic::Agent.logger.debug "No connection. Worker thread ending."
end
end
end
end
これはあんまちゃんと見てないがconnectはNewRelicに接続できるか確認するぽい。NewRelicにデータが送れる状況でのみワーカーがcreate_and_run_event_loopをするようになっているのだと思う。
create_and_run_event_loop
def create_and_run_event_loop
@event_loop = create_event_loop
@event_loop.on(:report_data) do
transmit_data
end
@event_loop.on(:report_event_data) do
transmit_event_data
end
@event_loop.on(:reset_log_once_keys) do
::NewRelic::Agent.logger.clear_already_logged
end
@event_loop.fire_every(Agent.config[:data_report_period], :report_data)
@event_loop.fire_every(report_period_for(:analytic_event_data), :report_event_data)
@event_loop.fire_every(LOG_ONCE_KEYS_RESET_PERIOD, :reset_log_once_keys)
@event_loop.run
end
def create_event_loop
EventLoop.new
end
なるほどね
EventLoop#run
def run
::NewRelic::Agent.logger.debug "Running event loop"
while !stopped?
run_once
end
end
def run_once(nonblock=false)
wait_to_run(nonblock)
prune_timers
fire_timers
until @event_queue.empty?
evt, args = @event_queue.pop
dispatch_event(evt, args)
reschedule_timer_for_event(evt)
end
end
def wait_to_run(nonblock)
timeout = nonblock ? 0 : next_timeout
ready = IO.select([@self_pipe_rd], nil, nil, timeout)
if ready && ready[0] && ready[0][0] && ready[0][0] == @self_pipe_rd
@self_pipe_rd.read(1)
end
end
@event_loop.runのところでwhile !stopped?な無限ループに入る。
で、このループは基本的にIO.selectでブロックする。@self_pipe_rdにはIO.pipeした奴が入ってて、これの書き込み側は以下のようになっており、#fireによってイベントが発火されるとブロックが解除される。
def fire(event, *args)
@event_queue << [event, args]
wakeup
end
def wakeup
begin
@self_pipe_wr.write_nonblock '.'
rescue Errno::EAGAIN
::NewRelic::Agent.logger.debug "Failed to wakeup event loop"
end
end
CRubyではブロッキングIOの間GVLが開放されるので、イベントが発火されるまでは本体の処理を邪魔しないということになる。また、このIO.selectのタイムアウトは以下のようにして決まり、設定しておいたTimerのうち最初に発火されるTimerまでの時間が経つと解除されるようになっている。
def next_timeout
return nil if @timers.empty?
timeout = @timers.values.map(&:next_fire_time).min - Time.now
timeout < 0 ? 0 : timeout
end
Timerによるイベントの発火
create_and_run_event_loopが呼ばれた際、イベントループが始まった時にTimerがセットされるように仕向けられている。
@event_loop.fire_every(Agent.config[:data_report_period], :report_data)
@event_loop.fire_every(report_period_for(:analytic_event_data), :report_event_data)
@event_loop.fire_every(LOG_ONCE_KEYS_RESET_PERIOD, :reset_log_once_keys)
# Timer.newを作って__add_timerイベントにしている
def fire_every(interval, event)
::NewRelic::Agent.logger.debug "Firing event #{event} every #{interval} seconds."
fire(:__add_timer, Timer.new(interval, event, true))
end
# __add_timerがsubscribeされている
def initialize
@self_pipe_rd, @self_pipe_wr = IO.pipe
@event_queue = Queue.new
@stopped = false
@timers = {}
@subscriptions = Hash.new { |h,k| h[k] = [] }
@subscriptions[:__add_timer] << Proc.new { |t| set_timer(t) }
@subscriptions[:__add_event] << Proc.new { |e, blk| @subscriptions[e] << blk }
end
# イベントループで、queueからpopされ、dispatch_eventされる
def run_once(nonblock=false)
wait_to_run(nonblock)
prune_timers
fire_timers
until @event_queue.empty?
evt, args = @event_queue.pop
dispatch_event(evt, args)
reschedule_timer_for_event(evt)
end
end
# dispatchされると、callで`set_timer(t)`が呼ばれる
def dispatch_event(event, args)
NewRelic::Agent.logger.debug("EventLoop: Dispatching event '#{event}' with #{@subscriptions[event].size} callback(s).")
errors = []
@subscriptions[event].each do |s|
begin
s.call(*args)
rescue NewRelic::Agent::ForceRestartException, NewRelic::Agent::ForceDisconnectException
raise
rescue => e
errors << e
end
end
if !errors.empty?
::NewRelic::Agent.logger.error "#{errors.size} error(s) running task for event '#{event}' in Agent Event Loop:", *errors
end
end
# ここで @timers にtimerがセットされる。すると、event loopのfire_timers呼び出しでもfire_timerが呼ばれるようになる
def set_timer(timer)
existing_timer = @timers[timer.event]
if existing_timer
elapsed_interval = Time.now - existing_timer.last_interval_start
timer.advance(elapsed_interval)
end
@timers[timer.event] = timer
fire_timer(timer)
end
# timer.due?であればイベントをキューにつっこむ
def fire_timer(timer)
if timer.due?
@event_queue << [timer.event]
timer.set_fired_time
end
end
まあつまり、設定しておいたインターバルでnext_fire_timeが計算され、その時間の間IO.selectでブロックし、その後イベントが発火されてそのイベントがディスパッチされる、というようになっている。
NewRelicのワーカースレッドがタイマーでディスパッチしているイベント
create_and_run_event_loopをよく見るとイベントを3つsubscribeし、これらを発火するタイマーイベントを3つ作っているだけなのだ。それぞれのイベントの内容を見ていく。
:report_data
@event_loop.fire_every(Agent.config[:data_report_period], :report_data)
インターバルは以下のようにデフォルトでは60秒になっている。
:data_report_period => {
:default => 60,
:public => false,
:type => Integer,
:allowed_from_server => true,
:description => 'Number of seconds betwixt connections to the New Relic data collection service. Note that transaction events have a separate report period, specified by data_report_periods.analytic_event_data.'
},
イベントのsubscriptionはこうなっている。
@event_loop.on(:report_data) do
transmit_data
end
def transmit_data
now = Time.now
::NewRelic::Agent.logger.debug "Sending data to New Relic Service"
@events.notify(:before_harvest)
@service.session do # use http keep-alive
harvest_and_send_errors
harvest_and_send_error_event_data
harvest_and_send_transaction_traces
harvest_and_send_slowest_sql
harvest_and_send_timeslice_data
check_for_and_handle_agent_commands
harvest_and_send_for_agent_commands
end
ensure
NewRelic::Agent::Database.close_connections
duration = (Time.now - now).to_f
NewRelic::Agent.record_metric('Supportability/Harvest', duration)
end
あんまちゃんと読んでないけど、収集したデータをNewRelicに飛ばすのはこれがやっているようだ。
:report_event_data
@event_loop.fire_every(report_period_for(:analytic_event_data), :report_event_data)
これも60秒おき。
:'data_report_periods.analytic_event_data' => {
:default => 60,
:public => false,
:type => Integer,
:dynamic_name => true,
:allowed_from_server => true,
:description => 'Number of seconds between connections to the New Relic data collection service for sending transaction event data.'
},
イベントの処理はこう。
@event_loop.on(:report_event_data) do
transmit_event_data
end
def transmit_event_data
transmit_single_data_type(:harvest_and_send_analytic_event_data, "TransactionEvent")
end
def transmit_single_data_type(harvest_method, supportability_name)
now = Time.now
msg = "Sending #{harvest_method.to_s.gsub("harvest_and_send_", "")} to New Relic Service"
::NewRelic::Agent.logger.debug msg
@service.session do # use http keep-alive
self.send(harvest_method)
end
ensure
duration = (Time.now - now).to_f
NewRelic::Agent.record_metric("Supportability/#{supportability_name}Harvest", duration)
end
def harvest_and_send_analytic_event_data
harvest_and_send_from_container(transaction_event_aggregator, :analytic_event_data)
harvest_and_send_from_container(synthetics_event_aggregator, :analytic_event_data)
harvest_and_send_from_container(@custom_event_aggregator, :custom_event_data)
end
なんかアナリティクスっぽいデータを送るようだ(読みたいところが別のとこであるということが読めてしまったので興味を失っている)
:reset_log_once_keys
@event_loop.on(:reset_log_once_keys) do
::NewRelic::Agent.logger.clear_already_logged
end
これも60秒おき。
LOG_ONCE_KEYS_RESET_PERIOD = 60.0
def log_once(level, key, *msgs)
@already_logged_lock.synchronize do
return if @already_logged.include?(key)
if @already_logged.size >= NUM_LOG_ONCE_KEYS && key.kind_of?(String)
# The reason for preventing too many keys in `logged` is for
# memory concerns.
# The reason for checking the type of the key is that we always want
# to allow symbols to log, since there are very few of them.
# The assumption here is that you would NEVER pass dynamically-created
# symbols, because you would never create symbols dynamically in the
# first place, as that would already be a memory leak in most Rubies,
# even if we didn't hang on to them all here.
return
end
@already_logged[key] = true
end
self.send(level, *msgs)
end
def clear_already_logged
@already_logged_lock.synchronize do
@already_logged = {}
end
end
メモリが気になるのでログを定期的に消しているようだ。これ別のイベントでちゃんとNewRelicに飛ばされたりしてるのかなあ(全く読んでない)。
Transactionのプロファイリングはどうなっているか
Rackミドルウェアのフック
なんとなくワーカースレッドがサンプリングしてるのかと勝手に思ってたけど全然違うっぽいことに気付いた(1分おきにサンプリングとかだったら粗すぎる…)。Rackミドルウェアをもう一度見てみる。
def call(env)
first_middleware = note_transaction_started(env)
state = NewRelic::Agent::TransactionState.tl_get
begin
Transaction.start(state, category, build_transaction_options(env, first_middleware))
events.notify(:before_call, env) if first_middleware
result = (target == self) ? traced_call(env) : target.call(env)
if first_middleware
capture_response_attributes(state, result)
events.notify(:after_call, env, result)
end
result
rescue Exception => e
NewRelic::Agent.notice_error(e)
raise e
ensure
Transaction.stop(state)
end
end
def self.start(state, category, options)
category ||= :controller
txn = state.current_transaction
if txn
txn.create_nested_frame(state, category, options)
else
txn = start_new_transaction(state, category, options)
end
txn
rescue => e
NewRelic::Agent.logger.error("Exception during Transaction.start", e)
nil
end
def self.start_new_transaction(state, category, options)
txn = Transaction.new(category, options)
state.reset(txn)
txn.state = state
txn.start(state)
txn
end
def start(state)
return if !state.is_execution_traced?
transaction_sampler.on_start_transaction(state, start_time)
sql_sampler.on_start_transaction(state, start_time, request_path)
NewRelic::Agent.instance.events.notify(:start_transaction)
NewRelic::Agent::BusyCalculator.dispatcher_start(start_time)
ignore! if user_defined_rules_ignore?
create_initial_segment @default_name
end
def agent
NewRelic::Agent.instance
end
def transaction_sampler
agent.transaction_sampler
end
def sql_sampler
agent.sql_sampler
end
シングルトンのtransaction_samplerとsql_samplerを参照し、on_start_transactionを呼ぶようだ。
まあ、stopも似たようなことをやっておき、1回のリクエストごとの結果を取れるようにしているのだろう。
そして、ここを読んでもプロファイリングをやっている場所はわからなかったのでまた別の場所を読む。
プロファイリングを行う場所
こういう感じだろうと期待していたのが全然違ったのでかなり迷走していたが、いろいろやってたらなんとなく読めた。 new_relic/agent/instrumentation に色々なgem向けのintegrationがとにかくいっぱい入っている。
で、前述したように、Railtieから呼ばれる#init_pluginの最後に呼ばれるinstall_instrumentationでDependencyDetection.detect!が呼ばれ、それぞれのgemのクラスが定義されていた場合はRackの時に前述したような感じでモンキーパッチを行う。というか、RackはNewRelicが収集している数あるメトリクスの中の1つにすぎなかったようだ。
で、モンキーパッチをしたメソッドが呼ばれた時に、大抵は開始と終了の時間を計測し、その計測結果を保存しておいて、ワーカースレッドが送信する、という挙動のようだ。例えばActiveRecordの奴を見てみる。
module NewRelic
module Agent
module Instrumentation
module ActiveRecord
ACTIVE_RECORD = "ActiveRecord".freeze
module BaseExtensions
def save(*args, &blk)
::NewRelic::Agent.with_database_metric_name(self.class.name, nil, ACTIVE_RECORD) do
super
end
end
def save!(*args, &blk)
::NewRelic::Agent.with_database_metric_name(self.class.name, nil, ACTIVE_RECORD) do
super
end
end
end
module RelationExtensions
def update_all(*args, &blk)
::NewRelic::Agent.with_database_metric_name(self.name, nil, ACTIVE_RECORD) do
super
end
end
def delete_all(*args, &blk)
::NewRelic::Agent.with_database_metric_name(self.name, nil, ACTIVE_RECORD) do
super
end
end
def destroy_all(*args, &blk)
::NewRelic::Agent.with_database_metric_name(self.name, nil, ACTIVE_RECORD) do
super
end
end
def calculate(*args, &blk)
::NewRelic::Agent.with_database_metric_name(self.name, nil, ACTIVE_RECORD) do
super
end
end
def pluck(*args, &blk)
::NewRelic::Agent.with_database_metric_name(self.name, nil, ACTIVE_RECORD) do
super
end
end
end
end
end
end
end
DependencyDetection.defer do
named :active_record_5
depends_on do
defined?(::ActiveRecord) && defined?(::ActiveRecord::Base) &&
defined?(::ActiveRecord::VERSION) &&
::ActiveRecord::VERSION::MAJOR.to_i == 5
end
depends_on do
!NewRelic::Agent.config[:disable_activerecord_instrumentation] &&
!NewRelic::Agent::Instrumentation::ActiveRecordSubscriber.subscribed?
end
executes do
::NewRelic::Agent.logger.info 'Installing ActiveRecord 5 instrumentation'
end
executes do
ActiveSupport::Notifications.subscribe('sql.active_record',
NewRelic::Agent::Instrumentation::ActiveRecordSubscriber.new)
ActiveSupport.on_load(:active_record) do
::ActiveRecord::Base.prepend ::NewRelic::Agent::Instrumentation::ActiveRecord::BaseExtensions
::ActiveRecord::Relation.prepend ::NewRelic::Agent::Instrumentation::ActiveRecord::RelationExtensions
end
end
end
これは大分わかりやすい。こういうのがいろんなgemに対してひたすら入っており、それらを全て送信しておけば、まあ当然NewRelicが出しているような集計結果は出せる。
(NewRelicの)transactionをstopするところでbinding.pryとかしてみればわかるが、そういういろんな種類のメトリクスがいろいろ入ってる奴がNewRelicのメトリクスになっていた。
それぞれ丁寧にintegrationを作っている以上、オーバーヘッドはあるもののそこそこ正確な計測結果が得られるので、割といいものだなあと思った。