From: Tyler Riddle <t.riddle@shadowcat.co.uk>
Date: Wed, 5 Sep 2012 23:02:10 +0000 (-0700)
Subject: detailed probe logs
X-Git-Url: http://git.shadowcat.co.uk/gitweb/gitweb.cgi?a=commitdiff_plain;h=9aa46b04b85fac9a539428e48032c11e68148317;p=scpubgit%2FSystem-Introspector.git

detailed probe logs
---

diff --git a/lib/System/Introspector/Config.pm b/lib/System/Introspector/Config.pm
index 898f1b3..028e7ae 100644
--- a/lib/System/Introspector/Config.pm
+++ b/lib/System/Introspector/Config.pm
@@ -11,6 +11,7 @@ sub _build_config {
     my ($self) = @_;
     my $reader = Config::General->new($self->config_file);
     my %config = $reader->getall;
+        
     return \%config;
 }
 
diff --git a/lib/System/Introspector/Gatherer.pm b/lib/System/Introspector/Gatherer.pm
index 8cd708c..42466f3 100644
--- a/lib/System/Introspector/Gatherer.pm
+++ b/lib/System/Introspector/Gatherer.pm
@@ -11,25 +11,39 @@ has introspectors => (is => 'ro', required => 1);
 sub gather_all {
     my ($self) = @_;
     my %report;
+    
+    log_trace { "gather_all() has been invoked" };
         
     for my $spec (@{ $self->introspectors }) {
         my ($base, $args) = @$spec;
         my $module = "System::Introspector::Probe::$base";
-        log_trace { "Using '$module' for this gather" };
-        $report{$base} = use_module($module)
-            ->new($args)
-            ->gather;
+        log_debug { "Using '$module' for this gather" };
+        my $moduleName = use_module($module);
+        log_trace { "Finished loading '$module'; returned value was '$moduleName'" };
+        my $instance = $moduleName->new($args); 
+        log_trace { "Finished constructing '$moduleName'" };
+        $report{$base} = $instance->gather; 
+		log_trace { "Finished invocation of '$moduleName->gather()'" };  
     }
+    
+    log_trace { "gather_all() has completed" };
+    
     return \%report;
 }
 
 sub _new_direct {
     my ($class, $remote, $args) = @_;
+    
+    log_trace {"Using direct gatherer with '$remote'" }; 
+    
     return $class->new::on($remote, $args || {});
 }
 
 sub _new_bridged {
     my ($class, $bridge, $remote, $args) = @_;
+    
+    log_trace { "Building bridged gatherer for '$remote'" };
+    
     return System::Introspector::Gatherer::Bridge->new::on($bridge,
         remote_spec  => $remote,
         remote_class => $class,
diff --git a/lib/System/Introspector/Gatherer/Bridge.pm b/lib/System/Introspector/Gatherer/Bridge.pm
index 6efc985..bb34f78 100644
--- a/lib/System/Introspector/Gatherer/Bridge.pm
+++ b/lib/System/Introspector/Gatherer/Bridge.pm
@@ -2,7 +2,6 @@ package System::Introspector::Gatherer::Bridge;
 use Object::Remote;
 use Object::Remote::Future;
 use Moo;
-use System::Introspector::Logger::Remote qw( set_logger ); 
 
 has remote_spec => (is => 'ro', required => 1);
 has remote_class => (is => 'ro', required => 1);
@@ -11,12 +10,7 @@ has remote => (is => 'lazy');
 
 sub _build_remote {
     my ($self) = @_;
-    my $logger = System::Introspector::Logger::Remote->new({ env_prefix => 'SYSTEM_INTROSPECTOR_LOG' }); 
-    
-    #TODO: this doesn't work because it's not respected on the
-    #remote side
-    set_logger($logger); 
-    
+        
     return $self->remote_class
         ->new::on($self->remote_spec, $self->remote_args);
 }
diff --git a/lib/System/Introspector/Logger.pm b/lib/System/Introspector/Logger.pm
index 45d26a4..9033be7 100644
--- a/lib/System/Introspector/Logger.pm
+++ b/lib/System/Introspector/Logger.pm
@@ -5,9 +5,10 @@ BEGIN { $ENV{SYSTEM_INTROSPECTOR_LOG_UPTO} = "TRACE" unless exists $ENV{SYSTEM_I
 package System::Introspector::Logger;
 
 use base qw(Log::Contextual);
-use System::Introspector::Logger::Local;
+use System::Introspector::Logger::Output;
+use Log::Contextual qw( set_logger );
 
-sub arg_default_logger { $_[1] || System::Introspector::Logger::Local->new({
+sub arg_default_logger { $_[1] || System::Introspector::Logger::Output->new({
       env_prefix => 'SYSTEM_INTROSPECTOR_LOG',
 }) };
 
diff --git a/lib/System/Introspector/Logger/Local.pm b/lib/System/Introspector/Logger/Local.pm
deleted file mode 100644
index c3d432f..0000000
--- a/lib/System/Introspector/Logger/Local.pm
+++ /dev/null
@@ -1,18 +0,0 @@
-use strictures 1; 
-
-package System::Introspector::Logger::Local; 
-
-use base qw ( Log::Contextual::WarnLogger );
-
-sub _log {
-  my $self    = shift;
-  my $level   = shift;
-  my $message = join( "\n", @_ );
-  my @timedata = localtime;
-  my $time = sprintf("%0.2i:%0.2i:%0.2i", $timedata[2], $timedata[1], $timedata[0]);
-  $message .= "\n" unless $message =~ /\n$/;
-  warn "[local $level $time] $message";
-}
-
-1;
-
diff --git a/lib/System/Introspector/Logger/Output.pm b/lib/System/Introspector/Logger/Output.pm
new file mode 100644
index 0000000..97a26ce
--- /dev/null
+++ b/lib/System/Introspector/Logger/Output.pm
@@ -0,0 +1,23 @@
+use strictures 1; 
+
+package System::Introspector::Logger::Output; 
+
+use base qw ( Log::Contextual::WarnLogger );
+
+sub _log {
+  my $self    = shift;
+  my $level   = shift;
+  my $message = join( "\n", @_ );
+  my @timedata = localtime;
+  my $time = sprintf("%0.2i:%0.2i:%0.2i", $timedata[2], $timedata[1], $timedata[0]);
+  $message .= "\n" unless $message =~ /\n$/;
+  our ($hostname);
+  #this is just a stub for right now - the configured hostname and the hostname the
+  #system reports don't have to match - the user would be expecting the configured name
+  $hostname = scalar(`hostname`) unless defined $hostname; 
+  chomp($hostname);
+  warn "[$level $time] [$hostname] $message";
+}
+
+1;
+
diff --git a/lib/System/Introspector/Logger/Probe.pm b/lib/System/Introspector/Logger/Probe.pm
deleted file mode 100644
index 3065c03..0000000
--- a/lib/System/Introspector/Logger/Probe.pm
+++ /dev/null
@@ -1,14 +0,0 @@
-use strictures 1; 
-
-BEGIN { $ENV{SYSTEM_INTROSPECTOR_PROBE_LOG_UPTO} = "TRACE" unless exists $ENV{SYSTEM_INTROSPECTOR_PROBE_LOG_UPTO} };
-
-package System::Introspector::Logger::Probe; 
-
-use base qw(System::Introspector::Logger);
-use System::Introspector::Logger::Remote;
-
-sub arg_package_logger { $_[1] || System::Introspector::Logger::Remote->new({
-      env_prefix => 'SYSTEM_INTROSPECTOR_PROBE_LOG',
-}) };
-
-1; 
\ No newline at end of file
diff --git a/lib/System/Introspector/Logger/Remote.pm b/lib/System/Introspector/Logger/Remote.pm
deleted file mode 100644
index 1e9a2c0..0000000
--- a/lib/System/Introspector/Logger/Remote.pm
+++ /dev/null
@@ -1,31 +0,0 @@
-use strictures 1; 
-
-package System::Introspector::Logger::Remote; 
-
-use base qw ( System::Introspector::Logger::Local );
-
-sub new {
-	my ($class, $args) = @_; 
-	my $spec = delete($args->{remote_spec});
-	my $self = $class->SUPER::new($args); 
-	
-	die "must specify 'remote_spec' of machine in arguments to new()" unless defined $spec; 
-	
-	$self->{si}->{remote_spec} = $spec; 
-	
-	return $self; 
-		
-}
-
-sub _log {
-  my $self    = shift;
-  my $level   = shift;
-  my $message = join( "\n", @_ );
-  my $time = localtime; 
-  my $remote = $self->{si}->{remote_spec};
-  $message .= "\n" unless $message =~ /\n$/;
-  warn "[remote:$remote $level $time] $message";
-}
-
-1;
-
diff --git a/lib/System/Introspector/Probe/DiskUsage.pm b/lib/System/Introspector/Probe/DiskUsage.pm
index e15de2c..90ecccd 100644
--- a/lib/System/Introspector/Probe/DiskUsage.pm
+++ b/lib/System/Introspector/Probe/DiskUsage.pm
@@ -1,17 +1,27 @@
 package System::Introspector::Probe::DiskUsage;
 use Moo;
 
+#this probe is a point of potential reliability issues 
+#df is prone to hang for long periods of time when faced with
+#errors on the devices that back filesystems it's trying to 
+#report on
+
 use System::Introspector::Util qw(
     lines_from_command
     transform_exceptions
 );
 
+use System::Introspector::Logger qw ( :log );
+
 with 'System::Introspector::Role::Probe';
 
 sub gather {
     my ($self) = @_;
+    log_debug { "Starting to gather disk usage information" };
     return transform_exceptions {
+  		log_trace { "Invoking df command" };
         my @lines = lines_from_command ['df', '-aP'];
+        log_trace { "df command has finished executing" };
         shift @lines; # header
         my @rows;
         for my $line (@lines) {
diff --git a/lib/System/Introspector/Probe/FileHandles.pm b/lib/System/Introspector/Probe/FileHandles.pm
index 2c5ec2b..fc05e48 100644
--- a/lib/System/Introspector/Probe/FileHandles.pm
+++ b/lib/System/Introspector/Probe/FileHandles.pm
@@ -6,14 +6,19 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw ( :log );
+
 with 'System::Introspector::Role::Probe';
 
 has lsof_command => (is => 'ro', default => sub { 'lsof' });
 
 sub gather {
     my ($self) = @_;
+    log_debug { "Gathering open file information" };
     return transform_exceptions {
+    	log_trace { "Invoking lsof" };
         my @lines = lines_from_command [$self->_lsof_command_call];
+        log_trace { "lsof has finished executing" };
         my @handles;
         for my $line (@lines) {
             chomp $line;
@@ -23,6 +28,7 @@ sub gather {
                 ($1, $2);
             } @fields };
         }
+        log_trace { "Completed gathering open file information" };
         return { handles => \@handles };
     };
 }
diff --git a/lib/System/Introspector/Probe/Groups.pm b/lib/System/Introspector/Probe/Groups.pm
index 4ed4f90..11ba9b8 100644
--- a/lib/System/Introspector/Probe/Groups.pm
+++ b/lib/System/Introspector/Probe/Groups.pm
@@ -6,14 +6,17 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw( :log );
+
 with 'System::Introspector::Role::Probe';
 
 sub gather {
     my ($self) = @_;
-        
+    log_debug { "Collecting group membership information" };     
     return transform_exceptions {
         my %group;
         my $fh = $self->_open_group_file;
+        log_trace { "Reading group file" };
         while (defined( my $line = <$fh> )) {
             chomp $line;
             next if !(length $line);
@@ -27,13 +30,14 @@ sub gather {
                 users   => $users,
             };
         }
-
+		log_trace { "Completed gathering group information" };
         return { groups => \%group };
     };
 }
 
 sub _open_group_file {
     my ($self) = @_;
+    log_trace { "opening /etc/group" }; 
     return handle_from_file '/etc/group';
 }
 
diff --git a/lib/System/Introspector/Probe/Host.pm b/lib/System/Introspector/Probe/Host.pm
index 0358d5e..c07ecb1 100644
--- a/lib/System/Introspector/Probe/Host.pm
+++ b/lib/System/Introspector/Probe/Host.pm
@@ -7,6 +7,7 @@ use System::Introspector::Util qw(
     output_from_file
     transform_exceptions
 );
+use System::Introspector::Logger qw ( :log );
 
 with 'System::Introspector::Role::Probe';
 
@@ -14,6 +15,7 @@ has hostname_file => (is => 'ro', default => sub {'/etc/hostname' });
 
 sub gather {
     my ($self) = @_;
+    log_debug { "Starting to gather host information" };
     return transform_exceptions {
         return {
             hostname => $self->_gather_hostname,
@@ -38,6 +40,7 @@ sub _gather_uname_info {
     my %uname;
     for my $field (@UnameFields) {
         (my $option = $field) =~ s{_}{-}g;
+        log_trace { "Invoking uname with option of '--$option'" }; 
         my $value = output_from_command [uname => "--$option"];
         chomp $value;
         $uname{ $field } = $value;
@@ -47,6 +50,7 @@ sub _gather_uname_info {
 
 sub _gather_hostname {
     my ($self) = @_;
+    log_trace { sprintf("Loading hostname info from '%s'", $self->hostname_file) }; 
     my $hostname = output_from_file $self->hostname_file;
     chomp $hostname;
     $hostname =~ s{(?:^\s+|\s+$)}{}g;
diff --git a/lib/System/Introspector/Probe/Hosts.pm b/lib/System/Introspector/Probe/Hosts.pm
index 5f1bd4d..f8861e3 100644
--- a/lib/System/Introspector/Probe/Hosts.pm
+++ b/lib/System/Introspector/Probe/Hosts.pm
@@ -6,6 +6,8 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw( :log );
+
 with 'System::Introspector::Role::Probe';
 
 has hosts_file => (
@@ -16,6 +18,8 @@ has hosts_file => (
 sub gather {
     my ($self) = @_;
     my $file = $self->hosts_file;
+    log_debug { "Starting to gather contents of hosts file" }; 
+    log_trace { "Using contents of '$file' as system host list" }; 
     return {
         hosts_file => transform_exceptions {
             return {
diff --git a/lib/System/Introspector/Probe/LibDirs/Perl.pm b/lib/System/Introspector/Probe/LibDirs/Perl.pm
index 015150b..7a6f73a 100644
--- a/lib/System/Introspector/Probe/LibDirs/Perl.pm
+++ b/lib/System/Introspector/Probe/LibDirs/Perl.pm
@@ -8,6 +8,10 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw( :log );
+
+with 'System::Introspector::Role::Probe';
+
 has root => (
     is      => 'ro',
     default => sub { '/' },
@@ -15,6 +19,7 @@ has root => (
 
 sub gather {
     my ($self) = @_;
+    log_debug { "Gathering Perl library information" }; 
     return transform_exceptions {
         my $pipe = $self->_open_locate_libdirs_pipe;
         my %libdir;
@@ -24,6 +29,7 @@ sub gather {
                 return { modules => $self->_gather_libdir_info($line) };
             };
         }
+        log_trace { "Completed gathering Perl library information" }; 
         return { libdirs_perl => \%libdir };
     };
 }
@@ -55,6 +61,7 @@ sub _gather_libdir_info {
 
 sub _open_locate_pm_pipe {
     my ($self, $libdir) = @_;
+  	log_debug { "Executing 'find' to search for Perl module files in '$libdir'" }; 
     return handle_from_command
         sprintf q{find %s -name '*.pm'}, $libdir;
 }
@@ -64,6 +71,7 @@ sub _open_locate_libdirs_pipe {
     my $root = $self->root;
     $root .= '/'
         unless $root =~ m{/$};
+    log_debug { "Executing 'locate' to identify Perl 5 library directories" };
     return handle_from_command sprintf
         q{locate --regex '^%s.*lib/perl5$'}, $root;
 }
diff --git a/lib/System/Introspector/Probe/MountPoints.pm b/lib/System/Introspector/Probe/MountPoints.pm
index 0423c62..4662a6f 100644
--- a/lib/System/Introspector/Probe/MountPoints.pm
+++ b/lib/System/Introspector/Probe/MountPoints.pm
@@ -6,10 +6,15 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw ( :log );
+
 with 'System::Introspector::Role::Probe';
 
 sub gather {
     my ($self) = @_;
+    
+    log_debug { "Starting to gather system mount point configuration" };
+    
     return {
         mtab => transform_exceptions {
             return { entries
@@ -24,12 +29,14 @@ sub gather {
 
 sub _open_fh {
     my ($self, $file) = @_;
+    log_debug { "Opening '$file' to use as mount point configuration source" };
     return handle_from_file $file;
 }
 
 sub _parse_tab_fh {
     my ($self, $fh) = @_;
     my @mounts;
+    log_trace { "Reading contents of tab file" };
     while (defined( my $line = <$fh> )) {
         chomp $line;
         next if $line =~ m{^\s*$}
@@ -52,6 +59,7 @@ sub _parse_tab_fh {
             },
         };
     }
+    log_trace { "Finished reading contents of tab file" };
     no warnings 'uninitialized';
     return [ sort {
         ($a->{device_name} cmp $b->{device_name})
diff --git a/lib/System/Introspector/Probe/Nagios/CheckMkAgent.pm b/lib/System/Introspector/Probe/Nagios/CheckMkAgent.pm
index 9016b2c..9998b15 100644
--- a/lib/System/Introspector/Probe/Nagios/CheckMkAgent.pm
+++ b/lib/System/Introspector/Probe/Nagios/CheckMkAgent.pm
@@ -6,10 +6,17 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw ( :log );
+
+with 'System::Introspector::Role::Probe';
+
 sub gather {
     my ($self) = @_;
+    log_debug { "Gathering Nagios mk agent info" };
     return transform_exceptions {
+        log_trace { "Collecting check_mk_agent output" };
         my @lines = $self->_get_check_mk_agent_output;
+        log_trace { "Done with check_mk_agent " };
         chomp @lines;
         my %plugin;
         my $current;
@@ -21,6 +28,7 @@ sub gather {
             next unless $current;
             push @$current, $line;
         }
+        log_trace { "Completed Nagios mk agent gather" }; 
         return { nagios_check_mk_agent => \%plugin };
     };
 }
diff --git a/lib/System/Introspector/Probe/Packages/Apt.pm b/lib/System/Introspector/Probe/Packages/Apt.pm
index 5de5813..76e3e6f 100644
--- a/lib/System/Introspector/Probe/Packages/Apt.pm
+++ b/lib/System/Introspector/Probe/Packages/Apt.pm
@@ -9,6 +9,10 @@ use System::Introspector::Util qw(
     files_from_dir
 );
 
+use System::Introspector::Logger qw ( :log );
+
+with 'System::Introspector::Role::Probe';
+
 has apt_lists_dir => (is => 'ro', builder => 1);
 has apt_update_after => (is => 'ro', default => sub { 86400 });
 has apt_update => (is => 'ro');
@@ -22,7 +26,8 @@ sub _build_apt_sources_dir { '/etc/apt/sources.list.d' }
 
 sub gather {
     my ($self) = @_;
-    return {
+    log_debug { "Starting to gather apt based package information" }; 
+    my $retval = {
         update => {
             last => $self->_last_apt_update,
             run => transform_exceptions {
@@ -39,6 +44,8 @@ sub gather {
             return { config => $self->_gather_sources };
         },
     };
+    log_trace { "Completed gathering apt based package information" }; 
+	return $retval;    
 }
 
 sub _last_apt_update {
@@ -52,23 +59,27 @@ sub _check_apt_state {
     my $threshold   = $self->apt_update_after;
     my $last_change = $self->_last_apt_update;
     return 'no'if ($last_change + $threshold) > time;
+    log_trace { "invoking apt-get update" }; 
     handle_from_command 'apt-get update';
     return 'yes';
 }
 
 sub _open_dpkg_query_pipe {
     my ($self) = @_;
+    log_trace { "invoking dpkg-query" }; 
     return handle_from_command 'dpkg-query --show';
 }
 
 sub _open_apt_get_upgrade_simulation_pipe {
     my ($self) = @_;
+    log_trace { "invoking apt-get simulated upgrade" };
     return handle_from_command 'apt-get -s upgrade';
 }
 
 sub _gather_sources {
     my ($self) = @_;
     my $sources_dir = $self->apt_sources_dir;
+    log_trace { "Gathering apt package source data from directory '$sources_dir'" };
     return {
         'sources_list' => $self->_fetch_source_list($self->apt_sources),
         'sources_list_dir' => (-e $sources_dir) ? transform_exceptions {
diff --git a/lib/System/Introspector/Probe/Perls.pm b/lib/System/Introspector/Probe/Perls.pm
index 432b397..0072b22 100644
--- a/lib/System/Introspector/Probe/Perls.pm
+++ b/lib/System/Introspector/Probe/Perls.pm
@@ -7,6 +7,8 @@ use System::Introspector::Util qw(
     fail
 );
 
+use System::Introspector::Logger qw( :log );
+
 has root => (
     is      => 'ro',
     default => sub { '/' },
@@ -16,6 +18,7 @@ with 'System::Introspector::Role::Probe';
 
 sub gather {
     my ($self) = @_;
+    log_debug { "Gathering installed Perl information" };
     return transform_exceptions {
         my @configs = $self->_find_possible_perl_configs;
         my %found;
@@ -30,6 +33,7 @@ sub gather {
             $found{$config} = $info
                 if defined $info;
         }
+        log_trace { "Completed with Perl searches" };
         return { perls => \%found };
     };
 }
diff --git a/lib/System/Introspector/Probe/Processes.pm b/lib/System/Introspector/Probe/Processes.pm
index 8e11add..f956393 100644
--- a/lib/System/Introspector/Probe/Processes.pm
+++ b/lib/System/Introspector/Probe/Processes.pm
@@ -8,6 +8,7 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw ( :log );
 
 # args is automatically included, since it has to be last
 my @Included = qw(
@@ -47,6 +48,8 @@ my @Included = qw(
 sub gather {
     my ($self) = @_;
     my @names = (@Included, 'args');
+    
+    log_debug { "Starting to gather running process information" };
         
     return transform_exceptions {
         my $pipe = $self->_open_ps_pipe;
@@ -72,6 +75,7 @@ sub gather {
 
 sub _open_ps_pipe {
     my ($self) = @_;
+    log_trace { "Invoking ps" };
     return handle_from_command sprintf
         'ps -eo %s',
         join(',', @Included, 'args');
diff --git a/lib/System/Introspector/Probe/Puppet.pm b/lib/System/Introspector/Probe/Puppet.pm
index 3f0b1c8..7f8f677 100644
--- a/lib/System/Introspector/Probe/Puppet.pm
+++ b/lib/System/Introspector/Probe/Puppet.pm
@@ -6,6 +6,8 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw( :log );
+
 with 'System::Introspector::Role::Probe';
 
 has classes_file => (
@@ -20,6 +22,9 @@ has resources_file => (
 
 sub gather {
     my ($self) = @_;
+    
+    log_debug { "Starting to gather Puppet information" };
+    
     return {
         classes     => $self->_gather_classes,
         resources   => $self->_gather_resources,
@@ -29,6 +34,7 @@ sub gather {
 sub _gather_resources {
     my ($self) = @_;
     return transform_exceptions {
+    	log_trace { sprintf "Reading contents of resource file '%s'", $self->resources_file };
         my @lines = output_from_file $self->resources_file;
         chomp @lines;
         return [ map {
@@ -42,6 +48,7 @@ sub _gather_resources {
 sub _gather_classes {
     my ($self) = @_;
     return transform_exceptions {
+    	log_trace { sprintf "Reading contents of classes file '%s'", $self->classes_file };
         my @lines = output_from_file $self->classes_file;
         chomp @lines;
         return \@lines;
diff --git a/lib/System/Introspector/Probe/Repositories/Git.pm b/lib/System/Introspector/Probe/Repositories/Git.pm
index 1ac056e..e17ab26 100644
--- a/lib/System/Introspector/Probe/Repositories/Git.pm
+++ b/lib/System/Introspector/Probe/Repositories/Git.pm
@@ -7,6 +7,10 @@ use System::Introspector::Util qw(
     lines_from_command
 );
 
+use System::Introspector::Logger qw( :log );
+
+with 'System::Introspector::Role::Probe';
+
 has root => (
     is      => 'ro',
     default => sub { '/' },
@@ -14,6 +18,7 @@ has root => (
 
 sub gather {
     my ($self) = @_;
+    log_debug { "Gathering data on Git repos" };
     return transform_exceptions {
         my $pipe = $self->_open_locate_git_config_pipe;
         my %location;
@@ -29,6 +34,7 @@ sub gather {
 
 sub _gather_git_info {
     my ($self, $config) = @_;
+    log_debug { "Found git repo config file '$config'" };
     return {
         config_file => $config,
         config      => transform_exceptions {
@@ -49,6 +55,7 @@ sub _gather_track_info {
 sub _find_tracking {
     my ($self, $dir) = @_;
     local $ENV{GIT_DIR} = $dir;
+    log_trace { "Invoking 'git for-each-ref' to find tracking info for '$dir'" };
     my @lines = lines_from_command
         ['git', 'for-each-ref',
             '--format', q{OK %(refname:short) %(upstream:short)},
@@ -80,6 +87,7 @@ sub _find_commit_count {
     return { __error__ => "No remote" }
         unless defined $remote;
     local $ENV{GIT_DIR} = $dir;
+    log_trace { "Invoking 'git log' local:'$local' remote:'$remote'" };
     my @lines = lines_from_command
         ['git', 'log', '--oneline', "$remote..$local"];
     return scalar @lines;
@@ -90,6 +98,7 @@ sub _find_changes {
     return { __error__ => "No remote" }
         unless defined $remote;
     local $ENV{GIT_DIR} = $dir;
+    log_trace { "Invoking 'git diff' local:'$local' remote:'$remote'" };
     my @lines = lines_from_command
         ['git', 'diff', '--name-only', $local, $remote];
     return \@lines;
@@ -109,12 +118,14 @@ sub _gather_git_config {
 
 sub _open_git_config_pipe {
     my ($self, $config) = @_;
+	log_trace { "Invoking 'git config' for file '$config'" }; 
     return handle_from_command "git config --file $config --list";
 }
 
 sub _open_locate_git_config_pipe {
     my ($self) = @_;
     (my $root = $self->root) =~ s{/$}{};
+    log_trace { "Invoking locate to find git repository location" };
     return handle_from_command sprintf
         q{locate --regex '^%s/.*\\.git/config$'}, $root;
 }
diff --git a/lib/System/Introspector/Probe/ResolvConf.pm b/lib/System/Introspector/Probe/ResolvConf.pm
index aff40a7..e69bb1b 100644
--- a/lib/System/Introspector/Probe/ResolvConf.pm
+++ b/lib/System/Introspector/Probe/ResolvConf.pm
@@ -5,6 +5,7 @@ use System::Introspector::Util qw(
     output_from_file
     transform_exceptions
 );
+use System::Introspector::Logger qw( :log );
 
 with 'System::Introspector::Role::Probe';
 
@@ -18,10 +19,10 @@ sub gather {
     return {
         resolv_conf_file => transform_exceptions {
             my $file = $self->resolv_conf_file;
-            return {
-                file_name => $file,
-                body => scalar output_from_file $file,
-            };
+   			log_debug { sprintf("Starting to gather host resolver configuration from '$file'") };
+   			my $buf = scalar output_from_file $file;
+   			log_trace { "Finished reading contents of file" };
+            return { file_name => $file, body => $buf };
         },
     };
 }
diff --git a/lib/System/Introspector/Probe/Sudoers.pm b/lib/System/Introspector/Probe/Sudoers.pm
index 1fc3277..a760851 100644
--- a/lib/System/Introspector/Probe/Sudoers.pm
+++ b/lib/System/Introspector/Probe/Sudoers.pm
@@ -8,6 +8,8 @@ use System::Introspector::Util qw(
     transform_exceptions
 );
 
+use System::Introspector::Logger qw( :log );
+
 with 'System::Introspector::Role::Probe';
 
 has sudoers_file => (
@@ -22,12 +24,15 @@ has hostname => (
 
 sub gather {
     my ($self) = @_;
+    log_debug { my $hostname = $self->hostname; chomp($hostname); sprintf("Gathering sudo data with file:'%s' hostname:'%s' ", $self->sudoers_file, $hostname) };
     my %file = $self->_gather_files($self->sudoers_file);
+    log_trace { "Completed gathering sudo data" };
     return \%file;
 }
 
 sub _gather_files {
     my ($self, $file) = @_;
+    log_trace { "gathering sudo information from file '$file'" }; 
     my $result = transform_exceptions {
         my @lines = output_from_file $file;
         my @result = ({ body => join '', @lines });
diff --git a/lib/System/Introspector/Probe/Users.pm b/lib/System/Introspector/Probe/Users.pm
index b844a69..e3bfdc0 100644
--- a/lib/System/Introspector/Probe/Users.pm
+++ b/lib/System/Introspector/Probe/Users.pm
@@ -10,15 +10,19 @@ use System::Introspector::Util qw(
     handle_from_file
 );
 
+use System::Introspector::Logger qw( :log );
+
 with 'System::Introspector::Role::Probe';
 
 has passwd_file => (is => 'ro', default => sub { '/etc/passwd' });
 
 sub gather {
     my ($self) = @_;
+    log_debug { "Gathering operating system user info from " . $self->passwd_file };   
     return transform_exceptions {
         my $fh = $self->_open_passwd_fh;
         my %user;
+        log_trace { "file is now open, starting to read" }; 
         while (defined( my $line = <$fh> )) {
             my $data = $self->_deparse_htpasswd_line($line);
             my $user = $data->{username};
@@ -34,14 +38,17 @@ sub gather {
             };
             $user{ $data->{username} } = $data;
         }
+        log_trace { "completed reading user information" };
         return { users => \%user };
     };
 }
 
 sub _gather_crontab {
     my ($self, $user) = @_;
+    log_trace { "Invoking crontab to get info for user '$user'" };
     my ($out, $err, $ok) = output_from_command
         ['crontab', '-u', $user, '-l'];
+	log_trace { "crontab has finished executing" }; 
     unless ($ok) {
         return {}
             if $err =~ m{^no crontab}i;
@@ -53,11 +60,17 @@ sub _gather_crontab {
 sub _gather_ssh_keys {
     my ($self, $user, $home) = @_;
     my $ssh_dir = "$home/.ssh";
-    my $ssh_authkeys = "$ssh_dir/authorized_keys";
-    return {
-        files => {},
-        authorized => { file_name => $ssh_authkeys, body => '' }
-    } unless -d $ssh_dir;
+    my $ssh_authkeys = "$ssh_dir/authorized_keys";   
+    
+    log_trace { "Checking ssh keys for user '$user'" }; 
+    
+    unless(-d $ssh_dir) {
+		log_trace { "User has no ssh directory" }; 
+		return {
+        	files => {},
+        	authorized => { file_name => $ssh_authkeys, body => '' }
+    	}   	
+    }
     my %key;
     for my $item (files_from_dir $ssh_dir) {
         next unless $item =~ m{\.pub$};
@@ -74,14 +87,17 @@ sub _gather_ssh_keys {
             body => scalar output_from_file $ssh_authkeys,
         };
     }) : { file_name => $ssh_authkeys, body => '' };
+    log_trace { "Finished with user ssh keys" };
     return { files => \%key, authorized => $auth_keys };
 }
 
 sub _gather_user_groups {
     my ($self, $user) = @_;
+    log_trace { "Gathering group membership for user '$user'" }; 
     my $groups = output_from_command [groups => $user];
     chomp $groups;
     $groups =~ s{^ .* : \s* }{}x;
+    log_trace { "Completed gathering group membership data" };
     return [split m{\s+}, $groups];
 }
 
diff --git a/lib/System/Introspector/State.pm b/lib/System/Introspector/State.pm
index 50512f7..9d20c80 100644
--- a/lib/System/Introspector/State.pm
+++ b/lib/System/Introspector/State.pm
@@ -20,14 +20,14 @@ sub gather {
     for my $group (@groups) {
         my @waiting;
         for my $host ($self->config->hosts) {
-            log_trace { "Adding group '$group' on '$host' to waiting list" };
+            log_debug { "Adding group '$group' on '$host' to list of active fetches" };
             push @waiting, [$host, $self->fetch($host, $group)];
         }
-        log_debug { sprintf("Waiting for results to become available for %i groups", scalar(@waiting)) };
+        log_debug { sprintf("There are %i hosts in the waiting list", scalar(@waiting)) };
         for my $wait (@waiting) {
             my ($host, @futures) = @$wait;
             
-            log_trace { "Waiting for futures on host '$host'" };
+            log_debug { "Waiting on futures for host '$host'" };
             
             my @data = await_all @futures;
             log_trace { "Received all from group '$group' on '$host'" };
@@ -50,9 +50,9 @@ sub fetch {
     push(@{ $spec->{$_}{sudo} ? \@sudo : \@nosudo}, [$_, $spec->{$_}])
         for sort keys %$spec;
     my @futures; 
-    log_debug { sprintf("Fetching results for '%s': sudo:%i nosudo:%i", $host, scalar(@sudo), scalar(@nosudo)) };   
+    log_info { "Probing host '$host' with " . join ", ", map $_->[0], @nosudo, @sudo };   
     if (@nosudo) {
-        log_trace { "Preparing to fetch without sudo: " . join ", ", map $_->[0], @nosudo };
+        log_debug { "Preparing to fetch without sudo: " . join ", ", map $_->[0], @nosudo };
         my $proxy = $self->_create_gatherer(
             host => $host,
             introspectors => [@nosudo],
@@ -60,7 +60,7 @@ sub fetch {
         push @futures, $proxy->start::gather_all;
     }
     if (@sudo) {
-        log_trace { "Preparing to fetch with sudo: ", join ", ", map $_->[0], @nosudo };
+        log_debug { "Preparing to fetch with sudo: ", join ", ", map $_->[0], @nosudo };
         my $proxy = $self->_create_gatherer(
             sudo => 1,
             host => $host,
diff --git a/lib/System/Introspector/Util.pm b/lib/System/Introspector/Util.pm
index a2940c5..8681b28 100644
--- a/lib/System/Introspector/Util.pm
+++ b/lib/System/Introspector/Util.pm
@@ -7,7 +7,6 @@ use IPC::Open2;
 use File::Spec;
 use Scalar::Util qw( blessed );
 use Capture::Tiny qw( capture_stderr );
-use Log::Contextual qw( :log );
 
 our @EXPORT_OK = qw(
     handle_from_command