Watcher: logging/debugging facility, pipes watcher debug logs out to Spring application logger

Author: jeremy

lib/spring/application.rb

@@ -66,7 +66,17 @@ def initialized?
 
     def start_watcher
       @watcher = Spring.watcher
-      @watcher.on_stale { state! :watcher_stale }
+
+      @watcher.on_stale do
+        state! :watcher_stale
+      end
+
+      if @watcher.respond_to? :on_debug
+        @watcher.on_debug do |message|
+          spring_env.log "[watcher:#{app_env}] #{message}"
+        end
+      end
+
       @watcher.start
     end
 

lib/spring/watcher/abstract.rb

@@ -23,9 +23,21 @@ def initialize(root, latency)
         @directories = Set.new
         @stale       = false
         @listeners   = []
+
+        @on_debug    = nil
+      end
+
+      def on_debug(&block)
+        @on_debug = block
+      end
+
+      def debug
+        @on_debug.call(yield) if @on_debug
       end
 
       def add(*items)
+        debug { "watcher: add: #{items.inspect}" }
+
         items = items.flatten.map do |item|
           item = Pathname.new(item)
 
@@ -56,16 +68,19 @@ def stale?
       end
 
       def on_stale(&block)
+        debug { "added listener: #{block.inspect}" }
         @listeners << block
       end
 
       def mark_stale
         return if stale?
         @stale = true
+        debug { "marked stale, calling listeners: listeners=#{@listeners.inspect}" }
         @listeners.each(&:call)
       end
 
       def restart
+        debug { "restarting" }
         stop
         start
       end

lib/spring/watcher/polling.rb

@@ -12,7 +12,13 @@ def initialize(root, latency)
       end
 
       def check_stale
-        synchronize { mark_stale if mtime < compute_mtime }
+        synchronize do
+          computed = compute_mtime
+          if mtime < computed
+            debug { "check_stale: mtime=#{mtime.inspect} < computed=#{computed.inspect}" }
+            mark_stale
+          end
+        end
       end
 
       def add(*)
@@ -21,27 +27,38 @@ def add(*)
       end
 
       def start
+        debug { "start: poller=#{@poller.inspect}" }
         unless @poller
           @poller = Thread.new {
             Thread.current.abort_on_exception = true
 
-            loop do
-              Kernel.sleep latency
-              check_stale
+            begin
+              loop do
+                Kernel.sleep latency
+                check_stale
+              end
+            rescue Exception => e
+              debug do
+                "poller: aborted: #{e.class}: #{e}\n  #{e.backtrace.join("\n  ")}"
+              end
+              raise
             end
           }
         end
       end
 
       def stop
+        debug { "stopping poller: #{@poller.inspect}" }
         if @poller
           @poller.kill
           @poller = nil
         end
       end
 
       def subjects_changed
-        @mtime = compute_mtime
+        computed = compute_mtime
+        debug { "subjects_changed: mtime #{@mtime} -> #{computed}" }
+        @mtime = computed
       end
 
       private