#!/usr/bin/perl -w
use strict;
use DBI;
use DBD::SQLite;
use Net::Whois::IP qw(whoisip_query);
use Date::Calc qw(Date_to_Time);
use DateTime::HiRes;
use DateTime;
use File::Util;
use Log::Log4perl qw(get_logger);
##initialize Log4perl############################################################
my $log_conf = q(
   log4perl.category = INFO, Logfile, Screen
   log4perl.appender.Logfile = Log::Log4perl::Appender::File
   log4perl.appender.Logfile.filename = auth_examine.log
   log4perl.appender.Logfile.mode = write
	log4perl.appender.Logfile.layout = Log::Log4perl::Layout::PatternLayout
	log4perl.appender.Logfile.layout.ConversionPattern = [%r] %F -%L %m%n
   log4perl.appender.Screen        = Log::Log4perl::Appender::Screen
	log4perl.appender.Screen.layout = Log::Log4perl::Layout::PatternLayout
	log4perl.appender.Screen.layout.ConversionPattern = [%r] %F -%L %m%n
);

Log::Log4perl::init( \$log_conf );
my $logger = Log::Log4perl::get_logger();

################################################################################
#nasty globals
my ($lc, %run_stats, %file_stats, %known_users, %known_port, %known_ip, %known_whois, %unknown_whois, $db_name, $dbh, @in);
################################################################################
my $exec_dir = "/home/wjw/bin";
my $path_to_db = "/home/wjw/bin/auth_log_analysis.sqlite3";
my $auth_log_path = "/var/log/auth.log";
#test
#$exec_dir = "/home/wjw/Devel/wjw-server_utils-work";
#$path_to_db = "/home/wjw/Devel/wjw-server_utils-work/auth_log_analysis.sqlite3";
#$auth_log_path = "/home/wjw/tmp/auth.log";
#end_test
$logger->info("Starting");
chdir $exec_dir;   #for when this is run as root from cron
$file_stats{file_name} = $auth_log_path;
$db_name = $path_to_db;
my $log = File::Util->new();
$dbh = DBI->connect("dbi:SQLite:dbname=$db_name","","") or $logger->logdie("DBI died connecting to $db_name with -> " . DBI::errstr);
@in = $log->load_file($file_stats{file_name}, '--as-lines');

check_log($in[0]); #give the first line of the file to check_log routine
run_log('start');
get_knowns();
process_file();
run_log('end');
run_unknowns();
$dbh->disconnect();
$logger->info("Done! Processed " . $run_stats{lines_examined} . " lines of " . $file_stats{file_name});
exit;
#################################################################
sub process_file {
	no strict "refs";
	my $w = scalar(@in);
	@in = splice(@in, $file_stats{skip_to_line});
	while (my $line = shift(@in)) {
		$run_stats{lines_examined} ++;
		my $response_string;
		my ($ip,$usr,$port,$time_stamp,$skip) = prep_log_entry($line);
		next if $skip == 1;

		#Add into database any users, ports, or ip addresses we have not seen before.
		#Also add to local hash so if we see them again during this run we don't re-add, or do a who_is again
		if(not exists $known_ip{$ip}) {
			my $ct = create_time();
			$dbh->do("insert into ip(IP,create_time) values (\'$ip\',\'$ct\')");
			$known_ip{$ip} = $ip;
			$logger->info("New IP added:" . $ip);
		}
		if(not exists $known_users{$usr}) {
			my $ct = create_time();
			$dbh->do("insert into users(user,create_time) values(\'$usr\',\'$ct\')");
			$known_users{$usr} = $usr;
			$logger->info("New user added: " . $usr);
		}
		if(not exists $known_port{$port}) {
			my $ct = create_time();
			$dbh->do("insert into ports(port,create_time) values(\'$port\',\'$ct\')");
			$known_port{$port} = -1;
			$logger->info("New port added: $port");
		}

		#we always log the attempt to break in!
		my $ip_id = &build_attempt($ip,$usr,$port,$time_stamp);

      #This is where we run the who_is and try to get info about the bastard ...
		if (not exists $known_whois{$ip}) {
			my ($response) = whoisip_query($ip);
			$logger->info("who_is attempted on ip" . $ip);
			if (scalar keys %{$response} > 0) {
   			$known_whois{$ip} = $ip;
   			foreach my $rkey (sort keys (%{$response})) {
   				my $response_line = $response->{$rkey};
   				if (defined $response_string) {
                  $response_string = "$response_string" . "$rkey " . "->" . " $response_line\n";
               } else {
                  $response_string = "$rkey " . "->" . "$response_line\n";
               }
   			}
   			if (defined $response_string) {
   				my $ip_id = $dbh->selectrow_arrayref("select eid from ip where ip = \'$ip\'");
   				my $rs = $dbh->quote($response_string);
   				my $ct = &create_time();
   				my $time_stamp = $ct;
   				my $stmt = qq(insert into who_is(entry,ip_id,timestamp,create_time) values ($rs, \'@$ip_id[0]\', \'$time_stamp\', \'$ct\'));
   				$dbh->do($stmt);
   			}
   		}
		}
	}
}
########################################################################################################
sub build_attempt {
	my ($ip,$usr,$port,$ts) = @_;
	my $ip_id = $dbh->selectrow_arrayref("select eid from ip where ip = \'$ip\'");
	my $usr_id = $dbh->selectrow_arrayref("select eid from users where user = \'$usr\'");
	my $port_id = $dbh->selectrow_arrayref("select eid from ports where port = \'$port\'");
	my $ct = create_time();
	$dbh->do("insert into attempts(ip_id,user_id,port_id,timestamp,create_time) values (\'@$ip_id[0]\',\'@$usr_id[0]\',\'@$port_id[0]\',\'$ts\',\'$ct\')");
	return @$ip_id[0];
}
########################################################################################################
#get the info we want from the auth.log entry and prep that info from a formatting perspective
sub prep_log_entry() {
	my $line = shift(@_);
	my ($ip,$usr,$port,$time_stamp,$skip);
	chomp($line);
	if ($line =~ /Failed password for invalid user |Failed password for /) {
		my @rem = split(/\s/,$');
		my $rem = $';
		my @pre = split(/\s+/,$`);
		my $year = Date::Calc::This_Year(1);
		my $day = $pre[1];
		my $month = Date::Calc::Decode_Month($pre[0],1);
		if (length($month) < 2) {
			$month = "0" . $month;
		}
		if (length($day) < 2) {
			$day = "0" . $day;
		}
		my $time = $pre[2];
		$time_stamp = $year . "-" . $month . "-" . $day . "T" . $time;
		$usr = $rem[0];
		$ip = $rem[2];
		$port = $rem[4];
		$skip = 0;
	} else {
		$skip = 1;
	}
	return ($ip,$usr,$port,$time_stamp,$skip);
}
########################################################################################################
#sub to populate the un/known* hashes
sub get_knowns() {
	#get the list of IP known addresses
	my $all = $dbh->selectall_arrayref("select eid, IP from ip");
	foreach my $row (@$all) {
		my ($id,$ip) = @$row;
		$known_ip{$ip} = $id;
	}
	my $num = scalar(keys %known_ip);
	$logger->info($num . " known IP's loaded");

	#get the list of known ports
	$all = $dbh->selectall_arrayref("select eid, port from ports");
	foreach my $row (@$all) {
		my ($id,$port) = @$row;
 		$known_port{$port} = $id;
	}
	$num = scalar(keys %known_port);
	$logger->info($num . " known ports loaded");

	#get the list of known users
	$all = $dbh->selectall_arrayref("select eid, user from users");
	foreach my $row (@$all) {
		my ($id,$user) = @$row;
		$known_users{$user} = $id;
	}
	$num = scalar(keys %known_users);
	 $logger->info($num . " known users loaded");

	#who_is addresses we have already found, don't search these again
	$all = $dbh->selectall_arrayref("select ip from ip where eid in (select ip_id from who_is)");
	foreach my $row (@$all) {
		$known_whois{@$row[0]} = @$row[0];
	}
	$num  = scalar(keys %known_whois);
	$logger->info($num . " known whois results loaded");

	#ip addresses we have but do not have who_is results for
	$all = $dbh->selectall_arrayref("select ip from ip where eid not in (select ip_id from who_is)");
	foreach my $row (@$all) {
		$unknown_whois{@$row[0]} = @$row[0];
	}
	$num = scalar(keys %unknown_whois);
	$logger->info($num . " ip(s) without who_is results loaded");
}
########################################################################################################
#function to get a record create time.  This is by no means perfect, but it should help identify
#issues in the database
sub create_time {
	my $ct = DateTime::HiRes->now();
	$ct->set_time_zone("America/Chicago");
	my $w = $ct->datetime() . "." . $ct->nanosecond();
	return $w;
}
#########################################################################################################
sub run_log {
	my $arg = shift(@_);
	if ($arg eq 'start') {
		my $fn = shift(@_);
		$run_stats{start_time} = create_time();
		if ($file_stats{first_run} == 1 || $file_stats{new_file} == 1) {
			$logger->info("This is a new auth.log file\n");
			return;
		}
		my $qs = qq(select last_line_read from run_log where eid = (select max(eid) from run_log));
		my $sth = $dbh->prepare($qs);
		my $rv = $sth->execute() or die $DBI::errstr;
		while (my @row = $sth->fetchrow_array()) {
			$file_stats{skip_to_line} = $row[0];
			$logger->info("Will be skipping to line " . $file_stats{skip_to_line});
		}
	}
	if ($arg eq 'end') {
		$run_stats{end_time} = create_time();
		my $qs = qq(insert into run_log (run_time_start, run_time_end, input_file, last_line_read, last_log_first_line) values (\'$run_stats{start_time}\', \'$run_stats{end_time}\', \'$file_stats{file_name}\', \'$run_stats{last_line_processed}\', \'$in[0]\'));
		$dbh->do($qs);
	}
}
##########################################################
#better run logging.... need to capture where we were in log file so as not to re-process records.
#base on line count as well as time stamp of last record processed.
sub check_log {
	my ($prev_create_time,$record_count,$first_line_txt);
	$first_line_txt = shift(@_);
	#compare last line read in log with current log length, if smaller it is the same file probably
	$file_stats{line_count} = $log->line_count($file_stats{file_name});
	my $qs = qq(select last_line_read from run_log where eid = (select max(eid) from run_log));
	my $sth = $dbh->prepare($qs);
	my $rv = $sth->execute() or die $DBI::errstr;
	while (my @row = $sth->fetchrow_array()) {
		$file_stats{skip_to_line} = $row[0];
		$logger->info( "Will be skipping to line " . $file_stats{skip_to_line});
	}
	if ($file_stats{line_count} < $file_stats{skip_to_line}) {
		$file_stats{first_run} = 1;
		$file_stats{skip_to_line} = 0;
	} else {
		$file_stats{first_run} = 0;
	}
	$qs = qq(select last_log_first_line from run_log where eid = (select max(eid) from run_log));
	$sth = $dbh->prepare($qs);
	$rv = $sth->execute() or die $DBI::errstr;
	while (my @row = $sth->fetchrow_array()) {
		$file_stats{last_log_first_line} = $row[0];
	}
	if ($file_stats{last_log_first_line} eq $first_line_txt) {
		$file_stats{first_run} = 0;
	} else {
		$file_stats{first_run} = 1;
		$file_stats{skip_to_line} = 0;
	}
	if (($file_stats{first_run} == 0) && ($file_stats{skip_to_line} == $file_stats{line_count})) {
		$logger->info("No new records in file.  Exiting\n");
		exit;
	}
	return;
}
##############################################################################
sub run_unknowns {
	#here were do a who_is on ip that don't yet have one for whatever reason
	no strict "refs";
	my $response_string;
	foreach my $ip (keys %unknown_whois) {
		my ($response) = whoisip_query($ip);
		$logger->info("who_is attempted on unknown ip " . $ip);
		if (scalar keys %{$response} > 0) {
			$known_whois{$ip} = $ip;
			foreach my $rkey (sort keys (%{$response})) {
				my $response_line = $response->{$rkey};
				if (defined $response_string) {
               $response_string = "$response_string" . "$rkey " . "->" . " $response_line\n";
            } else {
               $response_string = "$rkey " . "->" . "$response_line\n";
            }
			}
			if (defined $response_string) {
				my $ip_id = $dbh->selectrow_arrayref("select eid from ip where ip = \'$ip\'");
				my $rs = $dbh->quote($response_string);
				my $ct = &create_time();
				my $time_stamp = $ct;
				my $stmt = qq(insert into who_is(entry,ip_id,timestamp,create_time) values ($rs, \'@$ip_id[0]\', \'$time_stamp\', \'$ct\'));
				$dbh->do($stmt);
			}
		}
	}
}