diff --git a/bin/vagrant b/bin/vagrant index 8cc7a9d6e..d78b9825a 100755 --- a/bin/vagrant +++ b/bin/vagrant @@ -5,6 +5,10 @@ require 'vagrant/cli' env = Vagrant::Environment.new begin + # Begin logging early here + env.logger.info "`vagrant` invoked: #{ARGV.inspect}" + + # Disable color if the proper argument was passed shell = ARGV.include?("--no-color") ? Thor::Shell::Basic.new : Thor::Base.shell.new # Set the UI early in case any errors are raised, and load diff --git a/lib/vagrant/action.rb b/lib/vagrant/action.rb index 032199895..73b609962 100644 --- a/lib/vagrant/action.rb +++ b/lib/vagrant/action.rb @@ -129,6 +129,7 @@ module Vagrant end # We place a process lock around every action that is called + env.logger.info "Running action: #{callable_id}" env.lock do Busy.busy(int_callback) { callable.call(action_environment) } end diff --git a/lib/vagrant/action/warden.rb b/lib/vagrant/action/warden.rb index 68e5dbc99..73be36053 100644 --- a/lib/vagrant/action/warden.rb +++ b/lib/vagrant/action/warden.rb @@ -25,13 +25,16 @@ module Vagrant # Call the next middleware in the sequence, appending to the stack # of "recoverable" middlewares in case something goes wrong! raise Errors::VagrantInterrupt if env.interrupted? - @stack.unshift(@actions.shift).first.call(env) + action = @actions.shift + env["logger"].info("warden") { "Calling action: #{action}" } + @stack.unshift(action).first.call(env) raise Errors::VagrantInterrupt if env.interrupted? rescue SystemExit # This means that an "exit" or "abort" was called. In these cases, # we just exit immediately. raise rescue Exception => e + env["logger"].info("warden") { "Error occurred: #{e}" } env["vagrant.error"] = e # Something went horribly wrong. Start the rescue chain then @@ -46,7 +49,10 @@ module Vagrant # which has already run, in reverse order. def begin_rescue(env) @stack.each do |act| - act.recover(env) if act.respond_to?(:recover) + if act.respond_to?(:recover) + env["logger"].info("warden") { "Calling recover: #{act}" } + act.recover(env) + end end # Clear stack so that warden down the middleware chain doesn't diff --git a/lib/vagrant/environment.rb b/lib/vagrant/environment.rb index d36f6e2da..053cf8d4a 100644 --- a/lib/vagrant/environment.rb +++ b/lib/vagrant/environment.rb @@ -309,7 +309,7 @@ module Vagrant # Create the logger and custom formatter @logger = Logger.new(output) @logger.formatter = Proc.new do |severity, datetime, progname, msg| - "#{datetime} - [#{resource}] #{msg}\n" + "#{datetime} - #{progname} - [#{resource}] #{msg}\n" end @logger