#!/usr/bin/perl
use warnings;
use strict;
use autodie;
use HTTP::Date;
use POSIX qw(strftime);
use Data::Dump qw(dump);

$|=1;
my $debug = $ENV{DEBUG} || 0;

my $t;

sub t_iso {
	return strftime("%Y-%m-%d %H:%M:%S", localtime($_[0]));
}


open(my $log_fh, '<', "/var/log/apache2/other_vhosts_access.log");
sub log_time {
	my ( $t, $duration ) = @_;
	my $tell = tell($log_fh);
	print "XXX log_time $t ", t_iso($t) , " $tell\n" if $debug;
	my $found = 0;
	while(<$log_fh>) {
		#warn "# $. $_";
		if ( m/ \[(\d+[^\]]+)\] \S+ (\S+)/ ) {
			my $t_l = str2time($1);
			my $url = $2;
			my $dt = $t_l - $t;
			print "XXX log line ",t_iso($t_l)," $dt tell ",tell($log_fh),$/ if abs($dt) < 5 && $debug;
			if ( abs( $dt ) <=  $duration && $url =~ m/cgi/ ) {
				$found++;
				$tell = tell($log_fh) if $found == 1;
				if ( $debug ) {
					print "\nFOUND $tell $dt ",t_iso( $t_l ), " ", t_iso($t), " ", $_;
				} else {
					printf "FOUND %4.1f %s", $dt, $_;
				}
			}
			if ( 
				(   $found && $t_l - $t > $duration * 3 ) ||
				( ! $found && $t_l - $t > 90 ) # apache log entries come after more than 60s sometime
			) {	# overshoot time since logs are not always in order
				print "STOP ", t_iso($t_l), " tell $tell\n" if $debug;
				seek($log_fh, $tell, 0);
				last;
			}
		}
	}
	if ( ! $found ) {
		print "SEEK $tell\n" if $debug;
		seek($log_fh, $tell, 0);
	}
}


my $sql;
my $sql_count = 0;
my $in_sql = 0;

open(my $slow_fh, '<', '/var/log/mysql/mysql-slow.log');
while(<$slow_fh>) {
	print $_;
	if ( m/Time:\s+(\S+)\s+(\S+)/ ) {
		$t = str2time("20$1 $2");
	} elsif ( m/Query_time: (\S+)/ ) {
		my $d = $1;
		my $t_start = $t - $d;
		print "XXX ",t_iso($t), " -> ", t_iso($t_start), $/ if $debug;

		log_time $t_start, $d;
	} elsif ( m/SET timestamp=(\d+);/ ) {
		$in_sql = $1;
	} elsif ( $in_sql ) {
		$sql .= $_;
		if ( m/;/ ) {
			$in_sql = 0;
			open(my $sql_fh, '>', t_iso($t) . "-$in_sql-$sql_count.sql");
			print $sql_fh $sql;
			close $sql_fh;
			$sql_count++;
			$sql = '';
		}
	}
}

