Merge pull request #935 from chef/better_logging

Better debug logging

lib/ohai/plugins/azure.rb

@@ -24,14 +24,14 @@
     # project for details
     azure_metadata_from_hints = hint?("azure")
     if azure_metadata_from_hints
-      Ohai::Log.debug("azure plugin: azure_metadata_from_hints is present.")
+      Ohai::Log.debug("Plugin Azure: azure_metadata_from_hints is present.")
       azure Mash.new
       azure_metadata_from_hints.each { |k, v| azure[k] = v }
     elsif has_waagent? || has_dhcp_option_245?
-      Ohai::Log.debug("azure plugin: No hints present, but system appears to be on azure.")
+      Ohai::Log.debug("Plugin Azure: No hints present, but system appears to be on azure.")
       azure Mash.new
     else
-      Ohai::Log.debug("azure plugin: No hints present for azure and doesn't appear to be azure.")
+      Ohai::Log.debug("Plugin Azure: No hints present for azure and doesn't appear to be azure.")
       false
     end
   end
@@ -40,7 +40,7 @@
   # http://blog.mszcool.com/index.php/2015/04/detecting-if-a-virtual-machine-runs-in-microsoft-azure-linux-windows-to-protect-your-software-when-distributed-via-the-azure-marketplace/
   def has_waagent?
     if File.exist?("/usr/sbin/waagent") || Dir.exist?('C:\WindowsAzure')
-      Ohai::Log.debug("azure plugin: Found waagent used by MS Azure.")
+      Ohai::Log.debug("Plugin Azure: Found waagent used by MS Azure.")
       return true
     end
   end
@@ -50,7 +50,7 @@ def has_dhcp_option_245?
     if File.exist?("/var/lib/dhcp/dhclient.eth0.leases")
       File.open("/var/lib/dhcp/dhclient.eth0.leases").each do |line|
         if line =~ /unknown-245/
-          Ohai::Log.debug("azure plugin: Found unknown-245 DHCP option used by MS Azure.")
+          Ohai::Log.debug("Plugin Azure: Found unknown-245 DHCP option used by MS Azure.")
           has_245 = true
           break
         end

lib/ohai/plugins/c.rb

@@ -28,10 +28,10 @@ def collect(cmd, &block)
     if so.exitstatus == 0
       yield(so)
     else
-      Ohai::Log.debug("Plugin C '#{cmd}' failed. Skipping data.")
+      Ohai::Log.debug("Plugin C: '#{cmd}' failed. Skipping data.")
     end
   rescue Ohai::Exceptions::Exec
-    Ohai::Log.debug("Plugin C '#{cmd}' binary could not be found. Skipping data.")
+    Ohai::Log.debug("Plugin C: '#{cmd}' binary could not be found. Skipping data.")
   end
 
   collect_data do

lib/ohai/plugins/dmi.rb

@@ -92,34 +92,34 @@
 
       elsif type = type_line.match(line)
         if dmi_record == nil
-          Ohai::Log.debug("unexpected data line found before header; discarding:\n#{line}")
+          Ohai::Log.debug("Plugin DMI: unexpected data line found before header; discarding:\n#{line}")
           next
         end
         dmi[dmi_record[:type]][:all_records][dmi_record[:position]][:application_identifier] = type[1]
 
       elsif data = data_line.match(line)
         if dmi_record == nil
-          Ohai::Log.debug("unexpected data line found before header; discarding:\n#{line}")
+          Ohai::Log.debug("Plugin DMI: unexpected data line found before header; discarding:\n#{line}")
           next
         end
         dmi[dmi_record[:type]][:all_records][dmi_record[:position]][data[1]] = data[2]
         field = data[1]
 
       elsif extended_data = extended_data_line.match(line)
         if dmi_record == nil
-          Ohai::Log.debug("unexpected extended data line found before header; discarding:\n#{line}")
+          Ohai::Log.debug("Plugin DMI: unexpected extended data line found before header; discarding:\n#{line}")
           next
         end
         if field == nil
-          Ohai::Log.debug("unexpected extended data line found outside data section; discarding:\n#{line}")
+          Ohai::Log.debug("Plugin DMI: unexpected extended data line found outside data section; discarding:\n#{line}")
           next
         end
         # overwrite "raw" value with a new Mash
         dmi[dmi_record[:type]][:all_records][dmi_record[:position]][field] = Mash.new unless dmi[dmi_record[:type]][:all_records][dmi_record[:position]][field].class.to_s == "Mash"
         dmi[dmi_record[:type]][:all_records][dmi_record[:position]][field][extended_data[1]] = nil
 
       else
-        Ohai::Log.debug("unrecognized output line; discarding:\n#{line}")
+        Ohai::Log.debug("Plugin DMI: unrecognized output line; discarding:\n#{line}")
 
       end
     end

lib/ohai/plugins/groovy.rb

@@ -32,7 +32,7 @@
         languages[:groovy] = groovy
       end
     rescue Ohai::Exceptions::Exec
-      Ohai::Log.debug('Groovy plugin: Could not shell_out "groovy -v". Skipping plugin')
+      Ohai::Log.debug('Plugin Groovy: Could not shell_out "groovy -v". Skipping plugin')
     end
   end
 end

lib/ohai/plugins/haskell.rb

@@ -39,7 +39,7 @@
         haskell[:ghc][:description] = so.stdout.chomp
       end
     rescue Ohai::Exceptions::Exec
-      Ohai::Log.debug('Haskell plugin: Could not shell_out "ghc --version". Skipping data')
+      Ohai::Log.debug('Plugin Haskell: Could not shell_out "ghc --version". Skipping data')
     end
 
     # Check for ghci
@@ -54,7 +54,7 @@
         haskell[:ghci][:description] = so.stdout.chomp
       end
     rescue Ohai::Exceptions::Exec
-      Ohai::Log.debug('Haskell plugin: Could not shell_out "ghci --version". Skipping data')
+      Ohai::Log.debug('Plugin Haskell: Could not shell_out "ghci --version". Skipping data')
     end
 
     # Check for cabal
@@ -70,7 +70,7 @@
         haskell[:cabal][:description] = so.stdout.split("\n")[0].chomp
       end
     rescue Ohai::Exceptions::Exec
-      Ohai::Log.debug('Haskell plugin: Could not shell_out "cabal --version". Skipping data')
+      Ohai::Log.debug('Plugin Haskell: Could not shell_out "cabal --version". Skipping data')
     end
 
     # Check for stack
@@ -87,7 +87,7 @@
         haskell[:stack][:description] = so.stdout.chomp
       end
     rescue Ohai::Exceptions::Exec
-      Ohai::Log.debug('Haskell plugin: Could not shell_out "stack --version". Skipping data')
+      Ohai::Log.debug('Plugin Haskell: Could not shell_out "stack --version". Skipping data')
     end
 
     languages[:haskell] = haskell unless haskell.empty?

lib/ohai/plugins/hostname.rb

@@ -120,19 +120,19 @@ def sigar_is_available?
       # Sometimes... very rarely, but sometimes, 'hostname --fqdn' falsely
       # returns a blank string. WTF.
       if ourfqdn.nil? || ourfqdn.empty?
-        Ohai::Log.debug("hostname returned an empty string, retrying once.")
+        Ohai::Log.debug("Plugin Hostname: hostname returned an empty string, retrying once.")
         ourfqdn = resolve_fqdn
       end
 
       if ourfqdn.nil? || ourfqdn.empty?
-        Ohai::Log.debug("hostname returned an empty string twice and will" +
+        Ohai::Log.debug("Plugin Hostname: hostname returned an empty string twice and will" +
                         "not be set.")
       else
         fqdn ourfqdn
       end
     rescue
       Ohai::Log.debug(
-        "hostname returned an error, probably no domain set")
+        "Plugin Hostname: hostname returned an error, probably no domain set")
     end
     domain collect_domain
   end
@@ -152,20 +152,20 @@ def sigar_is_available?
       # Sometimes... very rarely, but sometimes, 'hostname --fqdn' falsely
       # returns a blank string. WTF.
       if ourfqdn.nil? || ourfqdn.empty?
-        Ohai::Log.debug("hostname --fqdn returned an empty string, retrying " +
+        Ohai::Log.debug("Plugin Hostname: hostname --fqdn returned an empty string, retrying " +
                         "once.")
         ourfqdn = from_cmd("hostname --fqdn")
       end
 
       if ourfqdn.nil? || ourfqdn.empty?
-        Ohai::Log.debug("hostname --fqdn returned an empty string twice and " +
+        Ohai::Log.debug("Plugin Hostname: hostname --fqdn returned an empty string twice and " +
                         "will not be set.")
       else
         fqdn ourfqdn
       end
     rescue
       Ohai::Log.debug(
-        "hostname --fqdn returned an error, probably no domain set")
+        "Plugin Hostname: hostname --fqdn returned an error, probably no domain set")
     end
     domain collect_domain
   end

lib/ohai/plugins/ip_scopes.rb

@@ -43,7 +43,7 @@
 
     rescue LoadError => e
       # our favourite gem is not installed. Boohoo.
-      Ohai::Log.debug("Plugin ip_scopes: cannot load gem, plugin disabled: #{e}")
+      Ohai::Log.debug("Plugin IpScopes: cannot load gem, plugin disabled: #{e}")
     end
   end
 

lib/ohai/plugins/linux/network.rb

@@ -80,7 +80,7 @@ def check_routing_table(family, iface, default_route_table)
     so = shell_out("ip -o -f #{family[:name]} route show table #{default_route_table}")
     so.stdout.lines do |line|
       line.strip!
-      Ohai::Log.debug("Parsing #{line}")
+      Ohai::Log.debug("Plugin Network: Parsing #{line}")
       if line =~ /\\/
         parts = line.split('\\')
         route_dest = parts.shift.strip
@@ -95,13 +95,13 @@ def check_routing_table(family, iface, default_route_table)
         if route_ending =~ /\bdev\s+([^\s]+)\b/
           route_int = $1
         else
-          Ohai::Log.debug("Skipping route entry without a device: '#{line}'")
+          Ohai::Log.debug("Plugin Network: Skipping route entry without a device: '#{line}'")
           next
         end
         route_int = "venet0:0" if is_openvz? && !is_openvz_host? && route_int == "venet0" && iface["venet0:0"]
 
         unless iface[route_int]
-          Ohai::Log.debug("Skipping previously unseen interface from 'ip route show': #{route_int}")
+          Ohai::Log.debug("Plugin Network: Skipping previously unseen interface from 'ip route show': #{route_int}")
           next
         end
 
@@ -118,7 +118,7 @@ def check_routing_table(family, iface, default_route_table)
           addr = iface[route_int][:addresses]
           unless addr.nil? || addr.has_key?(route_entry[:src]) ||
               addr.values.all? { |a| a["family"] != family[:name] }
-            Ohai::Log.debug("Skipping route entry whose src does not match the interface IP")
+            Ohai::Log.debug("Plugin Network: Skipping route entry whose src does not match the interface IP")
             next
           end
         end
@@ -156,7 +156,7 @@ def ethernet_layer_one(iface)
       so = shell_out("#{ethtool_binary} #{tmp_int}")
       so.stdout.lines do |line|
         line.chomp!
-        Ohai::Log.debug("Parsing ethtool output: #{line}")
+        Ohai::Log.debug("Plugin Network: Parsing ethtool output: #{line}")
         line.lstrip!
         k, v = line.split(": ")
         next unless keys.include? k
@@ -177,7 +177,7 @@ def ethernet_ring_parameters(iface)
     iface.each_key do |tmp_int|
       next unless iface[tmp_int][:encapsulation] == "Ethernet"
       so = shell_out("#{ethtool_binary} -g #{tmp_int}")
-      Ohai::Log.debug("Parsing ethtool output: #{so.stdout}")
+      Ohai::Log.debug("Plugin Network: Parsing ethtool output: #{so.stdout}")
       type = nil
       iface[tmp_int]["ring_params"] = {}
       so.stdout.lines.each do |line|
@@ -462,7 +462,7 @@ def favored_default_route(routes, iface, default_route, family)
     else
       default_route_table = configuration(:default_route_table)
     end
-    Ohai::Log.debug("default route table is '#{default_route_table}'")
+    Ohai::Log.debug("Plugin Network: default route table is '#{default_route_table}'")
 
     # Match the lead line for an interface from iproute2
     # 3: eth0.11@eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP
@@ -507,14 +507,14 @@ def favored_default_route(routes, iface, default_route, family)
                            else
                              "default_#{family[:name]}_interface"
                            end
-          Ohai::Log.debug("Unable to determine '#{attribute_name}' as no default routes were found for that interface family")
+          Ohai::Log.debug("Plugin Network: Unable to determine '#{attribute_name}' as no default routes were found for that interface family")
         else
           network["#{default_prefix}_interface"] = default_route[:dev]
-          Ohai::Log.debug("#{default_prefix}_interface set to #{default_route[:dev]}")
+          Ohai::Log.debug("Plugin Network: #{default_prefix}_interface set to #{default_route[:dev]}")
 
           # setting gateway to 0.0.0.0 or :: if the default route is a link level one
           network["#{default_prefix}_gateway"] = default_route[:via] ? default_route[:via] : family[:default_route].chomp("/0")
-          Ohai::Log.debug("#{default_prefix}_gateway set to #{network["#{default_prefix}_gateway"]}")
+          Ohai::Log.debug("Plugin Network: #{default_prefix}_gateway set to #{network["#{default_prefix}_gateway"]}")
 
           # deduce the default route the user most likely cares about to pick {ip,mac,ip6}address below
           favored_route = favored_default_route(routes, iface, default_route, family)
@@ -527,20 +527,20 @@ def favored_default_route(routes, iface, default_route, family)
             if family[:name] == "inet"
               ipaddress favored_route[:src]
               m = get_mac_for_interface(iface, favored_route[:dev])
-              Ohai::Log.debug("Overwriting macaddress #{macaddress} with #{m} from interface #{favored_route[:dev]}") if macaddress
+              Ohai::Log.debug("Plugin Network: Overwriting macaddress #{macaddress} with #{m} from interface #{favored_route[:dev]}") if macaddress
               macaddress m
             elsif family[:name] == "inet6"
               # this rarely does anything since we rarely have src for ipv6, so this usually falls back on the network plugin
               ip6address favored_route[:src]
               if macaddress
-                Ohai::Log.debug("Not setting macaddress from ipv6 interface #{favored_route[:dev]} because macaddress is already set")
+                Ohai::Log.debug("Plugin Network: Not setting macaddress from ipv6 interface #{favored_route[:dev]} because macaddress is already set")
               else
                 macaddress get_mac_for_interface(iface, favored_route[:dev])
               end
             end
           else
-            Ohai::Log.debug("the linux/network plugin was unable to deduce the favored default route for family '#{family[:name]}' despite finding a default route, and is not setting ipaddress/ip6address/macaddress. the network plugin may provide fallbacks.")
-            Ohai::Log.debug("this potential default route was excluded: #{default_route}")
+            Ohai::Log.debug("Plugin Network: Unable to deduce the favored default route for family '#{family[:name]}' despite finding a default route, and is not setting ipaddress/ip6address/macaddress. the network plugin may provide fallbacks.")
+            Ohai::Log.debug("Plugin Network: This potential default route was excluded: #{default_route}")
           end
         end
       end # end families.each
@@ -550,7 +550,7 @@ def favored_default_route(routes, iface, default_route, family)
         route_result = so.stdout.split($/).grep( /^0.0.0.0/ )[0].split( /[ \t]+/ )
         network[:default_gateway], network[:default_interface] = route_result.values_at(1, 7)
       rescue Ohai::Exceptions::Exec
-        Ohai::Log.debug("Unable to determine default interface")
+        Ohai::Log.debug("Plugin Network: Unable to determine default interface")
       end
 
       so = shell_out("ifconfig -a")

lib/ohai/plugins/linux/sessions.rb

@@ -45,6 +45,8 @@
           sessions[:by_user][user] = [s]
         end
       end
+    else
+      Ohai::Log.debug("Plugin Sessions: Could not find loginctl. Skipping plugin.")
     end
   end
 end