Практика написания сценария на PERL для нужд системного администратора. (Нестандартный анализ лог-файла прокси-сервера Squid Web Proxy Cache)

Опубликовано в журнале "Компьютер Price" http://www.comprice.ru/

Татьяна Ильченко < ti@sysadmins.ru >

Данная статья предназначена для системных администраторов, которые уже немного знакомы с PERL и, кроме того, желают получить от сервера максимум полезной в работе информации. Автор НЕ ЯВЛЯЕТСЯ ни экспертом, ни гуру в PERL-программировании. Статья родилась в результате желания рассказать о своем опыте в изучении некоторого количества вопросов, которые могут быть полезны коллегам по цеху.

Часть1.
Лирическое вступление с прагматическим подходом

Прокси-сервер (от англ proxy (англ.) - посредник, заместитель) - в нашем случае это программное обеспечение, в функции которого входит:

1) контроль и управление трафиком Internet по определенным протоколам (HTTP(s), FTP, POP3/SMTP etc);

2) направление всего исходящего трафика через одну определенную точку к конечным адресатам;

3) регулирование доступа пользователей локальной сети к ресурсам Internet и разделение пропускной способности канала между всеми пользователями;

4) кэширование (от англ. cache - класть в тайник; прятать что-л. про запас в потайном месте - копирование web-страниц в хранилище на сервере для уменьшения трафика);

5) регистрация всех действий пользователей при работе с ресурсами Internet;

Другими словами, прокси-сервер - это программное обеспечение, обеспечивающее общий доступ для нескольких компьютеров в Internet на одном канале по некоторым протоколам с рядом перечисленных выше функций.

Вообще, "семейство" proxy-серверов довольно обширно. Самые заметные его представители - Squid Web Proxy Cache [http://www.squid-cache.org/], OOPS! - русский проект, динамично развивающийся, но пока не вполне полновесный, [http://zipper.paco.net/~igor/oops/about.html], DeleGate [http://www.delegate.org/delegate/ ]. Среди них безусловным лидером, по крайней мере для UNIX-like платформ, является Squid Web Proxy Cache (коротко Squid). Это полнофункциональный HTTP/HTTPS/FTP прокси-сервер для UNIX-like операционных систем, свободно распространяемый с открытым исходным кодом, поддерживающий кэширование запросов, SSL-соединения, иерархическую структуру кэш-хранилища, так называемое transparent caching - прозрачное кэширование и пр. Все действия пользователя регистрируются в лог-файле, путь к которому определяется конфигурацией сервера. Как правило, это путь /usr/local/squid/logs/access.log. Вот пример записи данных в этом файле:

См. Листинг №1

Понятно, что для нас с вами все это выглядит структурированной абракадаброй - нет, кое-что здесь разобрать все-таки можно и без посторонней помощи. К примеру, можно разглядеть логины пользователей и таким вот эмпирическим путем установить, куда, например, ходил пользователь с логином _sorin. Следует учесть, что для загрузки одного документа пользователем может потребоваться не один, а несколько запросов - на каждый загружаемый объект. К примеру, для загрузки этой статьи с сервера [http://ti.rostnp.ru/articles/squid-log.html] потребуется выполнить, как минимум, 2 запроса - для того чтобы загрузить сам текст этой статьи и изображение логотипа вверху страницы. На самом деле записи о запросах, выполненных прокси-сервером для каждого пользователя от своего имени, содержат достаточно подробную информацию. Но нам-то нужно более наглядное представление. Как его получить и что полезного можно узнать, я и постараюсь рассказать в данной статье.

Поскольку в лог-файле регистрируется КАЖДЫЙ запрос, выполненный прокси-сервером, сам файл за сутки, к примеру, может "разрастись" довольно ощутимо (например, у меня на сервере за сутки файл "подрастает" на 10-12 тысяч строк). Просмотреть все это глазами в поисках информации о "Web-серфинге" того или иного пользователя, трафике за сутки, ошибках и отказах сервера просто нереально. Да и подсчитывать руками все параметры тоже утомительно. Что и говорить, нужен инструмент, позволяющий сгенерировать удобочитаемый отчет по функционированию прокси-сервера за определенные периоды (час, сутки, неделя, месяц и т.п.). Это позволило бы не накапливать данные в лог-файле, а оперативно очищать его - ведь надобности хранить исходные данные при наличии готовых отчетов нет. А сами отчеты занимают существенно меньше дискового пространства. Экономия и польза, как говорится, налицо.

Существует масса готовых решений для задачи анализа лог-файлов SQUID. Многие из них перечислены на странице [http://www.squid-cache.org/Scripts/index.html]. Некоторые можно найти, вопользовавшись поиском на [http://www.opennet.ru/]. В конце концов, можно написать персональный анализатор, или, как еще называют такие программы, парсер лог-файла нашего прокси-сервера. Я в работе использую готовый продукт SARG [http://web.onda.com.br/orso/sarg.html]. Всем хорош. И статистику генерирует в html-формате, помещая ее в отведенное место на корпоративном web-сервере, и гибкий в настройке, и параметров для сбора статистики много хороших и разных. Одно грустно - полезно иногда посмотреть статистику по отдельно взятым отказам сервера. Например, документы, с каких серверов были взяты из кэша, а какие - скачаны напрямую с серверов. Или, к примеру, сравнить общее количество запросов с количеством полученных пользователями отказов и сравнить это с пиковыми загрузками сервера. Это поможет оптимизировать работу сервера или покажет, что один такой сервер не справляется с пиковыми нагрузками и хорошо бы поставить дополнительный. Есть над чем задуматься. А тут еще на одном из форумов [http://sysadmins.ru] столкнулась с описанием подобной задачи. Как говорится, идея витала в воздухе. В конце концов, оформившись в некое подобие тут же написанного совместно с Андреем Бешковым [tigrisha@sysadmins.ru] в ходе online-переговоров ТЗ (технического задания), первая версия программы анализа лог-файла увидела свет. После тестирования и обсуждений на том же форуме, были сделаны кое-какие изменения и дополнения в исходном коде, устранены некоторые незамеченные при первоначальной отладке досадные мелочи и принято решение о дальнейшем развитии проекта c незамысловатым названием SquidLog. Дальше мы рассмотрим исходный код сценария для версии SquidLog-1.02beta и опишем, что и для чего нужно. Некоторые же вопросы оставим читателю для размышлений - эти своего рода "домашние задания" приведены в сносках к фрагментам исходного кода. Для начала, снова обратим взор внутрь лог-файла и постараемся разобраться в его формате на примере одной из строк:

См. Листинг №2

Выше мы уже обратили внимание на то, что лог-файл представляет собой набор структурированных строк. Условимся, что каждый фрагмент этой строки, не содержащий пробелов, - поле записи. Рассмотрим подробно эти поля.

1052999660.974 - это время в секундах с начала эпохи .

149 - это затраченное на выполнение запроса время в миллисекундах

192.168.10.10 - это ip-адрес внутри нашей сети, с которого произведен первоначальный запрос.

TCP_MISS/200 - статус/результат выполнения запроса .

Теперь остановимся поподробнее на наиболее часто встречающихся статусах и кодах выполнения запроса, ибо в нашем случае это ключевая информация как для понимания функционирования сервера в целом, так и для анализа запросов в частности.

См. Листинг №3

7553 - это размер объекта, переданного клиенту, в байтах;

GET - метод получения данных (GET,POST etc)

http://b.popular.ru/bi/4876 - собственно, URL, запрошенный пользователем;

_sorin - ident, или логин пользователя на прокси-сервере (если используется аутентификация пользователей, если же ident не доступен, то значением этого поля будет '-');

DIRECT/213.27.18.133 - откуда был запрошен объект, т.н. hierarchy data. DIRECT, если объект был напрямую взят с сервера, а не найден на одном из родительских кэш-серверов (при использовании иерархии прокси-серверов это поле может получать другие значения) / хост, где расположен объект запроса;

image/gif - и, наконец, MIME/тип объекта.

С форматом лог-файла разобрались. Теперь остановимся на том, какую же информацию мы хотим видеть в отчете. То есть, остановимся на "техническом задании". Нам нужно обрабатывать различные отказы сервера, и в отчет должна попадать следующая информация: дата/время неудачного запроса, код ответа сервера, логин пользователя и его ip-адрес, URL запрашиваемого объекта.

Поскольку событий может быть достаточно много, то эту информацию будем заносить в отдельный файл, так же как и сам отчет- для того, чтобы в последующем иметь возможность более детально остановиться на этой информации. На консоль же будем выдавать только статистическую информацию, то есть сам отчет о работе сервера: сколько всего запросов за указанные сутки, сколько из них событий и сколько удачных запросов, кроме того, подобную информацию будем выдавать в почасовой разбивке с возможностью указания порядка сортировки этого вывода (в порядке убывания/возрастания временных интервалов или событий). Помимо этого, предусмотрим вывод в файлы данных посуточно, то есть собранные за каждые сутки из указываемого периода данные об отказах сервера будем "складывать" в отдельные файлы . Если коротко, то с "техническим заданием" определились. Перейдем непосредственно к воплощению на практике. Да, для того, чтобы не "засорять" командную строку, для параметров (путь к лог-файлу, порядок сортировки вывода, опции вывода на консоль или в файл, сами статусы/коды событий сервера, директорию для хранения файлов отчетов) создадим файл конфигурации и расположим его в /usr/local/etc/squidlog.conf.

Вот мой пример с полным описанием всех обрабатываемых параметров:

См. Листинг №4

Итак, будем полагать, что Squid у нас уже установлен, настроен и работоспособен.

Нужный нам лог-файл располагается в

/sr/local/squid/logs/access.log (параметр cache_access_log в squid.conf). Кроме того, нам понадобится интерпретатор языка PERL [http://www.perl.org/ ], расположенный в /usr/local/bin/ (или любом другом доступном каталоге, узнать путь к нему можно командой whereis perl), и любой доступный текстовый редактор. От традиционного vi/vim до встроенного редактора Midnight Commander - в нем, кстати, есть довольно удобная подсветка синтаксиса для PERL-сценариев (к слову сказать, этот редактор "различает" синтаксис shell, HTML, PERL, GNU/ANSI С и, в некоторых случаях, для конфигурационных файлов). Ну вот, и с минимальным "набором инструментов" тоже определились. Полный исходный текст скрипта и конфигурационный файл можно найти по ссылке в конце этой статьи.

Начнем с разбора параметра командной строки - даты или диапазона дат, за который необходима статистика. Проще всего использовать массив @ARGV для получения параметров (еще один способ, кстати, более правильный и безопасный - это использование модуля GetOpt::Long , предназначенного для работы с именованными аргументами командной строки). Поскольку должна иметь место возможность сбора статистики как за сутки, так и за несколько дней, соответственно, нужно предусмотреть как ввод интервала дат, так и ввод одиночной даты в командной строке.

См. Листинг №5

Дальше разберем конфигурационный файл, который, как мы помним, расположен в /usr/local/etc/squidlog.conf, и командную строку, после чего установим значения параметров всем необходимым в этом случае переменным. При этом не забывая объявлять их посредством функции my (приучиться к этому поможет использование модуля strict, обеспечивающего явное объявление переменных и "запрещающего" использование потенциально опасных конструкций в сценарии). Перед тем как исполнить сценарий, perl откоммилирует его и обо всех ошибках сообщит. Не стоит бросаться исправлять все перечисленные ошибки - часто достаточно исправить первую ошибку в синтаксисе или логике сценария по указанному адресу (номеру строки), чтобы устранить следующие из нее остальные ошибки. Объявление переменных, кроме того что это "хороший тон" в программировании, позволяет локализовать их область видимости внутри программы и не засорять память переменными, которые нужны только в определенном участке кода. Я не стану приводить здесь полный список всех объявленных переменных, а буду пояснять назначение той или иной переменной в ходе рассмотрения нашего сценария.

Вот фрагмент, выполняющий функции разбора конфигурационного файла (его описание вынесено ниже в тексте, чтобы не комментировать каждую строчку кода):

См. Листинг №6

Сначала мы открываем файл, проверяя возвращаемое функцией open() значение - если функция вернет нам неопределенное значение, то есть false, то попытка открыть файл не удалась. В такой ситуации мы можем либо завершить работу сценария с ошибкой, либо принять к сведению сообщение об ошибке и назначить свои значения переменным, о чем и сообщим пользователю на консоль. Второй способ кажется мне более дружелюбным по отношению к пользователю - видимо, сказывается долгая практика совмещения должности системного администратора с должностью сотрудника службы технической поддержки. В другом же случае мы обработаем конфигурационный файл по следующему принципу: удалим из файла символы перевода строки, начальные и конечные пропуски строк, пропустим строки, начинающиеся с пробелов и стандартного символа, обозначающего комментарий, "#". Оставшиеся строки разберем по принципу: все, что справа до знака "=" это наименование параметра, а все, что слева после - его значение. Пары "параметр-значение" поместим в хэш-массив (другими словами, в ассоциативный массив) %conf, где левая часть отношения будет ключом, или индексом, а правая, соответственно, значением элемента хэш-массива. Остановимся подробнее на использовании встроенной переменной PERL $_ (если указать в начале use English, то эта же переменная обозначается как $ARG - по умолчанию для операторов ввода и поиска, если в качестве аргумента не указана никакая переменная; в нее по умолчанию происходит ввод, присваивание, в нее же заносится результат поиска по шаблону). В нашем случае, в эту переменную происходит чтение строки из файла, которую мы разбираем и заполняем ассоциативные массивы. После этого последовательно разберем эти массивы и присвоим значения элементов соответствующим переменным, необходимым нам в процессе обработки лог-файла.

Первый и основополагающий параметр - полный путь к лог-файлу SQUID:

См. Листинг №7

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

См. Листинг №8

Так же мы поступим и с остальными параметрами конфигурационного файла для нашего сценария. Остановимся на них коротко.

См. Листинг №9

На этом обработка конфигурационного файла закончена. Приступим к основной части: непосредственно к обработке лог-файла прокси-сервера. Все параметры определены и занесены в "скрижали" нашего сценария .

И тут мы пока остановимся, а в следующей части перейдем непосредственно к обработке лог-файла и формированию отчета. А до выхода второй части предлагаю пользователю выполнить домашнее задание, которое дано в сноске V в конце сегодняшнего повествования.

*В UNIX-системах началу эпохи соответствует 00 часов 00 минут 00 секунд 1 января 1970 года по Гринвичу (GMT/UTC). Время в PERL представлено интервалами, измеряемыми в секундах, с начала эпохи (см. выше). В нашем же случае этот формат совпадает с форматом записи времени в файле access.log.

** Полное описание кодов ответов можно найти в RFC2616 [http://www.w3.org/Protocols/rfc2616/rfc2616.html]

*** Содержимое файлов, создаваемых сценарием: 1) для общего отчета создаются файлы с именем <дата>.sqr (отчет собирается за каждые сутки из интервала дат, указанного при запуске сценария); 2) в файл с именем sqlog.deny заносятся все строки, подпадающие под условие отбора событий (интересующие нас ответы серверов). А впрочем, именование файлов для отчетов и статистической информации - на усмотрение читателя, мне же показался удобным именно такой принцип.

**** Если у вас этого модуля не оказалось (что, на мой взгляд, странно), не отчаивайтесь - его всегда можно найти на CPAN [http://www.cpan.org/] и установить, следуя инструкциям в документации.

***** В качестве "домашнего задания" могу предложить читателю написание кода для проверки, установлен ли на сервере SQUID и где располагается файл access.log ;-)

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

******* Для достаточно загруженных серверов с большим количеством пользователей такой вывод может занять не один мегабайт текста за сутки, что чрезвычайно затруднит восприятие сгенерированной нашим сценарием суточной статистики работы сервера.