#! /usr/bin/perl -w

# Ce script réécrit le log mysql en temps réel (simplification, utilisation de cronolog).
# Le log généré sera utilisé pour générer des statistiques (nombre de connexions
# par utilisateur, nombre de requêtes par utilisateur etc).
# Avantages :
# - le log de mysql est verbeux, on le réécrit en supprimant ce qui n'est pas utile.
#   Le script qui s'occupe des stats sera donc plus simple et plus efficient.
# - on utilise cronolog, donc le log est clairement délimité dans le temps.
# - si le format de log change, les scripts qui génèrent les stats ne devront pas changer.
#   Seul ce script devra être modifié.


# Le log mysqlconsiste en un identifiant de connexion, un mot clé (Query, Connect etc), parfois
# un timestamp et des infos spécifiques au mot clé.
# Pour une requête, le texte de la requête peut prendre plusieurs lignes.
# Pour les autres records, une seule ligne est utilisée.
# Pour chaque nouvelle seconde qui commence, l'heure est donnée avant le log.
# Pour le nouveau log, on écrit le mot clé, un timestampstamp et les informations 
# qui nous intéressent.

# Format d'origine :
# 88340390 Query       SELECT ref_data_id,c_232 from comptes_datas_3 where data_id=50
# 88340392 Connect     topgratuit@bizmachine3.co.fr.clara.net on
# 88340392 Init DB     topgratuit
# 88340392 Query       SELECT * FROM phpads_cache WHERE cacheid='what=zone:2'
# 88343914 Quit
# 88440736 Query       SELECT code_famille,libelle_famille FROM codesfamilles WHERE code_famille LIKE 'BI' ORDER BY code_famille LIMIT 100
# 88442371 Query       SELECT *
#                          FROM phpbb_users
#                          WHERE user_id = 1498 AND user_id <> -1
# 88442371 Query       SELECT *
# 050830 15:06:51 1057238 Query       SELECT * FROM user WHERE username='shaka'

# Format généré :
# Connect 18:20:50 1115803 motormchat bizmachine8.co.fr.clara.net
# Query 18:20:50 1115803
# Quit 17:27:29 1099476

use strict;
use File::Tail;
use Proc::Daemon;

Proc::Daemon::Init;

my $debug = 0;

my $logfile = "/var/log/mysql/mysql.log";
my $cronolog_logfile = "/var/log/mysql/cronolog/\%Y/\%m/\%d/mysql.log";
my $error_logfile = "/var/log/mysql/mysql-logger.log";
my $cronolog = "/usr/bin/cronolog";

open(ERROR_LOG, ">> $error_logfile") || die "Impossible d'ouvrir $error_logfile";
ERROR_LOG->autoflush(1);

if (!open(CRONOLOG, "| $cronolog $cronolog_logfile")) {
	log_error("Impossible d'exécuter cronolog");
	exit(1);
}

my $ref = tie *LOG, "File::Tail", (name => $logfile);

if (!$ref) {
	log_error("Impossible d'ouvrir $logfile");
	exit(1);
}

log_error(sprintf("Début %s", scalar localtime));

# Les enregistrements commencent toujours par ça, sauf
# quand mysql écrit l'heure courante dans le log
my $record_start_re = qr/^\t\t/;

# Le timestampstamp mysql au format hh:mm:ss
my $timestamp;

# Au début, on peut tomber sur la fin du log d'une requête, avec un
# format inattendu. Dans ce cas on ne fait pas attention, on passe
# à la ligne suivante. Sinon on loggue une erreur.
# Dès qu'on est synchronisé sur le début d'un enregistrement, le seul
# cas où on tombera sur un format inattendu sera dans le cas du log
# d'une requête qui prend plusieurs lignes.
my $starting = 1;

# Dans le cas de l'enregistrement d'un requête, la requête peut prendre plusieurs lignes,
# qu'on peut ignorer si on ne reconaît pas le format d'un enregistrement. Dans
# un autre cas, on ne peut ignorer sans logguer une erreur.
my $query_accumulating = 0;

while (<LOG>) {
    chomp;
    next if $_ eq ""; # On trouve des lignes vides parfois

    log_debug("");
    log_debug("Ligne examinée : \"$_\"") if $debug;

    if ($starting) {
        # Si début d'un nouvel enregistrement
        if (/\t\t/ or /^\d+\s+(\d+:\d+:\d+)\s+/) {
            $starting = 0;
            log_debug("starting => 0") if $debug;
        }
        else {
            log_debug("Format inattendu OK (starting)") if $debug;
        }
    }

    # Enregistrement avec l'heure.
    # 050830 15:06:51 1057238 Query       SELECT * FROM user WHERE username='shaka'
    if (/^\d+\s+(\d+:\d+:\d+)\s+/) {
        $timestamp = $1;
        log_debug("timestamp => $timestamp") if $debug;
        # On se ramène au cas où il n'y a pas de timestampstamp, après avoir récupéré
        # le timestamp
        $_ =~ s/^\d+\s+\d+:\d+:\d+\s+/\t\t/;
        log_debug("Ligne modifiée, maintenant : \"$_\"") if $debug;
    }

    # Si on n'a pas encore récupéré l'heure, on attend (une seconde maximum) de la récupérer.
    if (! $timestamp) {
        log_debug("Ligne suivante, pas encore de timestampstamp") if $debug;
        next;
    }

    if (/\t\t\d+\s+/) {
        $query_accumulating = 0;
        log_debug("Nouvel enregistrement, query_accumulating => 0") if $debug;
    }
        
	if (/\t\t(\d+)\s+Connect\s+([^@]+)@(\S+)/) {
		
		my $connect_id = $1;
		my $user = $2;
		my $host = $3;
		log_print("Connect $timestamp $connect_id $user $host\n");
		log_debug("Connect $timestamp $connect_id $user $host") if $debug;

	}

	elsif (/\t\t(\d+)\s+Query/) {

		my $connect_id = $1 || log_error("Pas de connect_id, line = $_");
		log_print("Query $timestamp $connect_id\n");
		log_debug("Query $timestamp $connect_id") if $debug;
        $query_accumulating = 1;
        log_debug("query_accumulating => 1") if $debug;
	}

	elsif (/\t\t(\d+)\s+Quit/) {
		my $connect_id = $1 || log_error("Pas de connect_id, line = $_");
		log_print("Quit $timestamp $connect_id\n");
		log_debug("Quit $timestamp $connect_id") if $debug;

	}

	elsif (/\t\t(\d+)\s+(\S+)/) {
        # Pas intéressé, merci 
        next;
	}

    elsif ($query_accumulating) {
		log_debug("Format inattendu OK (query_accumulating)") if $debug;
        next;
    }

    else {
        log_error("Format inattendu: \"$_\"");
		log_debug("ERREUR : format inattendu \"$_\"") if $debug;
        next;
    }
}

sub log_error {
	my $message = shift;
	print ERROR_LOG "$message\n";
}

sub log_debug {
	my $message = shift;
	print "$message\n";
}

sub log_print {
	my $message = shift;
	print CRONOLOG $message;
}
