* Updated Log->entry to use the new Log::Journald method, which improved writing to log speed at high log levels dramatically (ie: 33 seconds -> 1 seconds).

* Started using Time::HiRes and recording the run time of programs using AN::Tools at log level 2.
* Added a check in tools/an-prep-database to write journald.conf.d/an.conf to disable rate limiting to allow high log levels without losing messages.

Signed-off-by: Digimer <digimer@alteeve.ca>

AN/Tools.pm

@@ -14,6 +14,7 @@ BEGIN
 use strict;
 use warnings;
 use Scalar::Util qw(weaken isweak);
+use Time::HiRes;
 use Data::Dumper;
 my $THIS_FILE = "Tools.pm";
 
@@ -137,6 +138,9 @@ sub new
 	my $an = $self; 
 	weaken($an);	# Helps avoid memory leaks. See Scalar::Utils
 	
+	# Record the start time.
+	$an->data->{ENV_VALUES}{START_TIME} = Time::HiRes::time;
+	
 	# Get a handle on the various submodules
 	$an->Alert->parent($an);
 	$an->Database->parent($an);
@@ -319,6 +323,16 @@ sub nice_exit
 	# Close database connections (if any).
 	$an->Database->disconnect();
 	
+	# Report the runtime.
+	my $end_time = Time::HiRes::time;
+	my $run_time = $end_time - $an->data->{ENV_VALUES}{START_TIME};
+	$an->Log->variables({source => $THIS_FILE, line => __LINE__, level => 2, list => { 
+		's1:ENV_VALUES::START_TIME' => $an->data->{ENV_VALUES}{START_TIME}, 
+		's2:end_time'               => $end_time, 
+		's3:run_time'               => $run_time, 
+	}});
+	$an->Log->entry({source => $THIS_FILE, line => __LINE__, level => 1, key => "log_0135", variables => { runtime => $run_time }});
+	
 	exit($exit_code);
 }
 
@@ -679,6 +693,7 @@ sub _set_paths
 	$an->data->{path} = {
 			configs			=>	{
 				'firewalld.conf'	=>	"/etc/firewalld/firewalld.conf",
+				'journald_an'		=>	"/etc/systemd/journald.conf.d/an.conf",
 				'pg_hba.conf'		=>	"/var/lib/pgsql/data/pg_hba.conf",
 				'postgresql.conf'	=>	"/var/lib/pgsql/data/postgresql.conf",
 				ssh_config		=>	"/etc/ssh/ssh_config",

AN/Tools/Log.pm

@@ -7,6 +7,9 @@ use strict;
 use warnings;
 use Data::Dumper;
 use Scalar::Util qw(weaken isweak);
+use Log::Journald;
+use Sys::Syslog qw/:macros/;
+
 
 our $VERSION  = "3.0.0";
 my $THIS_FILE = "Log.pm";
@@ -297,34 +300,15 @@ sub entry
 		$string .= $message;
 	}
 	
-	# Clean up the string for bash
+	# Log with Log::Journald
-	$string =~ s/"/\\\"/gs;		# Single-escape "   -> \\"
+	Log::Journald::send(
-	$string =~ s/\\\\"/\\\\\\"/gs;	# triple-escape \\" -> \\\"
+		PRIORITY          => $priority, 
-	#$string =~ s/\(/\\\(/gs;
+		MESSAGE           => $string, 
-	
+		CODE_FILE         => $source, 
-	# NOTE: This might become too expensive, in which case we may need to create a connection to journald
+		CODE_LINE         => $line, 
-	#       that we can leave open during a run.
+		SYSLOG_FACILITY   => $secure ? "authpriv" : $facility,
-	if ((not defined $tag) or (not defined $priority_string) or (not defined $an->data->{path}{exe}{logger}))
+		SYSLOG_IDENTIFIER => $tag,
-	{
+	);
-		die $THIS_FILE." ".__LINE__."; Something not defined in Log->entry; path::exe::logger: [".$an->data->{path}{exe}{logger}."], tag: [".$tag."], 'defaults::log::tag': [".$an->data->{defaults}{'log'}{tag}."], priority_string: [".$priority_string."]\n";
-	}
-	my $shell_call = $an->data->{path}{exe}{logger}." --id --tag ".$tag." --priority ".$priority_string;
-	if ($server)
-	{
-		$shell_call .= " --server ".$server;
-	}
-	$shell_call .= " -- \"".$string."\"";
-	
-	# Record it!
-	#print $THIS_FILE." ".__LINE__."; [ Debug ] - shell_call: [$shell_call]\n";
-	open(my $file_handle, $shell_call." 2>&1 |") or warn $THIS_FILE." ".__LINE__."; [ Warning ] - Failed to call: [".$shell_call."], the error was: $!\n";
-	while(<$file_handle>)
-	{
-		# This should never be hit...
-		chomp;
-		warn $THIS_FILE." ".__LINE__."; [ Warning ] - Unexpected output from: [".$shell_call."] -> [".$_."]\n";
-	}
-	close $file_handle;
 	
 	return(0);
 }

AN/an-tools.xml

@@ -34,6 +34,8 @@ This is the AN::Tools master 'words' file.
 		<key name="message_0008">There was a problem establishing an SSH channel to the target: [#!variable!target!#] for shell call: [#!variable!shell_call!#]</key>
 		<key name="message_0009">The SSH session to: [#!variable!target!#] was successfully closed.</key>
 		<key name="message_0010">The SSH session to: [#!variable!target!#] was closed because 'no_cache' was set and there was an open SSH connection.</key>
+		<key name="message_0011">Wrote the system UUID to the file: [#!variable!file!#] to enable the web based tools to read this system's UUID.</key>
+		<key name="message_0012">Wrote the journald config file: [#!variable!file!#] to disable rate limiting to ensure high log levels are not lost.</key>
 		
 		<!-- Log entries -->
 		<key name="log_0001">Starting: [#!variable!program!#].</key>
@@ -203,6 +205,7 @@ The database connection error was:
 		<key name="log_0132">Connected to: [#!variable!connections!#] database(s).</key>
 		<key name="log_0133">Failed to read the system UUID. Received a non-UUID string: [#!variable!uuid!#]. Is the user: [#!variable!user!#] in the 'kmem' group?</key>
 		<key name="log_0134">The read host UUID: [#!variable!uuid!#] does not appear to be a valid UUID.</key>
+		<key name="log_0135">Runtime was approximately: [#!variable!runtime!#].</key>
 		
 		<!-- Test words. Do NOT change unless you update 't/Words.t' or tests will needlessly fail. -->
 		<key name="t_0000">Test</key>

cgi-bin/home

@@ -23,7 +23,7 @@ my $an = AN::Tools->new();
 print $an->Template->get({file => "shared.html", name => "http_headers"})."\n";
 
 # Set the log level to 2. Setting 3 slows he program down a LOT.
-$an->Log->level({set => 2});
+$an->Log->level({set => 3});
 
 # Read in our words file.
 $an->Words->read({file => $an->data->{path}{directories}{'cgi-bin'}."/words.xml"});
@@ -36,7 +36,7 @@ if (not $an->Get->host_uuid)
 {
 	# Too early, exit.
 	print $an->Words->string({key => "striker_error_0002"});
-	exit(1);
+	$an->nice_exit({exit_code => 1});
 }
 
 my $connections = $an->Database->connect({
@@ -44,6 +44,12 @@ my $connections = $an->Database->connect({
 	test_table => "network_interfaces", 
 });
 $an->Log->entry({source => $THIS_FILE, line => __LINE__, level => 2, key => "log_0132", variables => { connections => $connections }});
+if (not $connections)
+{
+	# No databases, exit.
+	print $an->Words->string({key => "striker_error_0003"});
+	$an->nice_exit({exit_code => 2});
+}
 
 # Turn off buffering so that the pinwheel will display while waiting for the SSH call(s) to complete.
 $| = 1;
@@ -116,7 +122,8 @@ my $template = $an->Template->get({file => "main.html", name => "master", variab
 
 print $template;
 
-exit(0);
+$an->nice_exit({exit_code => 0});
+
 
 #############################################################################################################
 # Functions                                                                                                 #

cgi-bin/words.xml

@@ -71,6 +71,7 @@ This is the AN::Tools master 'words' file.
 		<!-- Errors -->
 		<key name="striker_error_0001">There are not enough network interfaces on this machine. You have: [#!variable!interface_count!#] interface(s), and you need at least: [#!variable!required_interfaces_for_single!#] interfaces to connect to the requested networks (one for Back-Channel and one for each Internet-Facing network).</key>
 		<key name="striker_error_0002">The local system UUID can't be read yet. This might be because the system is brand new and/or ScanCore hasn't run yet. Please try again in a minute.</key>
+		<key name="striker_error_0003">None of the databases are accessible, unable to proceed.</key>
 		
 		<!-- These are works and strings used by javascript/jqery -->
 		<key name="js_0001">Up</key>

tools/an-prep-database

@@ -310,6 +310,10 @@ if ($local_id)
 		}
 	}
 	
+	#####################################################################################################
+	# NOTE: Below here is stuff that is for general setup. If it grows, we'll have to rename this tool. #
+	#####################################################################################################
+	
 	### TODO: This will need to set the proper SELinux context.
 	# Apache run scripts can't call the system UUID, so we'll write it to a text file.
 	if (not -e $an->data->{path}{data}{host_uuid})
@@ -322,9 +326,38 @@ if ($local_id)
 			mode      => "0666",
 			overwrite => 0,
 		});
-		$an->Log->entry({source => $THIS_FILE, line => __LINE__, level => 1, key => "message_0002", variables => { file => $an->data->{path}{configs}{'postgresql.conf'} }});
+		$an->Log->entry({source => $THIS_FILE, line => __LINE__, level => 1, key => "message_0011", variables => { file => $an->data->{path}{configs}{'postgresql.conf'} }});
 	}
 	
+	# Log level 3 creates so much logging that it hits journald's rate limiting (1000 logs per 30 
+	# seconds). So we need to disable it.
+	if (not -e $an->data->{path}{configs}{'journald_an'})
+	{
+		# Write the file to disable journald rate limiting.
+		my $body = "# This disables the rate limiting so that when log level is set to 3, log 
+# entries aren't lost. If you want to override this, don't delete the file, 
+# just comment out the lines below.
+
+[Journal]
+RateLimitInterval=0
+RateLimitBurst=0
+";
+		$an->Storage->write_file({
+			file      => $an->data->{path}{configs}{'journald_an'}, 
+			body      => $body,
+			user      => "root", 
+			group     => "root",
+			mode      => "0644",
+			overwrite => 0,
+		});
+		$an->Log->entry({source => $THIS_FILE, line => __LINE__, level => 1, key => "message_0012", variables => { file => $an->data->{path}{configs}{'journald_an'} }});
+		
+		my $shell_call = $an->data->{path}{exe}{systemctl}." restart systemd-journald.service";
+		$an->Log->variables({source => $THIS_FILE, line => __LINE__, level => 2, list => { shell_call => $shell_call }});
+		
+		my $output = $an->System->call({shell_call => $shell_call, source => $THIS_FILE, line => __LINE__});
+		$an->Log->variables({source => $THIS_FILE, line => __LINE__, level => 2, list => { output => $output }});
+	}
 }
 else
 {