Читаем исходники newrelic_rpm

Illustration of a person sitting on the floor against a wall, engrossed in reading a book, with a shadow casting over half of the scene.

Чтение исходников – лучший способ разобраться в том, как что-то работает. Гем newrelic_rpm (-v 3.5.4.34) – кладезь знаний о практическом применении самых изощрённых конструкций ruby. Из его сорцов можно многое понять об объектной модели ruby, о том как работает rails и, конечно же, о том как незаметно следить за всем, что делает пользователь вашего приложения. Я потратил большую часть своего воскресенья на изучение "кишок" newrelic_rpm и готов поделиться своими открытиями. Надеюсь, у меня получилось понятно описать как именно работает, собирает и отправляет данные гем самой популярной платформы для аналитики ruby приложений.

В основе newrelic_rpm лежит railtie, определённый в ./lib/newrelic_rpm.rb. Использование railtie позволяет получить доступ к процессу загрузки rails приложения. В данном случае - инициализировать агента NewRelic.

# ./lib/newrelic_rpm.rb

module NewRelic
      class Railtie < Rails::Railtie
        initializer "newrelic_rpm.start_plugin" do |app|
             NewRelic::Control.instance.init_plugin(:config => app.config)
        end
      end
end

Метод init_plugin наконец-то запускает агента (если всё в порядке с конфигом в newrelic.yml вашего приложения), который и будет собирать данные о приложении:

# ./lib/new_relic/control/instance_methods.rb:80

...
    NewRelic::Agent.agent = NewRelic::Agent::Agent.instance
    if Agent.config[:agent_enabled] && !NewRelic::Agent.instance.started?
      setup_log unless logger_override
      start_agent
      install_instrumentation
      load_samplers unless Agent.config['disable_samplers']
      local_env.gather_environment_info
      append_environment_info
    elsif !Agent.config[:agent_enabled]
      install_shim
    end
 end

 def start_agent
    NewRelic::Agent.agent.start
 end

Обратите внимание на метод local_env. Используя класс NewRelic::LocalEnvironment NewRelic определяет что же у вас за приложение - rails, sinatra и т.д. Затем эта информация используется для загрузки специфичных для каждого вида приложений методов, которые разбиты по модулям в ./lib/new_relic/control/frameworks/. Выглядит эта загрузка следующим образом:

# ./lib/new_relic/control/class_methods.rb:35

def load_framework_class(framework)
  begin
    require "new_relic/control/frameworks/#{framework}"
  rescue LoadError
  end
  NewRelic::Control::Frameworks.const_get(framework.to_s.capitalize)
end

В коде NewRelic::LocalEnvironment можно найти хорошие примеры о том как, используя ruby, получить информацию об используемых в приложении фреймворке, веб-сервере, гемах, архитектуры ОС и т.д. Советую изучить ./lib/new_relic/local_environment.rb и поиграться с этим классом в консоли. Вот какую информацию получил NewRelic о моём окружении после вызова gather_environment_info и local_env.append_environment_info:

{"Framework"=>"rails3", "Dispatcher"=>"unicorn", "Environment"=>"development", "Ruby version"=>"1.9.3", 
"Ruby description"=>"ruby 1.9.3p327 (2012-11-10 revision 37606) [x86_64-darwin12.2.1]", 
"Ruby platform"=>"x86_64-darwin12.2.1", "Ruby patchlevel"=>327, "Arch"=>"i386\n", 
"Database adapter"=>"postgresql", "Rails version"=>"3.2.11", "Rails Env"=>"development"}

Работает агент в отдельном потоке. При этом в первую очередь он пытается соединится с сервером NewRelic, и если соединение успешно, то запускает бесконечный цикл, который прерывается только если работа агента завершена.

#./lib/new_relic/agent/agent.rb

def start_worker_thread(connection_options = {})
  log.debug "Creating Ruby Agent worker thread."
  @worker_thread = NewRelic::Agent::AgentThread.new('Worker Loop') do
    deferred_work!(connection_options)
  end
end

 def deferred_work!(connection_options)
  catch_errors do
    NewRelic::Agent.disable_all_tracing do
      connect(connection_options)
      if @connected
        log_worker_loop_start
        create_and_run_worker_loop
      else
        log.debug "No connection. Worker thread ending."
      end
    end
  end
end

Сам цикл работает так: получает на выполнение блок кода, выполняет его, потом останавливает поток с агентом на некоторое время, затем снова выполняет переданный блок кода.

#./lib/new_relic/agen/worker_loop.rb

def run(period=nil, &block)
  @period = period if period
  @next_invocation_time = (Time.now + @period)
  @task = block
  while keep_running? do
    while @now < @next_invocation_time
      sleep_time = @next_invocation_time - @now
      sleep sleep_time if sleep_time > 0
      @now = Time.now
    end
    run_task if keep_running?
    @iterations += 1 if !@limit.nil?
  end
end

Метод, который NewRelic крутит в этом цикле определён всё в том же классе Agent, называется transmit_data. Занимается он отправкой данных на сервера NewRelic. Данные при этом хранятся в объектах класса TransactionSample (./lib/new_relic/transaction_sample.rb), а все собранные сэмплы в свою очередь содержатся в атрибуте @samples класса TransactionSampler (./lib/new_relic/agent/transactions_sampler.rb), экземпляр которого является атрибутом того самого Агента. Сэмплы разбиты на сегменты (./lib/new_relic/transaction_sample/segment.rb). Перед отправкой на сервера NewRelic из сэмплов убираются все лишние данные. Пример сэмпла, сформированного при загрузке блог поста в FJEngine:

Transaction Sample collected at 2013-02-24 19:32:43 +0100
  {
  Path: Controller/posts/show 
  segment_count: 20
  request_params: 
  uri: /posts/57
  custom_params: [:cpu_time, 0.1900000000000004]
  }

>> 0 ms [Segment] ROOT 
  >> 1 ms [Segment] Controller/posts/show 
      -backtrace : ["/Users/fodoj/.rvm/gems/ruby-1.9.3-p327/gems/actionpack-3.2.11/lib/abstract_cont
    >> 20 ms [Segment] Database/SQL/other 
        -backtrace : ["/Users/fodoj/.rvm/gems/ruby-1.9.3-p327/gems/activerecord-3.2.11/lib/active_reco
        -sql : SELECT a.attname, format_type(a.atttypid, a.atttypmod),

        -connection_config: {:adapter=>"postgresql", :host=>"localhost", :encoding=>"utf8", :database=>"fjzon
    << 24 ms Database/SQL/other
    >> 25 ms [Segment] Database/SQL/other 
        -backtrace : ["/Users/fodoj/.rvm/gems/ruby-1.9.3-p327/gems/activerecord-3.2.11/lib/active_reco
        -sql : SELECT COUNT(*)
            FROM pg_class c
            LEFT JOIN pg_
        -connection_config: {:adapter=>"postgresql", :host=>"localhost", :encoding=>"utf8", :database=>"fjzon
    << 26 ms Database/SQL/other
    >> 27 ms [Segment] Database/SQL/other 
        -backtrace : ["/Users/fodoj/.rvm/gems/ruby-1.9.3-p327/gems/activerecord-3.2.11/lib/active_reco
        -sql : SELECT DISTINCT(attr.attname)
          FROM pg_attribute attr

        -connection_config: {:adapter=>"postgresql", :host=>"localhost", :encoding=>"utf8", :database=>"fjzon
    << 29 ms Database/SQL/other

И вот тот же сэмпл, но подготовленный для отправки в NewRelic (./lib/new_relic/transaction_sample.rb:167#prepare_to_send):

Transaction Sample collected at 2013-02-24 19:35:02 +0100
  {
  Path: Controller/posts/show 
  segment_count: 40
  request_params: 
  uri: /posts/57
  custom_params: [:cpu_time, 0.17999999999999972]
  }

>> 0 ms [Segment] ROOT 
  >> 0 ms [Segment] Controller/posts/show 
    >> 18 ms [Segment] Database/SQL/other 
    << 23 ms Database/SQL/other
    >> 23 ms [Segment] Database/SQL/other 
    << 25 ms Database/SQL/other
    >> 25 ms [Segment] Database/SQL/other 
    << 27 ms Database/SQL/other

Вкратце о том, как newrelic_rpm собирает данные. В ./lib/new_relic/agent/instrumentation/ определены различные расширения и модули для перехвата выполняемых в приложении методов. К примеру, ./lib/new_relic/agent/instrumentation/active_record.rb переопределяет метод log, тем самым получая доступ к выполняемым sql запросам. В том же файле можно посмотреть использование чудесного метода add_method_tracer из модуля MethodTracer (./lib/new_relic/agent/method_tracer.rb) – уже ради одного этого модуля стоит изучить исходники гема. Для анализа времени выполнения кода используется StatsEngine, в дебри которого пока что лезть не будем.