Fix colorized log alignment. (#349)

* Fix colorized log alignment.

CHANGELOG.md

@@ -8,6 +8,8 @@ appear at the top.
   * Add your entries below here, remember to credit yourself however you want
     to be credited!
   * Known hosts lookup optimization is now enabled by default. @byroot
+  * Fixed colorized output alignment in Logger::Pretty. @xavierholt
+    [PR #349](https://github.com/capistrano/sshkit/pull/349)
 
 ## 1.10.0 (2016-04-22)
 

lib/sshkit/formatters/pretty.rb

@@ -34,7 +34,7 @@ def log_command_data(command, stream_type, stream_data)
 
       def log_command_exit(command)
         runtime = sprintf('%5.3f seconds', command.runtime)
-        successful_or_failed =  command.failure? ? colorize('failed', :red, :bold) : colorize('successful', :green, :bold)
+        successful_or_failed = command.failure? ? colorize('failed', :red, :bold) : colorize('successful', :green, :bold)
         message = "Finished in #{runtime} with exit status #{command.exit_status} (#{successful_or_failed})."
         write_message(command.verbosity, message, command.uuid)
       end
@@ -43,8 +43,8 @@ def log_command_exit(command)
 
       def format_message(verbosity, message, uuid=nil)
         message = "[#{colorize(uuid, :green)}] #{message}" unless uuid.nil?
-        level = colorize(Pretty::LEVEL_NAMES[verbosity], Pretty::LEVEL_COLORS[verbosity])
-        '%6s %s' % [level, message]
+        level = colorize(LEVEL_NAMES[verbosity].rjust(6), LEVEL_COLORS[verbosity])
+        "#{level} #{message}"
       end
 
       private

test/unit/formatters/test_pretty.rb

@@ -18,12 +18,12 @@ def pretty
     end
 
     {
-      log:   "\e[0;34;49mINFO\e[0m Test\n",
-      fatal: "\e[0;31;49mFATAL\e[0m Test\n",
-      error: "\e[0;31;49mERROR\e[0m Test\n",
-      warn:  "\e[0;33;49mWARN\e[0m Test\n",
-      info:  "\e[0;34;49mINFO\e[0m Test\n",
-      debug: "\e[0;30;49mDEBUG\e[0m Test\n"
+      log:   "\e[0;34;49m  INFO\e[0m Test\n",
+      fatal: "\e[0;31;49m FATAL\e[0m Test\n",
+      error: "\e[0;31;49m ERROR\e[0m Test\n",
+      warn:  "\e[0;33;49m  WARN\e[0m Test\n",
+      info:  "\e[0;34;49m  INFO\e[0m Test\n",
+      debug: "\e[0;30;49m DEBUG\e[0m Test\n"
     }.each do |level, expected_output|
       define_method("test_#{level}_output_with_color") do
         output.stubs(:tty?).returns(true)
@@ -37,11 +37,11 @@ def test_command_lifecycle_logging_with_color
       simulate_command_lifecycle(pretty)
 
       expected_log_lines = [
-        "\e[0;34;49mINFO\e[0m [\e[0;32;49maaaaaa\e[0m] Running \e[1;33;49m/usr/bin/env a_cmd some args\e[0m as \e[0;34;49muser\e[0m@\e[0;34;49mlocalhost\e[0m",
-        "\e[0;30;49mDEBUG\e[0m [\e[0;32;49maaaaaa\e[0m] Command: \e[0;34;49m/usr/bin/env a_cmd some args\e[0m",
-        "\e[0;30;49mDEBUG\e[0m [\e[0;32;49maaaaaa\e[0m] \e[0;32;49m\tstdout message\e[0m",
-        "\e[0;30;49mDEBUG\e[0m [\e[0;32;49maaaaaa\e[0m] \e[0;31;49m\tstderr message\e[0m",
-        "\e[0;34;49mINFO\e[0m [\e[0;32;49maaaaaa\e[0m] Finished in 1.000 seconds with exit status 0 (\e[1;32;49msuccessful\e[0m)."
+        "\e[0;34;49m  INFO\e[0m [\e[0;32;49maaaaaa\e[0m] Running \e[1;33;49m/usr/bin/env a_cmd some args\e[0m as \e[0;34;49muser\e[0m@\e[0;34;49mlocalhost\e[0m",
+        "\e[0;30;49m DEBUG\e[0m [\e[0;32;49maaaaaa\e[0m] Command: \e[0;34;49m/usr/bin/env a_cmd some args\e[0m",
+        "\e[0;30;49m DEBUG\e[0m [\e[0;32;49maaaaaa\e[0m] \e[0;32;49m\tstdout message\e[0m",
+        "\e[0;30;49m DEBUG\e[0m [\e[0;32;49maaaaaa\e[0m] \e[0;31;49m\tstderr message\e[0m",
+        "\e[0;34;49m  INFO\e[0m [\e[0;32;49maaaaaa\e[0m] Finished in 1.000 seconds with exit status 0 (\e[1;32;49msuccessful\e[0m)."
       ]
       assert_equal expected_log_lines, output.split("\n")
     end