rails activesupport通知 – 错误的db运行时值

我正在尝试记录我的REST API应用程序的请求。 我正在使用rails通知，例如http://railscasts.com/episodes/249-notifications-in-rails-3

我无法理解如何解决rails通知的一个问题。

我的初始化代码

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |name, start, finish, id, payload| p name p start p finish p id p payload end Controller respond section class PostsController < ApplicationController # GET /posts # GET /posts.json respond_to :json, :html .... end 

控制器创建动作

  def create @post = Post.new(params[:post]) @post.save! respond_with(@post, :location => nil) end 

控制台输出

 "process_action.action_controller" 2013-02-02 20:13:11 +0200 2013-02-02 20:13:11 +0200 "951b8999e9b71d4a8949" {:controller=>"PostsController", :action=>"create", :params=>{"utf8"=>"✓", "authenticity_token"=>"1WugY9gh6ZCRXjfBTuckye3c9XDvtCqMQ2JdBpCo88s=", "post"=>{"name"=>"post3", "title"=>"post3", "content"=>"post3"}, "commit"=>"Create Post", "action"=>"create", "controller"=>"posts"}, :format=>:html, :method=>"POST", :path=>"/posts", :status=>302, :view_runtime=>nil, :db_runtime=>0} 

如您所见：db_runtime => 0

但是，如果我将控制器操作代码更改为默认支架

  def create @post = Post.new(params[:post]) #@post.save! #respond_with(@post) respond_to do |format| if @post.save format.html { redirect_to @post, notice: 'Post was successfully created.' } format.json { render json: @post, status: :created, location: @post } else format.html { render action: "new" } format.json { render json: @post.errors, status: :unprocessable_entity } end end end 

我可以看到

 "process_action.action_controller" 2013-02-02 20:22:51 +0200 2013-02-02 20:22:51 +0200 "bf2a3173c08a0fd9008e" {:controller=>"PostsController", :action=>"create", :params=>{"utf8"=>"✓", "authenticity_token"=>"1WugY9gh6ZCRXjfBTuckye3c9XDvtCqMQ2JdBpCo88s=", "post"=>{"name"=>"post3", "title"=>"post3", "content"=>"post3"}, "commit"=>"Create Post", "action"=>"create", "controller"=>"posts"}, :format=>:html, :method=>"POST", :path=>"/posts", :status=>302, :view_runtime=>nil, :db_runtime=>4.727} 

：db_runtime => 4.727

这是什么原因以及我如何解决它以使其在第一个例子中起作用？ 谢谢 ！

UPD

  bundle show rails /Users/admin/.rvm/gems/ruby-1.9.3-p125/gems/rails-3.2.11 rvm current ruby-1.9.3-p125 

UPD2

当我使用respond_with时，它似乎不起作用！ 有人可以告诉我为什么吗？ 谢谢

Answer 1

好吧，这似乎是一个bug。 让我们看看，发生了什么：

首先，我们有控制器动作的AR railtie及其使用cleanup_view_runtime钩子设置db_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之前和之后保存运行时数据。 好。

让我们看看如何工作respond_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 

这里似乎有太多代码，但你应该看到这个问题的callstack：respond_with – > self.class.responder.respond – > self.class.responder.to_format – > default_render – > default_renderer引发ActionView :: MissingTemplate（因为我们没有任何）。 此时我们可以通过捕获ActionView :: MissingTemplate看到渲染的实现：json和：xml（api_behaviour）。

现在我们知道respond_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（当时所有模板数据都准备好渲染，没有数据库查询）

一些凌乱的解释，但我希望它会有所帮助:)

Answer 2

Rails工具通过将请求包装在Rack金属级别并记录不同指标的事件来工作。 在这两种情况下，整个块应该由标准仪器包装和跟踪。

在深入挖掘源代码后，我能看到的唯一区别是调用save（）与save！（）。 看起来ActiveRecord中的基础方法事件订阅可能表现不同。

尝试更改您的respond_with（）示例以使用save vs. save！ 并查看它是否正确记录了db_runtime？ 如果是这样，那就是一个Rails错误，你可以通过模仿保存来解决它！ function使用保存。

Answer 3

更新：

这不是直截了当的，需要一些调整..

除非你把自己的Railtie编写成像Active Record一样挂钩，但它比复制Active Record有的复杂一点……

但这是它如何做到的：

1） 日志订户

2） 铁路

3） 控制器运行时

我希望你能得到如何开始进入它的暗示。

干杯!