уведомления rails activesupport - неправильное значение времени выполнения db

Хорошо, похоже на ошибку. Давайте посмотрим, что происходит:

Во-первых, у нас есть AR railtie для действия контроллера и его реализация для установки db_runtime с помощью хука cleanup_view_runtime.

def cleanup_view_runtime
      if ActiveRecord::Base.connected?
       db_rt_before_render = ActiveRecord::LogSubscriber.reset_runtime
       runtime = super
       db_rt_after_render = ActiveRecord::LogSubscriber.reset_runtime
       self.db_runtime = db_rt_before_render + db_rt_after_render
       runtime - db_rt_after_render
     else
       super
     end
end

Приложение вызывает действие контроллера -> действие, выполняющее некоторые запросы к базе данных и отображающее некоторые вещи -> до и после рендеринга AR Logger сохраняет данные времени выполнения. Хорошо.

Давайте посмотрим, как работает response_with

def respond_with(*resources, &block)
  raise "In order to use respond_with, first you need to declare the formats your " <<
        "controller responds to in the class level" if self.class.mimes_for_respond_to.empty?

  if collector = retrieve_collector_from_mimes(&block)
    options = resources.size == 1 ? {} : resources.extract_options!
    options[:default_response] = collector.response
    (options.delete(:responder) || self.class.responder).call(self, resources, options)
  end
end

def self.call(*args)
  new(*args).respond
end

def to_format
  if get? || !has_errors? || response_overridden?
    default_render
  else
    display_errors
  end
rescue ActionView::MissingTemplate => e
  api_behavior(e)
end

Кажется, здесь слишком много кода, но вы должны увидеть стек вызовов для этой проблемы: response_with -> self.class.responder.respond -> self.class.responder.to_format -> default_render -> default_renderer у нас нет). На данный момент мы можем видеть реализацию для рендеринга :json и :xml(api_behaviour) через перехват ActionView::MissingTemplate.

Теперь мы знаем, как работает response_with, но AR Logger не знает.. Хук cleanup_view_runtime вызывается дважды: для default_renderer (в это время данные шаблона были подготовлены и были вызваны некоторые запросы к БД, но мы ловим ActionView::MissingTemplate в процессе рендеринга)

db_rt_before_render = ActiveRecord::LogSubscriber.reset_runtime
runtime = super # <-- here
db_rt_after_render = ActiveRecord::LogSubscriber.reset_runtime

и для api_behavour(на тот момент все данные шаблона были готовы к рендерингу и никаких запросов к БД)

Немного сумбурное объяснение, но надеюсь будет полезно :)

Инструментарий Rails работает, обертывая запрос на металлическом уровне стойки и записывая события для различных метрик. В обоих случаях весь блок должен быть обернут и отслежен стандартной аппаратурой.

Единственная разница, которую я вижу после изучения источника, заключается в вызове save() по сравнению с save!(). Похоже, что базовые подписки на события метода в ActiveRecord могут вести себя по-разному.

Попробуйте изменить свой пример response_with(), чтобы использовать сохранение вместо сохранения! и посмотрите, правильно ли он записывает db_runtime? Если это так, то это ошибка Rails, и вы можете обойти ее, имитируя сохранение! функции с помощью сохранения.

ОБНОВИТЬ:

Это не просто и требует некоторой настройки вокруг ..

Нет, если вы не напишете свой собственный Railtie, чтобы подключиться к этому, как Active Record, но это немного сложнее, чем копирование того, что есть у Active Record...

Но вот как это делается:

1) Подписчик журналов

2) Railtie

3) Среда выполнения контроллера

Я надеюсь, что вы получили намек на то, как начать вникать в это.

Ваше здоровье!