Однажды, сидя поздним вечером на работе, захотелось сделать простенький шустренький дашборд, который бы отрисовывал графики ошибок или других варнингов из логов Apache или Ngnix. Термин Realtime слегка льстит, в действительности мы видим обновление на графике каждые 3 секунды. Такого плана дашборд, очень полезен особенно когда идет выкатка новой версии в бой, сидишь и смотришь как она тихонечко расползается по серверам, изменяя направления кривых на графике.
Сразу хочу показать что получилось
Серверная часть
на каждом сервере где есть лог, тейлимся к нему
tail -f /var/log/log | perl frenko_sender.pl
frenko_sender.pl
#!/usr/local/bin/perl -w
use strict;
use IO::Socket;
my($sock, $server_host, $msg, $PORTNO);
$PORTNO = 15555;
$server_host = '188.x.x.x';
$sock = IO::Socket::INET->new(Proto => 'udp',
PeerPort => $PORTNO,
PeerAddr => $server_host)
or die "Creating socket: $!\n";
while (<>){
$sock->send($_)
}
Как видим, frenko_sender.pl, просто отсылает каждую строчку из лога по udp на сервер, где будет происходить агрегация данных. Кстати можно обойтись и без этого скрипта, если научить syslogd сразу слать логи по udp в нужное нам место, ну и, как заметил Dreadatour nc (Netcat) тоже никто не отменял:
tail -f /var/log/log | nc -u 188.x.x.x 15555
Был выбран перловый вариант, так как в планах прикрутить туда раунд робин что бы циклично распределять нагрузку между серверами, которые будут обрабатывать логи.
Теперь о сервере(frenko_listen.pl) который считает нам статистику, спасибо Диме Карасику за IO::Lambda, так как именно на нем я остановил свой выбор.
frenko_listen.pl line(1-30)
#!/usr/local/bin/perl -w
use strict;
use warnings;
use Cache::Memcached::Fast;
use IO::Socket;
use IO::Lambda qw(:all);
use IO::Lambda::Socket qw(:all);
use Getopt::Std;
use POSIX qw/setsid/;
my $PORT=15555;
my $LOCALHOST ='188.x.x.x';
my $CONFIG='./frenko_config';
my $time_to_die=0;
my $memd = new Cache::Memcached::Fast({
servers => [
{ address => 'localhost:11211', weight => 2.5 }],
connect_timeout => 0.2,
io_timeout => 0.5,
close_on_error => 1,
max_failures => 3,
failure_timeout => 2,
ketama_points => 150,
nowait => 1,
utf8 => ($^V >= 5.008001 ? 1 : 0),
});
$LOCALHOST — это внешний айпишник для нашего сервера, который слушает 15555 порт по UDP. Как вы догадались, чиселки будем писать в memcached =).
frenko_listen.pl line(32-46)
my %Regexps=();
load_config(\%Regexps);
sub load_config{
my $re=shift;
%{$re}=();
open (F,$CONFIG) || die 'cant open config '.$CONFIG;
while (<F>){
next if /^[\s\n]+$/;
my ($regexp,$key,undef,$rate)=split("\t",$_,4);
$$re{$key}{re}=$regexp;
$$re{$key}{rate}=$rate || 1;
}
close (F);
}
Тут мы загружаем конфиг с регулярными выражениями, по которым будем определять правила подсчета статистики. Конфиг выглядит вот так:
frenko_config
errdescr= 9 [E2;Javascript error at web interface - nginx acclog] 1
errorcode=\d+ 10 [E3;Fail upload with errorcode - nginx acclog] 1
В первой колонке регулярка, потом уникальный ключ, по которому мы будем считать и выводить данные на график, в третей колонке описание ошибки, краткое и полное, ну а в последней колонке это вероятность, с которой мы будем сохранять данные. Например если мы будем выводить на график хиты пользователей, то у нас на одном графике будет огромный разрыв между кривыми, например ошибок 3 а хитов за это время 30000, для данной ситуации используют логарифмический масштаб, но хочется что б было красиво. Поэтому для хитов мы б ставили например 0.1 — это значт что только в 10% мы будем увеличивать счетчик хитов.
frenko_listen.pl line(49-80)
sub sendstat{
my ($key,$rate,$memd)= @ _;
if ($rate==1 || $rate<rand()){
saver($key,$_,$memd) for (2,300,1200)
}
}
sub saver{
my ($key,$accur,$memd)=@ _;
my $memc=startpoint($accur);
$key=$key.'_'.$accur.'_'.$memc;
my $ttl=1000;
if ($accur==300){$ttl=7400}
elsif($accur==1200){$ttl=87000}
$memd->set($key,1,$ttl) unless $memd->incr($key);
}
sub startpoint{
my $accur=shift;
my $t=time();
my $x=$t % $accur;
my $memc=$t-$x;
return $memc;
}
Тут непосредственно увеличиваем счетчики для наших данных. Причем храним данные в 2х, 300 и 1200 секундных ячейках, для графиков которые обновляются раз в 3 секунды, раз в 5 минут и раз в 20 минут. Ключи для мемкеша например для 2х секундной ячейки (для Javascript error из нашего frenko_config) будут выглядеть вот так: 9_2_1338129044, 9_2_1338129046 для 300 секундной ячейки: 9_300_1338121800, 9_300_1338122100 и т.д.
frenko_listen.pl line(82-128)
sub udp_server(&@)
{
my ($callback, $port, $host) = @ _ ;
my $server = IO::Socket::INET-> new(
Proto => 'udp',
LocalPort => $port,
LocalHost => $host,
Blocking => 0,
);
return $! unless $server;
return lambda {
context $server, 65536, 0;
recv {
my ( $addr, $msg) = @ _ ;
again;
context $callback-> (), $addr, $msg;
&tail();
}}
}
sub handle_incoming_connection_udp
{
lambda {
my ( $addr, $msg ) = @ _ ;
if (length($msg)>5){
if (! index($msg,'reconfig')){
load_config(\%Regexps);
}
else {
foreach (keys %Regexps){
if ($msg=~/$Regexps{$_}{re}/){
sendstat($_,$Regexps{$_}{rate},$memd);
last;
}
}
}
}
}
}
sub runserv{
my $server = udp_server { handle_incoming_connection_udp } $PORT,$LOCALHOST;
die $server unless ref $server;
$server-> wait;
}
Обработка логов происходит внутри sub handle_incoming_connection_udp. Смотрим, что если строчка длиннее 5 символов, то начинаем ее парсить. Пробегая по списку наших регулярок, загруженных из конфига.
Представьте себе ситуацию, например вы слушаете логи на трехстах серверах, и вам понадобилось добавить в конфиг новую регулярку, если вы остановите frenko_listen.pl, то потеряете данные. Чтоб избегать таких ситуаций нужно научить наш сервер обновлять конфиг на лету, что и сделано выше. Если нам пришла строчка которая начинается на 'reconfig', то, мы перегружаем конфиг. Ну и конечно же не забываем про wrapper который будет поднимать наш frenko_sender.pl во время падения.
Тут кстати нужно подумать над тем как оптимизировать пробег =).
Например бежать в определенном порядке, отсортированном по частоте. То есть если у нас хостов намного больше, чем других метрик, то нужно начинать пробег с регулярки для хостов. Также вместо некоторых регулярок можно использовать функцию index().
На данный момент получается что при обработке 1042 строк логов в секундну (в конфиге 15 регулярок) нагрузка на процессор 30-32%
два 4-ёх ядерных Intel(R) Xeon(R) CPU E5405 @ 2.00GHz
Когда видишь такие цифры, то становится грустно. Переделаем наш конфиг добавив четвертым параметром выражение для index() — она должна ускорить дело.
frenko_config
errdescr= 9 [E2;Javascript error at web interface - nginx acclog] 1 errdescr=
errorcode=\d+ 10 [E3;Fail upload with errorcode - nginx acclog] 1 errorcode=
И также немного изменим нашу функцию загрузки конфига и парсинга:
sub load_config{
my $re=shift;
%{$re}=();
open (F,$CONFIG) || die 'cant open config '.$CONFIG;
while (<F>){
next if /^[\s\n]+$/;
my ($regexp,$key,undef,$rate,$index)=split("\t",$_,5);
$index=~s/[\n\t\r]//g;
$$re{$key}{re}=$regexp;
$$re{$key}{index}=$index;
$$re{$key}{rate}=$rate || 1;
}
close (F);
}
sub handle_incoming_connection_udp
{
lambda {
my ( $addr, $msg ) = @_;
if (length($msg)>5){
if (substr($msg,0,8) eq 'reconfig'){
load_config(\%Regexps);
}
else {
foreach my $key(keys %Regexps){
if (index($msg,$Regexps{$key}{index})>=0){
if ($Regexps{$key}{index} eq $Regexps{$key}{re}){
sendstat($key,$Regexps{$key}{rate},$memd);
last;
}elsif($msg=~/$Regexps{$key}{re}/){
sendstat($key,$Regexps{$key}{rate},$memd);
last;
}
}
}
}
}
}
}
Данные модификации немного снизили нагрузку на проц, получилось 25-28%. В идеале получить хотя бы 10%.
Данные по memcached выглядят следующим образом:
STAT uptime 601576
STAT bytes_read 358221242
STAT bytes_written 92007777
STAT bytes 5018318
STAT curr_items 62269
STAT total_items 557908
STAT reclaimed 372969
Идем дальше
frenko_listen.pl line(130-157)
sub signal_handler{
$time_to_die=1;
}
getopts('d:', my $opts = {});
if (exists $opts->{d}) {
print "start daemon\n";
my $pid=fork;
exit if $pid;
die 'Couldn\'t fork: '.$! unless defined($pid);
for my $handle (*STDIN, *STDOUT, *STDERR){
open ($handle, '+<', '/dev/null' ) || die 'Cant\t reopen '.$handle.' to /dev/null: '.$!;
}
POSIX::setsid() || die 'Can\'t start a new session: '.$!;
$time_to_die=0;
$SIG{TERM} = $SIG{INT} = $SIG{HUP}= \&signal_handler;
until ($time_to_die){
runserv();
}
}
else {
runserv()
}
Здесь, мы научили наш сервер демонизироваться по флажочку -d.
Итого, у нас получилась хорошо масштабируемая серверная архитектура. Осталось дело за малым. Перейдем к клиентской части.
Клиентская часть
Пересмотрел множество рисовалок для графиков, но остановился на highcharts, так как там есть возможность рисовать график без флеша, динамически аяксом подгружая данные для новых точек, ну и кучу остальных плюшек. Идем на highcharts и делаем все как описано в документации. Там все просто.
Данные для клиентской части я отдаю fastcgi скриптом, он ходит в мемкеш и отдает точки для заданного промежутка времени.
Сам график выполняет два запроса: это начальная инициализация и порция новых точек для графика. Ответы на эти запросы выглядят вот так:
/frenky.fpl?init=1&accur=2
{"status":"1","init":[["U1",[[1338188480,19],[1338188482,21],[1338188484,11],[1338188486,19],[1338188488,13],[1338188490,9],[1338188492,13],[1338188494,18],[1338188496,14],[1338188498,21],[1338188500,17],[1338188502,13],[1338188504,21],[1338188506,19],[1338188508,22],[1338188510,23],[1338188512,14],[1338188514,17],[1338188516,24],[1338188518,15],[1338188520,23],[1338188522,19],[1338188524,20]],"User uploaded the file - apache errlog"]]}
/frenky.fpl?refresh=1&accur=2
{"status":"1","refresh":[[1338188814,20],[1338188814,1],[1338188814,0],[1338188814,0],[1338188814,0],[1338188814,0],[1338188814,0],[1338188814,8],[1338188814,7],[1338188814,0],[1338188814,0],[1338188814,0]]}
Одна из проблем, с которой я столкнулся — это если в случае двух запущенных процессов fastcgi мы хотим, чтобы они обновили себе конфиг с регулярками. Как через веб интерфейс достучаться до обоих процессов — красивого решения пока что не нашел, поэтому просто перезапускаю апач.
Скачать все исходники, включая js и fcgi, можно тут rdash.rar
UPDATE
После всех, описанных в комментариях, оптимизаций получили следующие цифры:
при нагрузке 50 тыс строк в секунду кушает 80% CPU
если добавить сортировку правил то 80 тыс строк в секунду и 90% CPU
https://github.com/frenkyoptic/rdash