spec/support/client_forker.rb in zk-1.4.2 vs spec/support/client_forker.rb in zk-1.5.0

@@ -12,32 +12,62 @@
     @cnx_args  = cnx_args
     @base_path = base_path
     @pids_root = "#{@base_path}/pid"
   end
 
+  LBORDER = ('-' * 35) << '< '
+  RBORDER = ' >' << ('-' * 35) 
+
+  def mark(thing)
+    logger << "\n#{LBORDER}#{thing}#{RBORDER}\n\n"
+  end
+
+  def mark_around(thing)
+    mark "#{thing}: ENTER"
+    yield
+  ensure
+    mark "#{thing}: EXIT"
+  end
+
   def before
-    ZK.open(*cnx_args) do |z|
-      z.rm_rf(@base_path)
-      z.mkdir_p(@pids_root)
+    mark_around('BEFORE') do
+      ZK.open(*cnx_args) do |z|
+        z.rm_rf(@base_path)
+        z.mkdir_p(@pids_root)
+      end
     end
   end
 
   def tear_down
-    @zk.rm_rf(@base_path)
-    @zk.close! unless @zk.closed?
+    mark_around('TEAR_DOWN') do
+      @zk.close! if @zk and !@zk.closed?
+      ZK.open(*cnx_args) { |z| z.rm_rf(@base_path) }
+    end
   end
 
   def kill_child!
     return unless @pid
     Process.kill('TERM', @pid)
     pid, st = Process.wait2(@pid)
     logger.debug { "child #{@pid} exited with status: #{st.inspect}" }
   rescue Errno::ESRCH
   end
 
+  CLEAR      = "\e[0m".freeze
+  YELLOW     = "\e[33m".freeze    # Set the terminal's foreground ANSI color to yellow.
+
+  def yellow_log_formatter()
+    orig_formatter = ::Logger::Formatter.new
+
+    proc do |s,dt,pn,msg|
+      "#{CLEAR}#{YELLOW}#{orig_formatter.call(s,dt,pn,msg)}#{CLEAR}"
+    end
+  end
+
   def run
     before
+    mark 'BEGIN TEST'
 
     logger.debug { "Process.pid of parent: #{Process.pid}" }
 
     @zk = ZK.new(*cnx_args) do |z|
       z.on_connected do
@@ -49,11 +79,11 @@
       end
     end
 
     @parent_pid = $$
     
-    @zk.create("#{@pids_root}/#{$$}", $$.to_s)
+    @zk.create("#{@pids_root}/#{$$}", $$.to_s, :ignore => :node_exists)
 
     event_catcher = EventCatcher.new
 
     @zk.register(@pids_root) do |event|
       if event.node_child?
@@ -64,12 +94,18 @@
     end
 
     logger.debug { "parent watching for children on #{@pids_root}" }
     @zk.children(@pids_root, :watch => true)  # side-effect, register watch
 
+    ZK.install_fork_hook
+
+    mark 'FORK'
+
     @pid = fork do
-      @zk.reopen
+      Thread.abort_on_exception = true
+      ::Logging.reopen
+
       @zk.wait_until_connected
 
       child_pid_path = "#{@pids_root}/#{$$}"
 
       create_latch = Zookeeper::Latch.new
@@ -89,11 +125,15 @@
       if @zk.exists?(child_pid_path, :watch => true)
         logger.debug { "woot! #{child_pid_path} exists!" }
         create_sub.unregister
       else
         logger.debug { "awaiting the create_latch to release" }
-        create_latch.await
+        create_latch.await(2) 
+        unless @zk.exists?(child_pid_path)
+          logger.debug { require 'pp'; PP.pp(@zk.event_handler, '') }
+          raise "child pid path not created after 2 sec"
+        end
       end
 
       logger.debug { "now testing for delete event totally created in child" }
 
       delete_latch = Zookeeper::Latch.new
@@ -150,9 +190,10 @@
 
     _, @stat = Process.wait2(@pid)
 
 #     $stderr.puts "#{@pid} exited with status: #{stat.inspect}"
   ensure
+    mark "END TEST"
     kill_child!
     tear_down
   end
 end