cleaned up logging, and much improved error message when file is not found

10 files changed, 102 insertions, 93 deletions

diff --git a/lib/leap_cli/commands/ca.rb b/lib/leap_cli/commands/ca.rb
index 94a173c..e0b57da 100644
--- a/lib/leap_cli/commands/ca.rb
+++ b/lib/leap_cli/commands/ca.rb
@@ -87,11 +87,11 @@ module LeapCli; module Commands
     c.action do |global_options,options,args|
       long_running do
         if cmd_exists?('certtool')
-          progress('Generating DH parameters (takes a long time)...')
+          log 0, 'Generating DH parameters (takes a long time)...'
           output = assert_run!('certtool --generate-dh-params --sec-param high')
           write_file!(:dh_params, output)
         else
-          progress('Generating DH parameters (takes a REALLY long time)...')
+          log 0, 'Generating DH parameters (takes a REALLY long time)...'
           output = OpenSSL::PKey::DH.generate(3248).to_pem
           write_file!(:dh_params, output)
         end
diff --git a/lib/leap_cli/commands/deploy.rb b/lib/leap_cli/commands/deploy.rb
index 13fcb1d..84c7846 100644
--- a/lib/leap_cli/commands/deploy.rb
+++ b/lib/leap_cli/commands/deploy.rb
@@ -56,7 +56,7 @@ module LeapCli
         statuses.strip.split("\n").each do |status_line|
           if status_line =~ /^-/
             submodule = status_line.split(' ')[1]
-            progress "Updating submodule #{submodule}"
+            log "Updating submodule #{submodule}"
             assert_run! "git submodule update --init #{submodule}"
           end
         end
diff --git a/lib/leap_cli/commands/node.rb b/lib/leap_cli/commands/node.rb
index 4956d64..61e463b 100644
--- a/lib/leap_cli/commands/node.rb
+++ b/lib/leap_cli/commands/node.rb
@@ -26,7 +26,7 @@ module LeapCli; module Commands
         ssh.install_authorized_keys
         ssh.install_prerequisites
       end
-      progress("Completed: init-node #{node.name}")
+      log("Completed: init-node #{node.name}")
     end
   end
 
@@ -87,17 +87,17 @@ module LeapCli; module Commands
   # see `man sshd` for the format of known_hosts
   #
   def save_public_host_key(node)
-    progress("Fetching public SSH host key for #{node.name}")
+    log("Fetching public SSH host key for #{node.name}")
     public_key = get_public_key_for_ip(node.ip_address, node.ssh.port)
     pub_key_path = Path.named_path([:node_ssh_pub_key, node.name])
     if Path.exists?(pub_key_path)
       if public_key == SshKey.load_from_file(pub_key_path)
-        progress("Public SSH host key for #{node.name} has not changed")
+        log("Public SSH host key for #{node.name} has not changed")
       else
         bail!("WARNING: The public SSH host key we just fetched for #{node.name} doesn't match what we have saved previously. Remove the file #{pub_key_path} if you really want to change it.")
       end
     elsif public_key.in_known_hosts?(node.name, node.ip_address, node.domain.name)
-      progress("Public SSH host key for #{node.name} is trusted (key found in your ~/.ssh/known_hosts)")
+      log("Public SSH host key for #{node.name} is trusted (key found in your ~/.ssh/known_hosts)")
     else
       puts
       say("This is the SSH host key you got back from node \"#{node.name}\"")
@@ -123,7 +123,7 @@ module LeapCli; module Commands
   end
 
   def ping_node(node)
-    progress("Pinging #{node.name}")
+    log("Pinging #{node.name}")
     assert_run!("ping -W 1 -c 1 #{node.ip_address}", "Could not ping #{node.name} (address #{node.ip_address}). Try again, we only send a single ping.")
   end
 
diff --git a/lib/leap_cli/commands/user.rb b/lib/leap_cli/commands/user.rb
index 22ed9c9..aed29b7 100644
--- a/lib/leap_cli/commands/user.rb
+++ b/lib/leap_cli/commands/user.rb
@@ -94,7 +94,7 @@ module LeapCli
     def pick_pgp_key
       secret_keys = GPGME::Key.find(:secret)
       if secret_keys.empty?
-        progress("Skipping OpenPGP setup because I could not find any OpenPGP keys for you")
+        log "Skipping OpenPGP setup because I could not find any OpenPGP keys for you"
         return nil
       end
 
@@ -126,7 +126,7 @@ module LeapCli
         buffer << " "
         buffer << ssh_key
         buffer << " "
-        buffer << relative_path(keyfile)
+        buffer << Path.relative_path(keyfile)
         buffer << "\n"
       end
       write_file!(:authorized_keys, buffer.string)
diff --git a/lib/leap_cli/commands/vagrant.rb b/lib/leap_cli/commands/vagrant.rb
index 07bb863..4a480ff 100644
--- a/lib/leap_cli/commands/vagrant.rb
+++ b/lib/leap_cli/commands/vagrant.rb
@@ -48,7 +48,7 @@ module LeapCli; module Commands
   end
 
   def execute(cmd)
-    progress2 "Running: #{cmd}"
+    log 2, :run, cmd
     exec cmd
   end
 
diff --git a/lib/leap_cli/config/manager.rb b/lib/leap_cli/config/manager.rb
index 00b4ec5..7406f1c 100644
--- a/lib/leap_cli/config/manager.rb
+++ b/lib/leap_cli/config/manager.rb
@@ -140,7 +140,7 @@ module LeapCli
           return Config::Object.new(self)
         end
 
-        progress2("loading %s" % filename)
+        log :loading, filename, 2
 
         #
         # read file, strip out comments
@@ -158,8 +158,8 @@ module LeapCli
         begin
           hash = JSON.parse(buffer.string, :object_class => Hash, :array_class => Array) || {}
         rescue SyntaxError => exc
-          log0 'Error in file "%s":' % filename
-          log0 exc.to_s
+          log 0, :error, 'in file "%s":' % filename
+          log 0, exc.to_s, :indent => 1
           return nil
         end
         object = Config::Object.new(self)
@@ -198,7 +198,7 @@ module LeapCli
           node['services'].to_a.sort.each do |node_service|
             service = @services[node_service]
             if service.nil?
-              log0('Error in node "%s": the service "%s" does not exist.' % [node['name'], node_service])
+              log 0, :error, 'in node "%s": the service "%s" does not exist.' % [node['name'], node_service]
             else
               new_node.deep_merge!(service)
               service.node_list.add(name, new_node)
@@ -211,7 +211,7 @@ module LeapCli
           node['tags'].to_a.sort.each do |node_tag|
             tag = @tags[node_tag]
             if tag.nil?
-              log0('Error in node "%s": the tag "%s" does not exist.' % [node['name'], node_tag])
+              log 0, :error, 'in node "%s": the tag "%s" does not exist.' % [node['name'], node_tag]
             else
               new_node.deep_merge!(tag)
               tag.node_list.add(name, new_node)
diff --git a/lib/leap_cli/config/object.rb b/lib/leap_cli/config/object.rb
index 731f3ff..bf0452a 100644
--- a/lib/leap_cli/config/object.rb
+++ b/lib/leap_cli/config/object.rb
@@ -170,11 +170,16 @@ module LeapCli
         global.nodes
       end
 
+      class FileMissing < Exception; end
+
       #
       # inserts the contents of a file
       #
       def file(filename)
-        filepath = Path.find_file(@node.name, filename)
+        if filename.is_a? Symbol
+          filename = [filename, @node.name]
+        end
+        filepath = Path.find_file(filename)
         if filepath
           if filepath =~ /\.erb$/
             ERB.new(File.read(filepath), nil, '%<>').result(binding)
@@ -182,7 +187,7 @@ module LeapCli
             File.read(filepath)
           end
         else
-          log0('no such file, "%s"' % filename)
+          raise FileMissing.new(Path.named_path(filename))
           ""
         end
       end
@@ -213,16 +218,18 @@ module LeapCli
               value = @node.instance_eval($1) #, @node.send(:binding))
               self[key] = value
             rescue SystemStackError => exc
-              puts "STACK OVERFLOW, BAILING OUT"
-              puts "There must be an eval loop of death (variables with circular dependencies). This is the offending string:"
-              puts
-              puts "    #{$1}"
-              puts
+              log :error, "while evaluating node '#{@node.name}'"
+              log "offending string: #{$1}", :indent => 1
+              log "STACK OVERFLOW, BAILING OUT. There must be an eval loop of death (variables with circular dependencies)."
               raise SystemExit.new()
+           rescue FileMissing => exc
+              log :error, "while evaluating node '#{@node.name}'"
+              log "offending string: #{$1}", :indent => 1
+              log "error message: no file '#{exc}'", :indent => 1
             rescue StandardError => exc
-              puts "Eval error in '#{@node.name}'"
-              puts "   string: #{$1}"
-              puts "   error: #{exc.name}"
+              log :error, "while evaluating node '#{@node.name}'"
+              log "offending string: #{$1}", :indent => 1
+              log "error message: #{exc}", :indent => 1
             end
           end
           value
diff --git a/lib/leap_cli/log.rb b/lib/leap_cli/log.rb
index 0cba54d..1266caf 100644
--- a/lib/leap_cli/log.rb
+++ b/lib/leap_cli/log.rb
@@ -1,10 +1,10 @@
+require 'paint'
+
 module LeapCli
   extend self
-
   def log_level
     @log_level ||= 1
   end
-
   def log_level=(value)
     @log_level = value
   end
@@ -14,38 +14,55 @@ end
 ## LOGGING
 ##
 
-def log0(message=nil, &block)
-  if message
-    puts message
-  elsif block
-    puts yield(block)
-  end
-end
+#
+# these are log titles typically associated with files
+#
+FILE_TITLES = [:updated, :created, :removed, :missing, :nochange, :loading]
 
-def log1(message=nil, &block)
-  if LeapCli.log_level > 0
-    if message
-      puts message
-    elsif block
-      puts yield(block)
+#
+# master logging function.
+#
+# arguments can be a String, Integer, Symbol, or Hash, in any order.
+#
+# * String: treated as the message to log.
+# * Integer: the log level (0, 1, 2)
+# * Symbol: the prefix title to colorize. may be one of
+#   [:error, :warning, :info, :updated, :created, :removed, :no_change, :missing]
+# * Hash: a hash of options. so far, only :indent is supported.
+#
+def log(*args)
+  level   = args.grep(Integer).first || 1
+  title   = args.grep(Symbol).first
+  message = args.grep(String).first
+  options = args.grep(Hash).first || {:indent => 0}
+  if message && LeapCli.log_level >= level
+    print "  " * (options[:indent]+1)
+    if options[:indent] > 0
+      print '- '
+    else
+      print '= '
     end
-  end
-end
-
-def log2(message=nil, &block)
-  if LeapCli.log_level > 1
-    if message
-      puts message
-    elsif block
-      puts yield(block)
+    if title
+      prefix = case title
+        when :error     then Paint['error', :red, :bold]
+        when :warning   then Paint['warning', :yellow, :bold]
+        when :info      then Paint['info', :cyan, :bold]
+        when :updated   then Paint['updated', :cyan, :bold]
+        when :created   then Paint['created', :green, :bold]
+        when :removed   then Paint['removed', :red, :bold]
+        when :nochange  then Paint['no change', :magenta]
+        when :loading   then Paint['loading', :magenta]
+        when :missing   then Paint['missing', :yellow, :bold]
+        when :run       then Paint['run', :magenta]
+        when :failed    then Paint['FAILED', :red, :bold]
+        when :ran       then Paint['ran', :green, :bold]
+        else ""
+      end
+      print "#{prefix} "
+      if FILE_TITLES.include?(title) && message =~ /^\//
+        message = LeapCli::Path.relative_path(message)
+      end
     end
+    puts "#{message}"
   end
 end
-
-def progress(message)
-  log1("  = " + message)
-end
-
-def progress2(message)
-  log2("  = " + message)
-end
diff --git a/lib/leap_cli/path.rb b/lib/leap_cli/path.rb
index 48b0d11..ed4e478 100644
--- a/lib/leap_cli/path.rb
+++ b/lib/leap_cli/path.rb
@@ -105,14 +105,14 @@ module LeapCli; module Path
   end
 
   #
-  # tries to find a file somewhere with 'filename', under a directory 'name' if possible.
+  # tries to find a file somewhere with 'filename' (which is probably in the form [node.name, filename])
   #
-  def self.find_file(name, filename)
+  def self.find_file(filename)
     # named path?
-    if filename.is_a? Symbol
-      path = named_path([filename, name], platform_provider)
+    if filename.is_a? Array
+      path = named_path(filename, platform_provider)
       return path if File.exists?(path)
-      path = named_path([filename, name], provider)
+      path = named_path(filename, provider)
       return path if File.exists?(path)
     end
 
@@ -162,6 +162,11 @@ module LeapCli; module Path
     File.exists?(named_path(name, provider_dir))
   end
 
+  def self.relative_path(path)
+    path = named_path(path)
+    path.sub(/^#{Regexp.escape(provider)}\//,'')
+  end
+
   private
 
   def self.find_in_directory_tree(filename)
diff --git a/lib/leap_cli/util.rb b/lib/leap_cli/util.rb
index f163387..bd8b04b 100644
--- a/lib/leap_cli/util.rb
+++ b/lib/leap_cli/util.rb
@@ -60,11 +60,11 @@ module LeapCli
       cmd = cmd + " 2>&1"
       output = `#{cmd}`
       unless $?.success?
-        progress("run: #{cmd}")
-        progress(Paint["FAILED", :red] + ": (exit #{$?.exitstatus}) #{output}")
+        log :run, cmd
+        log :failed, "(exit #{$?.exitstatus}) #{output}"
         bail!
       else
-        progress2(Paint["ran",:green] + ": #{cmd}")
+        log 2, :ran, cmd
       end
       return output
     end
@@ -73,7 +73,7 @@ module LeapCli
       options = files.last.is_a?(Hash) ? files.pop : {}
       file_list = files.collect { |file_path|
         file_path = Path.named_path(file_path)
-        File.exists?(file_path) ? relative_path(file_path) : nil
+        File.exists?(file_path) ? Path.relative_path(file_path) : nil
       }.compact
       if file_list.length > 1
         bail! "Sorry, we can't continue because these files already exist: #{file_list.join(', ')}. You are not supposed to remove these files. Do so only with caution."
@@ -96,7 +96,7 @@ module LeapCli
       options = files.last.is_a?(Hash) ? files.pop : {}
       file_list = files.collect { |file_path|
         file_path = Path.named_path(file_path)
-        !File.exists?(file_path) ? relative_path(file_path) : nil
+        !File.exists?(file_path) ? Path.relative_path(file_path) : nil
       }.compact
       if file_list.length > 1
         bail! "Sorry, you are missing these files: #{file_list.join(', ')}. #{options[:msg]}"
@@ -109,26 +109,6 @@ module LeapCli
     ## FILES AND DIRECTORIES
     ##
 
-    def relative_path(path)
-      path.sub(/^#{Regexp.escape(Path.provider)}\//,'')
-    end
-
-    def progress_created(path)
-      progress Paint['created', :green, :bold] + ' ' + relative_path(path)
-    end
-
-    def progress_updated(path)
-      progress Paint['updated', :cyan, :bold] + ' ' + relative_path(path)
-    end
-
-    def progress_nochange(path)
-      progress2 Paint['no change', :white, :bold] + ' ' + relative_path(path)
-    end
-
-    def progress_removed(path)
-      progress Paint['removed', :red, :bold] + ' ' + relative_path(path)
-    end
-
     #
     # creates a directory if it doesn't already exist
     #
@@ -141,7 +121,7 @@ module LeapCli
           unless dir =~ /\/$/
             dir = dir + '/'
           end
-          progress_created dir
+          log :created, dir
         end
       end
     end
@@ -188,7 +168,7 @@ module LeapCli
       filepath = Path.named_path(filepath)
       if File.exists?(filepath)
         File.unlink(filepath)
-        progress_removed(filepath)
+        log :removed, filepath
       end
     end
 
@@ -198,7 +178,7 @@ module LeapCli
       existed = File.exists?(filepath)
       if existed
         if file_content_equals?(filepath, contents)
-          progress_nochange filepath
+          log :nochange, filepath, 2
           return
         end
       end
@@ -208,9 +188,9 @@ module LeapCli
       end
 
       if existed
-        progress_updated filepath
+        log :updated, filepath
       else
-        progress_created filepath
+        log :created, filepath
       end
     end