Added log subscriber.

lib/toy/instrumentation/log_subscriber.rb

@@ -0,0 +1,54 @@
+require 'securerandom'
+require 'active_support/notifications'
+require 'active_support/log_subscriber'
+
+module Toy
+  module Instrumentation
+    class LogSubscriber < ::ActiveSupport::LogSubscriber
+      SaveAction   = 'save'
+      CreateAction = 'create'
+      UpdateAction = 'update'
+
+      def read(event)
+        return unless logger.debug?
+        log_event :read, event
+      end
+
+      def read_multiple(event)
+        return unless logger.debug?
+        log_event :read_multiple, event
+      end
+
+      def key(event)
+        return unless logger.debug?
+        log_event :key, event
+      end
+
+      def create(event)
+        return unless logger.debug?
+        log_event :create, event
+      end
+
+      def update(event)
+        return unless logger.debug?
+        log_event :update, event
+      end
+
+      def destroy(event)
+        return unless logger.debug?
+        log_event :destroy, event
+      end
+
+      def log_event(action, event)
+        id = event.payload[:id]
+        model = event.payload[:model]
+
+        name = '%s (%.1fms)' % ["#{model.name} #{action}", event.duration]
+
+        debug "  #{color(name, CYAN, true)}  [ #{id.inspect} ]"
+      end
+    end
+  end
+end
+
+Toy::Instrumentation::LogSubscriber.attach_to :toystore

spec/toy/instrumentation/log_subscriber_spec.rb

@@ -0,0 +1,85 @@
+require 'helper'
+require 'toy/instrumentation/log_subscriber'
+
+describe Toy::Instrumentation::LogSubscriber do
+  uses_constants('User')
+
+  before do
+    Toy.instrumenter = ActiveSupport::Notifications
+    @io = StringIO.new
+    Toy::Instrumentation::LogSubscriber.logger = Logger.new(@io)
+  end
+
+  after do
+    Toy::Instrumentation::LogSubscriber.logger = nil
+  end
+
+  let(:log) { @io.string }
+
+  context "creating a new record" do
+    before do
+      clear_logs
+      @user = User.create
+    end
+
+    it "logs" do
+      log.should match(/User create/)
+      log.should match(/\[ #{@user.id.inspect} \]/)
+    end
+  end
+
+  context "updating a record" do
+    before do
+      User.attribute :name, String
+      @user = User.create(:name => 'Old Name')
+      clear_logs
+      @user.update_attributes(:name => 'New Name')
+    end
+
+    it "logs" do
+      log.should match(/User update/)
+      log.should match(/\[ #{@user.id.inspect} \]/)
+    end
+  end
+
+  context "finding a record" do
+    before do
+      clear_logs
+      User.read('blah')
+    end
+
+    it "logs" do
+      log.should match(/User read/)
+      log.should match(/\[ #{'blah'.inspect} \]/)
+    end
+  end
+
+  context "destroying a record" do
+    before do
+      @user = User.create
+      clear_logs
+      @user.destroy
+    end
+
+    it "logs" do
+      log.should match(/User destroy/)
+      log.should match(/\[ #{@user.id.inspect} \]/)
+    end
+  end
+
+  context "checking if a record exists" do
+    before do
+      clear_logs
+      User.key?('blah')
+    end
+
+    it "logs" do
+      log.should match(/User key/)
+      log.should match(/\[ #{'blah'.inspect} \]/)
+    end
+  end
+
+  def clear_logs
+    @io.string = ''
+  end
+end