====== Archiver les logs de squid dans une base MySQL ======
Par défaut, squid envoi tous ses journaux dans des fichiers. Si c'est pratique pour suivre en temps réel qui accède à quoi, c'est déjà beaucoup plus dur de faire des analyse plus fines, par exemple:
* Retrouver tous les sites web visité par un utilisateur (ou adresse IP)
* Retrouver quels utilisateurs ont visité une liste précise de sites
* etc...
Il existe beaucoup d'outils d'analyse des journaux de squid (le plus connu est probablement sarg), mais s'ils permettent d'avoir des statistiques intéressantes, ils n'aident pas vraiment pour les exemples ci-dessus. Pour ça, le mieux est de loguer toutes les requêtes qui passent par squid dans une base de données. Certaines versions de squid ont une directive nommée logfile_daemon, qui permet d'envoyer les journaux à un démon, qui pourra lui même enregistrer tout ça dans une base (voir par exemple http://sourceforge.net/projects/logmysqldaemon/). Mais (il y a toujours un mais), il y a deux problèmes majeurs avec cette solution:
* La directive logfile_daemon n'est supportée que par squid 2.7 ou 3.2 et supérieur
* Avec ce mode de fonctionnement, si un problème survient dans le démon qui gère les journaux, alors squid plante tout simplement
Voilà donc la solution que nous avons mis au point: squid inscrit ses journaux dans des fichiers texte classiques, et un démon indépendant les surveille en temps réel, et inscrit tout ça dans une base de donnée (pour nous, c'est du MySQL, mais n'importe quelle base compatible avec le module perl DBI devrait fonctionner). En plus des journaux squid, cette solution est capable d'archiver les journaux de squidGuard.
===== Schéma MySQL =====
Il faut tout d'abord créer une base de donnée et lui injecter ce schéma:
-- Table to store squid access logs
CREATE TABLE access_log (
id INTEGER NOT NULL AUTO_INCREMENT PRIMARY KEY,
proxy_host VARCHAR(30),
timestamp DECIMAL(15,3),
date_day DATE, -- set by trigger
date_time TIME, -- set by trigger
response_time INTEGER,
client_ip CHAR(15),
squid_status VARCHAR(30),
http_status VARCHAR(10),
reply_size INTEGER,
request_method VARCHAR(15),
url VARCHAR(200),
domain VARCHAR(50),
username VARCHAR(30),
squid_connect VARCHAR(20),
server_ip CHAR(15),
mime_type VARCHAR(50)
) ENGINE=MYISAM;
-- trigger that extracts the date value from the timestamp column
-- and stores it in the date_day and date_time columns
-- this allows fast calculation of per-day aggregate values
DELIMITER //
CREATE TRIGGER extract_date_bi BEFORE INSERT ON access_log FOR EACH ROW
BEGIN
SET NEW.date_day = DATE(FROM_UNIXTIME(NEW.timestamp));
SET NEW.date_time = TIME(FROM_UNIXTIME(NEW.timestamp));
END; //
CREATE TABLE deny_log (
id INTEGER NOT NULL AUTO_INCREMENT PRIMARY KEY,
proxy_host VARCHAR(30),
date_day DATE,
date_time TIME,
category VARCHAR(40),
client_ip CHAR(15),
url VARCHAR(200),
domain VARCHAR(50),
username VARCHAR(30)
) ENGINE=MYISAM;
===== Script de journalisation =====
Il suffit ensuite de lancer ce script:
#!/usr/bin/perl -w
use File::Tail;
use DBI;
use URI;
use Getopt::Long;
use threads;
use threads::shared;
use strict;
our %opts = ();
# Set default options
$opts{squidlog} = '/var/log/squid/access.log';
$opts{squidguardlog} = '/var/log/squidGuard/deny.log';
$opts{squid} = 1;
$opts{squidguard} = 0;
$opts{debug} = 0;
$opts{dbhost} = 'localhost';
$opts{dbname} = 'squid_log';
$opts{dbuser} = 'squid';
$opts{dbpass} = 'squid';
# get command line arguments
GetOptions(
"debug=i" => \$opts{debug},
"squidlog=s" => \$opts{squidlog},
"squidguardlog=s" => \$opts{squidguardlog},
"squid!" => \$opts{squid},
"squidguard!" => \$opts{squidguard},
"dbhost=s" => \$opts{dbhost},
"dbname=s" => \$opts{dbname},
"dbpass=s" => \$opts{dbpass}
);
# Disable output buffering
select(STDOUT);
$| = 1;
select(STDERR);
$| = 1;
open STDERR, '>&STDOUT';
# Set process name
$0 = 'squid-db-logd';
# Get hostname
our $host = `hostname`;
chomp($host);
### Subroutines
# Print messages on stderr
# for debuging purpose
sub printlog {
my $msg = shift;
print "$msg\n";
return;
}
# Connect to the database
sub db_connect {
my $dbh = DBI->connect("DBI:mysql:database=$opts{dbname};host=$opts{dbhost}",
$opts{dbuser}, $opts{dbpass}, {RaiseError => 1});
die "Couldn't connect to database\n" unless ($dbh);
return $dbh;
}
# escape chars for MySQL queries
sub mysql_escape {
my $string = shift;
$string =~ s|'|\\'|g;
return $string;
}
# log squid access
sub squid_log {
my $logfile = shift;
printlog("squid_log thread connecting to database") if ($opts{debug} ge 1);
my $dbh = db_connect;
# Open log file
printlog("opening squid log file") if ($opts{debug} ge 1);
my $tail = File::Tail->new(name=>$logfile, maxinterval=>15);
while (defined(my $line=$tail->read)){
my ($timestamp, $response_time, $client_ip, $status, $reply_size,
$request_method, $url, $username, $server, $mime_type) = split /\s+/, $line;
my ($squid_status, $http_status) = split /\//, $status;
my ($squid_connect, $server_ip) = split /\//, $server;
# Skip stats requested by squidclient
next if ($url =~ m/^cache_object:/);
my $domain;
if ($request_method eq 'CONNECT'){
($domain,undef) = split /:/, $url;
}
else{
my $uri = URI->new($url);
$domain = mysql_escape($uri->host);
}
# MySQL escape
# Shouldn't be needed, but just in case logs contains junk
$timestamp = mysql_escape($timestamp);
$response_time = mysql_escape($response_time);
$client_ip = mysql_escape($client_ip);
$squid_status = mysql_escape($squid_status);
$http_status = mysql_escape($http_status);
$reply_size = mysql_escape($reply_size);
$request_method = mysql_escape($request_method);
$url = mysql_escape($url);
$username = mysql_escape($username);
$squid_connect = mysql_escape($squid_connect);
$server_ip = mysql_escape($server_ip);
$mime_type = mysql_escape($mime_type);
printlog("New access_log entry:\ntimestamp: $timestamp\nresponse_time: $response_time\n".
"client_ip: $client_ip\nsquid_status: $squid_status\nhttp_status: $http_status\n".
"reply_size: $reply_size\nrequest_method: $request_method\nurl: $url\n".
"username: $username\nsquid_connect: $squid_connect\n".
"server_ip: $server_ip\nmime_type: $mime_type\n\n") if ($opts{debug} ge 2);
my $q = "INSERT INTO access_log ".
"(proxy_host, timestamp, response_time, client_ip, squid_status, http_status, ".
"reply_size, request_method, url, domain, username, squid_connect, server_ip, mime_type)".
" VALUES('$host', '$timestamp','$response_time','$client_ip','$squid_status','$http_status',".
"'$reply_size','$request_method','$url','$domain','$username','$squid_connect','$server_ip','$mime_type')";
my $qh = $dbh->prepare($q);
$qh->execute or exit(1);
}
}
# log squid access
sub squidguard_log {
my $logfile = shift;
printlog("squidguard_log thread connecting to database") if ($opts{debug} ge 1);
my $dbh = db_connect;
# Open log file
printlog("opening squidGuard log file") if ($opts{debug} ge 1);
my $tail = File::Tail->new(name=>$logfile, maxinterval=>15);
while (defined(my $line=$tail->read)){
my ($date_day, $date_time, undef, $category, $url, $client_ip, $username) = split /\s+/, $line;
# Clean some values
$category =~ m/default\/(\w+)/;
$category = $1;
$client_ip =~ s/\/\-$//;
my $uri = URI->new($url);
my $domain = mysql_escape($uri->host);
# MySQL escape
$date_day = mysql_escape($date_day);
$date_time = mysql_escape($date_time);
$category = mysql_escape($category);
$url = mysql_escape($url);
$client_ip = mysql_escape($client_ip);
$username = mysql_escape($username);
printlog("New deny_log entry:\ndate: $date_day\ntime: $date_time\ncategory: $category\n".
"client_ip: $client_ip\nurl: $url\nusername: $username\n\n") if ($opts{debug} ge 2);
my $q = "INSERT INTO deny_log ".
"(proxy_host, date_day, date_time, category, client_ip, url, domain, username)".
" VALUES('$host', '$date_day','$date_time','$category','$client_ip','$url','$domain','$username')";
my $qh = $dbh->prepare($q);
$qh->execute;
}
}
printlog("Starting log monitoring threads") if ($opts{debug} ge 1);
my $thr1 = threads->create('squid_log', $opts{squidlog}) if ($opts{squid});
my $thr = 1;
if ($opts{squidguard}){
my $thr2 = threads->create('squidguard_log', $opts{squidguardlog}) if ($opts{squidguard});
$thr++;
}
while (scalar(threads->list(threads::running)) ge $thr){
sleep(5);
}
die "At least one thread died\n";
Ce script peut être lancé en tant que squid (il a simplement besoin d'avoir accès en lecture aux journaux de squid). Ce script ne se détache pas de la console (je le fais tourner avec runit). On peut le lancer comme ça:
./squid-db-logd.pl --dbhost=127.0.0.1 --dbname=squid_log --dbuser=squid --dbpass=secret \
--squidguard --squidlogfile=/var/log/squid/access.log --squidguardlogfile=/var/log/squidGuard/deny.log
===== Rotation et compression des tables =====
La journalisation dans une base de donnée peut consommer **beaucoup** d'espace disque (en fonction du nombre d'utilisateur derrière ce proxy). L'idée est donc de faire une rotation des tables access_log et deny_log une fois par mois. Les anciennes tables sont compressées (toujours consultables directement par MySQL, mais en lecture seule) et de supprimer les vieilles tables (par exemple, on conserve 1 an de journaux). Voilà un petit script cron à mettre en place:
#!/bin/bash
DB_HOST=localhost
# COnservation des journaux en nombre de jours
RETENTION=365
SQL_DB=squid_log
TABNAME="access_log deny_log"
SQLCMD="mysql ${SQL_DB} --batch -u squid -psecret";
MONTH=$(date +%m)
YEAR=$(date +%Y)
# We rotate on the first day of a new month
if [ "$MONTH" == "1" ]; then
MONTH=12
else
MONTH=$(($MONTH-1))
fi
# Pad with 0
MONTH=$(printf "%02d" $MONTH)
DATE=$MONTH"_"$YEAR
for T in ${TABNAME}; do
# create table 0
echo "CREATE TABLE IF NOT EXISTS ${T}_0 LIKE ${T};" | $SQLCMD;
# Rotate table
echo "FLUSH TABLES ${T}; RENAME TABLE ${T} TO ${T}_$DATE; RENAME TABLE ${T}_0 TO ${T}" | ${SQLCMD} >/dev/null 2>&1
# Drop _0 table if we rotate more than two times a month
if echo "DESCRIBE ${T}_0;" | ${SQLCMD} >/dev/null 2>&1; then
echo "DROP TABLE ${T}_0;" | $SQLCMD
fi
#compress 2
cd /var/lib/mysql/${SQL_DB}/
echo "FLUSH TABLE ${T}_${DATE};" | $SQLCMD
myisampack -s "${T}_${DATE}.MYI"
myisamchk -s -rq --sort-index --analyze "${T}_${DATE}.MYI"
echo "FLUSH TABLE ${T}_${DATE}" | $SQLCMD
done
# Now check existing table to drop olds ones
for T in $(echo "show tables" | $SQLCMD | grep -v -P "^Tables_in_"$SQL_DB | grep -v -P "^(access|deny)_log$"); do
TMONTH=$(echo $T | perl -pe 'm/^(access|deny)_log_(\d+)_(\d+)/; print $2;exit')
TYEAR=$(echo $T | perl -pe 'm/^(access|deny)_log_(\d+)_(\d+)/; print $3;exit')
# Drop table if older than configured retention
if [ "$(($(date -d "01/$MONTH/$YEAR" +%s)-$(date -d "01/$TMONTH/$TYEAR" +%s)))" -gt "$((24*3600*$RETENTION))" ]; then
echo "DROP TABLE $T;" | $SQLCMD
fi
done
===== Quelques requêtes utiles =====
* Les 30 domaines les plus visités:
select domain,count(domain) as occurances from access_log group by domain order by occurances DESC limit 30;
* Les 10 catégories qui génèrent le plus de blocage par squidGuard
select category,count(category) as occurances from deny_log group by category order by occurances DESC limit 10;
* Afficher toutes les pages consultées (et le login de l'utilisateur) depuis la machine 192.168.7.50 le 8 Octobre 2012 entre 22h00 et 23h00
select date_day,date_time,url,username from access_log where client_ip='192.168.7.50' and date_day='2012-10-08' and date_time>'22:00:00' and date_time<'23:00:00';
* Même requête que précédemment, mais en exportant le résultat au format CSV dans /tmp/result.csv
select date_day,date_time,url,username INTO OUTFILE '/tmp/result.csv' FIELDS TERMINATED BY ','
OPTIONALLY ENCLOSED BY '"' ESCAPED BY '\\' LINES TERMINATED BY '\n'
from access_log where client_ip='192.168.7.50' and date_day='2012-10-08' and date_time>'22:00:00' and date_time<'23:00:00';