improve how logging is handled

lib/listen/internals/logging.rb

@@ -0,0 +1,31 @@
+require 'celluloid/logger'
+
+module Listen
+  module Internals
+    module Logging
+      def _info(*args)
+        _log(:info, *args)
+      end
+
+      def _warn(*args)
+        _log(:warn, *args)
+      end
+
+      def _debug(*args)
+        _log(:debug, *args)
+      end
+
+      def _log(*args)
+        Celluloid::Logger.send(*args)
+      end
+
+      def _format_error(fmt)
+        format(fmt, $ERROR_INFO, ", Backtrace: \n" + $ERROR_POSITION * "\n")
+      end
+
+      def _error_exception(fmt)
+        _log :error, _format_error(fmt)
+      end
+    end
+  end
+end

lib/listen/listener.rb

@@ -6,6 +6,8 @@
 require 'listen/queue_optimizer'
 require 'English'
 
+require 'listen/internals/logging'
+
 module Listen
   class Listener
     include Celluloid::FSM
@@ -39,8 +41,8 @@ def initialize(*args, &block)
       # Setup logging first
       if Celluloid.logger
         Celluloid.logger.level = _debug_level
-        _log :info, "Celluloid loglevel set to: #{Celluloid.logger.level}"
-        _log :info, "Listen version: #{Listen::VERSION}"
+        _info "Celluloid loglevel set to: #{Celluloid.logger.level}"
+        _info "Listen version: #{Listen::VERSION}"
       end
 
       @silencer = Silencer.new
@@ -173,6 +175,8 @@ def queue(type, change, dir, path, options = {})
 
     private
 
+    include Internals::Logging
+
     def _init_options(options = {})
       { debug: false,
         latency: nil,
@@ -240,9 +244,7 @@ def _wait_for_changes
         _process_changes unless state == :paused
       end
     rescue RuntimeError
-      Kernel.warn format(
-        "Listen warning: exception in processing events: %s\nBacktrace:\n\t%s",
-        $ERROR_INFO, $ERROR_POSITION * "\n\t")
+      Kernel.warn _format_error('exception while processing events: %s %s')
     end
 
     def _silenced?(path, type)
@@ -255,10 +257,6 @@ def _start_adapter
       adapter.start
     end
 
-    def _log(type, message)
-      Celluloid::Logger.send(type, message)
-    end
-
     def _adapter_class
       @adapter_class ||= Adapter.select(options)
     end
@@ -280,7 +278,7 @@ def _process_changes
       block_start = Time.now.to_f
       # TODO: condition not tested, but too complex to test ATM
       block.call(*result) unless result.all?(&:empty?)
-      _log :debug, "Callback took #{Time.now.to_f - block_start} seconds"
+      _debug "Callback took #{Time.now.to_f - block_start} seconds"
     end
 
     attr_reader :wait_thread
@@ -332,17 +330,16 @@ def _stop_wait_thread
     end
 
     def _queue_raw_change(type, dir, rel_path, options)
-      _log :debug, "raw queue: #{[type, dir, rel_path, options].inspect}"
+      _debug "raw queue: #{[type, dir, rel_path, options].inspect}"
 
       unless (worker = async(:change_pool))
-        _log :warn, 'Failed to allocate worker from change pool'
+        _warn 'Failed to allocate worker from change pool'
         return
       end
 
       worker.change(type, dir, rel_path, options)
     rescue RuntimeError
-      _log :error, format('%s crashed: %s:%s', __method__, $ERROR_INFO,
-                          $ERROR_POSITION * "\n")
+      _error_exception "_queue_raw_change exception %s:\n%s:\n"
       raise
     end
   end

spec/acceptance/listen_spec.rb

@@ -23,8 +23,7 @@
 
       it 'warns the backtrace' do
         expect(Kernel).to receive(:warn).
-          with('[Listen warning]: Change block raised an exception: foo')
-        expect(Kernel).to receive(:warn).with(/^Backtrace:.*/)
+          with(/exception while processing events: foo .*Backtrace:/)
         wrapper.listen { touch 'file.rb' }
       end
     end