Сеанс консольной магии: анализ access логов nginx'а.
О том, что где-то рядом живут sed, grep, awk и pipelines, я узнал еще года 4 назад, но использовать (с толком) их не приходилось. Пока не захотелось странного…
Странное заключалось в поиске запросов от парсеров в логе nginx’а, и в поиске “дорогих” страниц.
Оказалось все просто:
- sed – потоковый редактор текста. Т.е. ты ему поток текста, а он его преобразует по данным тобою правилам.
- grep- потоковый фильтр. Ты ему критерий, он тебе данные, отфильтрованные по этому критерию.
- awk – скриптовый язык для обработки потоков. Мощная штука. Очень мощная штука.
А теперь хором
Задача номер один – поиск парсеров. Парсеры отличаются тем, что делают много запросов с одного IP. Понеслась…
Файл group_by_ips.sh:
awk '
{
requests_count_from_ips[$1]++
}
END
{
for (ip in requests_count_from_ips)
{
print requests_count_from_ips[ip] ": " ip;
}
}' | \
sort -nr
Создаем массив, в котором в качестве ключей используем IP, а в качестве значений – количество запросов с него. Т.к. IP в access логе у нас стоит первым, то соответственно его значение попадет в скрипт, как $1. По окончанию обработки потока бежим по массиву и выводим первым – количество запросов, а потом IP. Ну и сортируем вывод sort’ом.
#cat ./access.log | ./group_by_ips.sh | head
81015: 66.249.72.83
11740: 69.80.244.163
6527: 82.193.155.236
2456: 88.212.197.90
1833: 195.131.145.226
1770: 67.202.41.3
1584: 195.208.157.26
1544: 89.239.140.106
1235: 89.252.9.34
1208: 72.26.227.114
Мы для кого работаем?
Задача #2 состоит в определении “стоимости” различных url. Стоимостью мы будем считать время работы backend’а. Для того, чтобы он попал в access лог будем использовать переменную “upstream_response_time”. Формат моих логов:
log_format fastcgi_log '$remote_addr $request $status $body_bytes_sent'
' $http_referer $upstream_response_time $request_time $time_local $host [$http_user_agent]';
Файл calc_weights_by_urls.sh:
awk '{
gsub(/[0-9]+/, "X", $3);
urls[$2" "$3] += $8;
}
END
{
for(i in urls)
{
print urls[i]":"i;
}
}' | \
sort -nr
#cat ./access.log | ./calc_weight_by_urls.sh | head
88160.2:GET /users/X/
85643.6:GET /photos/X/
84629.4:GET /photos/category/X/?pager=X
45453.2:GET /photos/X/?from_member
25910:GET /users/X/?pager=X
9275.3:GET /photos/category/X/
8299.5:GET /
8298.21:GET /users/X/photos/?category=X
4309.97:GET /my/favorite_authors_photos/
4304.44:GET /new_on_site/photos/?pager=X
Коль пошла такая пьянка
Раз уж у нас есть данные по стоимости каждого запроса, то можно улучшить решение первой задачи, и считать стоимость IP не по количеству запросов, а как сумму стоимостей запросов с этого IP.
Файл calc_weights_by_ips.sh:
awk '
{
ips[$1] += $8;
}
END
{
for(i in ips)
{
print ips[i]":"i;
}
}' | \
sort -nr
cat ./access.log | ./calc_weight_by_ips.sh | head
42533.1:66.249.72.83
12886.8:69.80.244.163
5272.19:82.193.155.236
3892.73:93.189.148.97
1678.77:88.212.197.90
1424.76:67.202.41.3
1327.53:82.207.122.195
1318.4:81.19.66.89
1199.44:67.195.45.213
1114.04:80.72.18.82
В итоге три первых IP сохранились, а дальше уже картина немного другая.
Немного о скорости
Несмотря на то, что я, мягко говоря, не айс в этих утилитах, и скорее всего написал все криво и неоптимально, но скорость все равно радует:
- размер анализируемого лога – 160Mb (650К строк)
- время работы подсчета стоимости по IP – 2 секунды
- время работы подсчета стоимости по урлам – 4 секунды
awk ‘ { requests_count_from_ips[$1]++ }
END { for (ip in requests_count_from_ips) { print requests_count_from_ips[ip] “: ” ip;
} }’ | sort -nr
Это плохой пример, если нужно пропарсить гигабайты упакованных логов
А гигабайты обрабатывает конструкция:
sort | uniq -c | awk ‘{ print $1 “: ” $2 }’ | sort -nr
Т.е.
awk ‘ { requests_count_from_ips[$1]++ }
END { for (ip in requests_count_from_ips) { print requests_count_from_ips[ip] “: ” ip;
} }’
Эквивалентно
sort | uniq -c
Цветовое кодирование? Можно пример?
Давно уже вдоль и поперёк изъезженная тема, но всё равно как садишься за консоль, аж волосы дыбом встают от ощущения магии. =)
Я, кстати, люблю ещё применять цветовое кодирование на основе каких-либо критериев. Awk по сути использует псевдо-C язык, я же предпочитаю писать анализаторы на awk в связке с PHP.
>idler комментирует…
– мощности машины ведь не >указаны
> 2 секунды, 4 секунды…
> Это ни о чем не говорит
На самом деле это не особо важно. Главное, что это не 3 часа, а секунды.
Пофиксил ))
awk: cmd. line:5: END blocks must have an action part
2 секунды, 4 секунды…
– мощности машины ведь не указаны
Это ни о чем не говорит
а не думаешь что оно уже где-нить реализовано? всетаки задача анализа логов не такая уж и редкая.
Ну так!
Одна из безумных идей – реализовать подобие fluent intarface для логов.
lmbLog('access.log')->filter(1, '192.168.0.1')->count(3)->groupby(8);
отлично, попробовал у себя тоже.
правда пришлось доработать скрипт подсчета “стоимости” урлов, чтобы он показывал еще количество запросов и среднее время загрузки страницы (правда я и так его знаю).
как грится – пишите еще
Не эквивалентно, ибо “uniq -c” выдаст количество совпадений строк, а не ip’шников.