Приложение в твоем смартфоне
Приложение в твоем смартфоне
Приложение в твоем смартфоне
Приложение в твоем смартфоне
28 мая 2012 в 19:42

Риалтайм дашборд

Perl*

Однажды, сидя поздним вечером на работе, захотелось сделать простенький шустренький дашборд, который бы отрисовывал графики ошибок или других варнингов из логов 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 ) = <hh user=_>;

		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
+36
2508
111
noxx 16,0 G+

комментарии (41)

–21
unity_ultra_hardcore, #
А что за странный язык? Есть археологи в посте?
+15
mephist, #
да вы остряк, как я погляжу
+7
Eternalko, #
Перлы выдает :)
+2
vovochka404, #
И у этого человека в профиле «о себе: ДУХ СТАРОЙ ШКОЛЫ ЖИВЕТ В НАС » :-D
+1
noxx, #
Серверная часть на Perl
+7
Dreadatour, #
Не поддавайся на трололо
+3
jackz, #
А красивенько получилось. Докрутить бы еще плавный сдвиг графиков с прорисовочкой линий, чтобы не так дергано было — вот это красотень была бы :)
–2
vibornoff, #
Топик добра…
+1
bondbig, #
Красиво, но вот только при достаточно серьезной нагрузке (количестве логов в секунду) все это дело довольно быстро скукожится.
0
noxx, #
На данный момент 106 серверов и кушаем не более 30% cpu
0
noxx, #
ну и плюс вы можете поставить несколько серверов которые будут обрабатывать логи
0
bondbig, #
так вопрос в том — сколько логов в секунду сможет обработать один сервер.
0
noxx, #
на данный момент нагрузка примерно 2000 логов в секунду (106 серверов) 30% cpu в конфиге 15 толстых регулярок
0
bondbig, #
Т.е. в среднем 20 записей в секунду генерит один сервер. Не так и много. Промышленные решения собирают до 100 000 записей в секунду на одно устройство.
Но для homebrew вполне хорошо.
+1
noxx, #
Буду еще оптимизировать =)
0
bondbig, #
пожелаю успехов! Может вырастет в продукт промышленный.
+1
valodka, #
Если 100 тыс. записей об ошибках в секунду, то это как-то совсем плохо, наверное
0
bondbig, #
почему об ошибках? Любых записей. Я речь веду про системы лог-менеджмента. Которые собирают любые логи в любых форматах с любых устройств. И приводят их к общему виду.
0
slang, #
Есть реализация от facebook под названием scribe. Поможет легко, быстро, масштабируемо и отказоустойчиво собрать логи на Вашем статс-сервере с имеющихся нод. А сам парсер круто бы переписать на чём-то быстром, типа C — решение будет очень неплохим. Используем подобное в продакшне, отказались от регулярок и сравниваем строки, даже кривой первый ПХПшный парсер делает 3500/сек строк при удачном подборе размера файлов скрайба. На С всё гораздо быстрее, а передачей логов с нод скрайбом вообще можно пренебречь.
0
bondbig, #
оно только собирает? Или же парсит тоже? Самое сложное как раз распарсить логи от разнородного ПО и железа, привести к общему формату, чтобы потом анализировать можно было. Ну, для примера, на одном МСЭ блокирующее действие оставляет запись DROP, на другом — DISCARD, на третьем DENY. И все это еще в разных форматах и по разным каналам (syslog, opsec, nfs, eventlog, etc.) А на лог-сервере все должно быть в общем виде, если мы строим график по заблокированным соединениям, например, то строить надо независимо от того, что именно было написано в логе и как мы его (лог) получили.
0
slang, #
Не парсит оно, это отличный прозрачный транспорт, не более того. К тому же есть апи на куче языков для его использования, Вам же нужно придумать свой этот единый формат, и выбрать метод обработки:
1. Обрабатывать на ноде, с учётом специфики, приводя к единой схеме и слать в скрайб, на статс сервере же колбасить этот единый формат и отдавать в следующий слой, например построение графика.
2. Сыпать как есть в скрайб, и решать на стаст-сервере вопросы различного парсинга, форматирования и дальнейшей аггрегации/показа.
0
bondbig, #
ну, тогда скорости не интересны, просто транспорт упрется банально в сеть или диски.
Я же говорил про все вышесказанное, когда сказал про 100 000 в секунду, а не тупо передать.
0
slang, #
Любой транспорт упрётся в сеть, речь ведь не об этом. Я предложил скрайб как хорошую систему передачи данных. Понятное дело, что реализацию обработки конкретных исключительных ситуаций Вам придётся делать самому, Вы не найдёте готовой системы, покрывающей все форматы устройств. Опять же, скрайб однозначно отвечает на вопросы, насколько легко добавить/убрать ноды, сменить ранг или приоритезацию. А также, что произойдёт если нода станет генерировать слишком много логов, успеет это всё отротейтиться? А не потеряете ли Вы важные данные в случае обрыва связи с одной из нод? А при падении статс-сервера? Что делать в исключительных ситуациях, куда бежать? В скрайбе это всё решено и конфигурируемо. Парсинг же — задача конкретного исполнения (не совсем общая задача), и Вам его нужно организовывать, желательно, отдельным слоем, желательно на чём-то быстром.
–3
bondbig, #
Меня не интересуют задачи, стоящие перед разработчиками/программистами. Я не программист. Но в деле log-management, особенно в его инкарнации в SIEM, разбираюсь очень даже неплохо (зарабатываю этим на жизнь, можно сказать), не надо мне ничего тут продавать, я сам могу продать готовые решения, которые не придется пилить с IDE и отладчиком )
И все эти «исключительные» ситуации не являются такими уж исключительными и страшными для известных мне готовых решений.
–1
slang, #
Держите нас в курсе…
А мой комментарий же относился больше к топик-стартеру (тут уж я ответом промахнулся), отражает личный опыт и может быть полезен другим читателям. Не зацикливайтесь на нём сильно, я Вам ничего не продаю.
0
bondbig, #
К топик-стартеру надо обращаться в корне дерева, а не в глубине ветки под моим комментарием. Прости, если чем обидел, я не нарочно.
0
bondbig, #
какая разница, сколько серверов? Каждый может посылать 10 логов в минуту, так и 1000 можно поставить.
Сколько логов в секунду поступает — вот что интересно.
0
stolen, #
Чтоб избегать таких ситуаций нужно научить наш сервер обновлять конфиг на лету, что и сделано выше. Если нам пришла строчка которая начинается на 'reconfig', то, мы перегружаем конфиг. Ну и конечно же не забываем про wrapper который будет поднимать наш frenko_sender.pl во время падения.

Хочется взять и переписать на Erlang.

Но вообще очень круто. Многим симпатична идея реалтайм-отрисовки логов, но немногим приходит в голову просто взять и реализовать.

Нет ли желания еще и websockets прикрутить для большей реалтаймовости?
0
stolen, #
А, ну у вас же есть серьезный аргумент, затмевающий все плюшки эрланга.
+1
Dreadatour, #
Офигеть, ты подстригся?! о_О
+1
stolen, #
Ага. Оказалось, что в длинных волосах топор иногда запутывается. Очень неудобно выходит в таких случаях.
0
noxx, #
Есть, но после оптимизации серверной части =)
0
chemistmail, #
Интересно послушать про аргумент, даже очень.
По факту, у самого антибот на erlang работающий по аналогичной схеме, регулярки там тоже есть с вебморды добавляются, для них мозиловский js прикручен, + полный разбор по кусочкам access логов + разная логика.
Количество логов аналогичное, кушает в 1 — 3 % от cpu на виртуалке с 1 cpu и гигом оперативы.
Хост система аналогична указанной в посте.
И да, при желании можно распараллелить на кластер из нескольких машин.
+1
seriyPS, #
Тут кстати нужно подумать над тем как оптимизировать пробег =).
У меня была похожая задача. Сделал так:
— Есть список регулярок [re1, re2, re3, re4, re5, ..., reN]
— приходит строчка лога и последовательно проверяется регулярками пока не заматчится. Например re4
— подошедшая регулярка перемещается в начало списка [re4, re1, re2, re3, re5, ..., reN]
— так что следующая строчка лога будет проверяться сперва этой регуляркой, потом остальными

Получается что редкие регулярки быстро сползают в конец а частые держатся ближе к началу. Если добавить еще какие-то веса, то можно еще улучшить характеристики.

Не сказал бы, что это сильно что-то ускорило, профайлер показал что это не самое узкое место. В итоге вместо Python запустил PyPi и получил 2x ускорение.

Единственное что — в Python хорошей структуры данных для такой работы не нашел. Хорошо подошел бы связный список…
+1
Dreadatour, #
Можно просто посмотреть все метрики на данный момент времени и отсортировать регулярки, их определяющие, в соответствующем порядке. И пересортировывать, скажем, раз в минуту.

Ещё вариант — в начало списка помещать подстроки (регулярки) для тех выражений лога, для которых нет метрик, но которые часто встречаются в логе — чтобы их отсеять сразу и не гонять регулярки зря (есть вероятность профукать часть статистики — нужно быть осторожным).
+2
vovochka404, #
Есть еще одно предложение по оптимизации. Никак не могу понять почему его никто не упомянул.
НЕ комилировать регулярки при каждом сравнении, а компилировать их лишь при чтении с конфига:

# $$re{$key}{re}=$regexp;  - было.
$$re{$key}{re}=qr($regexp); # стало.

perldoc.perl.org/perlop.html#Regexp-Quote-Like-Operators

0
noxx, #
Приду на работу попробую и отпишусь. Еще кстати есть такая штука как study()
0
DurRandir, #
«study» is now a no-op, presumably fixing all outstanding bugs related to study causing regex matches to behave incorrectly! © perl5160delta
0
noxx, #
Спасибо, сделал, пару процентов снизил.
0
stalker_by, #
Не в качестве критики, но очень советую посмотреть на Splunk, real-time анализ практически любых логов с графиками, дашбордами, отчетами и п.р.
0
Bteam, #
Не знаю что тут происходит но вот хорошая штука для отображение данных основанных на времени square.github.com/cubism/
Там даже две версии серверной части поддерживается.

Только зарегистрированные пользователи могут оставлять комментарии. Войдите, пожалуйста.