Provide proper SQL execution time information in logs

The current implementation relies on a monkeypatch
because the current upstream implementation doesn't
respect a possibly already present duration info.

TODO: Look into providing a proper patch for
active_support/notifications so that we don't need
to keep on monkeypatching forever.

[#1296 state:resolved]

lib/dm-rails/railties/log_listener.rb

@@ -1,3 +1,28 @@
+require 'active_support/notifications'
+
+# TODO This needs to be fixed upstream in active_support/notifications/instrumenter.rb
+#
+# We need to monkeypatch this for now, because the original implementation hardcodes the
+# duration to the time elapsed between start and end of the event. The current upstream
+# implementation is included here for reference:
+#
+#   def duration
+#     @duration ||= 1000.0 * (@end - @time)
+#   end
+#
+# It should be safe to assume that explicitly provided duration information should be at
+# least as precise as the current generic solution, if not more (as in our specific case).
+#
+module ActiveSupport
+  module Notifications
+    class Event
+      def duration
+        @duration ||= payload[:duration] ? (payload[:duration] / 1000.0) : 1000.0 * (@end - @time)
+      end
+    end
+  end
+end
+
 module LogListener
   def log(message)
     ActiveSupport::Notifications.instrument('sql.data_mapper',