Resource logger now has a thread-safe progress meter built-in

lib/vagrant/resource_logger.rb

@@ -1,3 +1,5 @@
+require 'thread'
+
 module Vagrant
   # Represents a logger for a specific resource within Vagrant. Each
   # logger should be initialized and set to represent a single
@@ -8,8 +10,15 @@ module Vagrant
   #
   # This class is thread safe. The backing class which actually does
   # all the logging IO is protected.
+  #
+  # This class also handles progress meters of multiple resources and
+  # handles all the proper interleaving and console updating to
+  # display the progress meters in a way which doesn't conflict with
+  # other incoming log messages.
   class ResourceLogger
     @@singleton_logger = nil
+    @@progress_reporters = nil
+    @@writer_lock = Mutex.new
 
     # The resource which this logger represents.
     attr_reader :resource
@@ -23,6 +32,9 @@ module Vagrant
     attr_reader :logger
 
     class << self
+      # Returns a singleton logger. If one has not yet be
+      # instantiated, then the given environment will be used to
+      # create a new logger.
       def singleton_logger(env=nil)
         if env && env.config && env.config.loaded?
           @@singleton_logger ||= Util::PlainLogger.new(env.config.vagrant.log_output)
@@ -31,9 +43,16 @@ module Vagrant
         end
       end
 
+      # Resets the singleton logger (only used for testing).
       def reset_singleton_logger!
         @@singleton_logger = nil
       end
+
+      # Returns the progress parts array which contains the various
+      # progress reporters.
+      def progress_reporters
+        @@progress_reporters ||= {}
+      end
     end
 
     def initialize(resource, env)
@@ -45,7 +64,63 @@ module Vagrant
     # TODO: The other logging methods.
 
     def info(message)
-      logger.info("[#{resource}] #{message}")
+      @@writer_lock.synchronize do
+        # We clear the line in case progress reports have been going
+        # out.
+        print(cl_reset)
+        logger.info("[#{resource}] #{message}")
+      end
+
+      # Once again flush the progress reporters since we probably
+      # cleared any existing ones.
+      flush_progress
+    end
+
+    # Sets a progress report for the resource that this logger
+    # represents. This progress report is interleaved within the output.
+    def report_progress(progress, total, show_parts=true)
+      # Simply add the progress reporter to the list of progress
+      # reporters
+      self.class.progress_reporters[resource] = {
+        :progress => progress,
+        :total => total,
+        :show_parts => show_parts
+      }
+
+      # And force an update to occur
+      flush_progress
+    end
+
+    # Clears the progress report for this resource
+    def clear_progress
+      self.class.progress_reporters.delete(resource)
+    end
+
+    def flush_progress
+      # Don't do anything if there are no progress reporters
+      return if self.class.progress_reporters.length <= 0
+
+      @@writer_lock.synchronize do
+        reports = []
+
+        # First generate all the report percentages and output
+        self.class.progress_reporters.each do |name, data|
+          percent = (data[:progress].to_f / data[:total].to_f) * 100
+          line = "#{name}: #{percent.to_i}%"
+          line << " (#{data[:progress]} / #{data[:total]})" if data[:show_parts]
+          reports << line
+        end
+
+        # Output it to stdout
+        print "#{cl_reset}[progress] #{reports.join(" ")}"
+        $stdout.flush
+      end
+    end
+
+    def cl_reset
+      reset = "\r"
+      reset += "\e[0K" unless Mario::Platform.windows?
+      reset
     end
   end
 end

lib/vagrant/util/progress_meter.rb

@@ -30,4 +30,4 @@ module Vagrant
       end
     end
   end
-end
+end

test/test_helper.rb

@@ -79,6 +79,8 @@ class Test::Unit::TestCase
     # calls will recreate it for us.
     environment.load_logger!
     environment.logger.class.reset_singleton_logger!
+    environment.logger.stubs(:flush_progress)
+    environment.logger.stubs(:cl_reset).returns("")
 
     environment
   end
@@ -105,7 +107,7 @@ class Test::Unit::TestCase
     mock_vm.stubs(:invoke_around_callback).yields
     mock_vm.stubs(:actions).returns([action])
     mock_vm.stubs(:env).returns(mock_environment)
-    mock_vm.env.stubs(:logger).returns(Vagrant::ResourceLogger.new("mock", nil))
+    mock_vm.env.stubs(:logger).returns(quiet_logger("mock"))
 
     mock_ssh = Vagrant::SSH.new(mock_vm.env)
     mock_ssh.stubs(:execute)
@@ -117,6 +119,14 @@ class Test::Unit::TestCase
     [mock_vm, vm, action]
   end
 
+  # Returns a resource logger which is safe for tests
+  def quiet_logger(resource, env=nil)
+    logger = Vagrant::ResourceLogger.new(resource, env)
+    logger.stubs(:flush_progress)
+    logger.stubs(:cl_reset).returns("")
+    logger
+  end
+
   # Returns a linux system
   def linux_system(vm)
     Vagrant::Systems::Linux.new(vm)

test/vagrant/resource_logger_test.rb

@@ -71,6 +71,10 @@ class ResourceLoggerTest < Test::Unit::TestCase
     end
 
     context "logging methods" do
+      setup do
+        @instance.stubs(:flush_progress)
+      end
+
       should "log with the proper format" do
         message = "bar"
         @logger.expects(:info).with("[#{@resource}] #{message}").once
@@ -78,5 +82,58 @@ class ResourceLoggerTest < Test::Unit::TestCase
         @instance.info(message)
       end
     end
+
+    context "reporting progress" do
+      setup do
+        @instance.stubs(:flush_progress)
+      end
+
+      should "flush progress" do
+        @instance.expects(:flush_progress).once
+        @instance.report_progress(72, 100)
+      end
+
+      should "add the reporter to the progress reporters" do
+        @instance.report_progress(72, 100)
+        assert @klass.progress_reporters.has_key?(@instance.resource)
+      end
+    end
+
+    context "clearing progress" do
+      setup do
+        @instance.stubs(:flush_progress)
+
+        @klass.progress_reporters.clear
+        @instance.report_progress(72, 100)
+      end
+
+      should "remove the key from the reporters" do
+        assert @klass.progress_reporters.has_key?(@instance.resource)
+        @instance.clear_progress
+        assert !@klass.progress_reporters.has_key?(@instance.resource)
+      end
+    end
+
+    context "command line reset" do
+      context "on windows" do
+        setup do
+          Mario::Platform.forced = Mario::Platform::Windows7
+        end
+
+        should "just return \\r for the clear screen" do
+          assert_equal  "\r", @instance.cl_reset
+        end
+      end
+
+      context "on other platforms" do
+        setup do
+          Mario::Platform.forced = Mario::Platform::Linux
+        end
+
+        should "return the full clear screen" do
+          assert_equal "\r\e[0K", @instance.cl_reset
+        end
+      end
+    end
   end
 end