ActiveSupport 通知没有持续时间（开始时间和结束时间完全相同）答案

【问题标题】：ActiveSupport notifications don't have a duration (the start- and end-time are exactly the same)ActiveSupport 通知没有持续时间（开始时间和结束时间完全相同）
【发布时间】：2016-08-08 08:12:43
【问题描述】：

我们使用ActiveSupport 通知来记录特定的网络调用（使用 Faraday）。只在其中一种类型的调用中，当代码到达...

ActiveSupport::Notifications.subscribe(notification[:name]) do |_name, starts, ends, _, env|
  handle_notification(starts, ends, env, notification[:service], env[:request_headers][notification[:header]])
end

...starts 和ends 是一样的，所以我无法计算通话时长。

这只发生在一个特定的调用上，代码基本相同。但是，我确实注意到正常工作的调用被提取到 gems 中，但不工作的调用不在 gems 中。不确定是否重要。

我该如何调试/解决这个问题？

【问题讨论】：

您能否检查在您生成这些通知的位置是否通过了该块？它包含所有必需的代码
它确实通过了，所以当我做ActiveSupport::Notifications::Event.new(..).duration 时，它等于 0.033 或类似的值，这没有意义

标签： ruby-on-rails ruby-on-rails-4 notifications activesupport

【解决方案1】：

我在尝试使用 factory_girl（现在称为 factory_bot，因为我们在政治上都是正确的）锁定慢速工厂时遇到了同样的问题。

在我的情况下，使用travel_to 是罪魁祸首。 travel_to 似乎起作用的方式（不幸的是），本质上是“冻结”时间......也就是说，一旦调用了travel_to x，Time.now 将返回 x 的值，无论有多少时间在调用之间传递。

解决方法可能涉及使用travel_back，或避免调用travel_to。

【讨论】：

【解决方案2】：

start 和 end 值是 Time 对象。如果您只是记录这些值的输出，它们看起来就像时间/日期值2017-01-12 10:51:00 +0100。

您必须将它们转换为毫秒或微秒才能看到精确值。

您可以使用以下方法将 Time 对象转换为毫秒：

start.to_f * 1000
end.to_f * 1000

然后您可以使用像 1484216765256 这样的值（以毫秒为单位）并通过从 start 中减去 end 来计算持续时间。

【讨论】：

这个建议对我没有帮助...如果 OP 具有相同的 issue I had，那么两个 Time 实例（starts 和 ends）实际上是相同的，甚至没有微秒的差异。