Логирование в Haskell с помощью hslogger

29 января 2014

В любом серьезном приложении должно быть логирование, и по возможности логов должно писаться как можно больше. Тут даже обсуждать нечего. Наиболее каноничным средством для решения этой задачи в мире Haskell является гибкий и богатый возможностями пакет hslogger. Сегодня мы научимся работать с ним.

Основные функции следующие:

debugM :: String -> String -> IO ()
infoM :: String -> String -> IO ()
noticeM :: String -> String -> IO ()
warningM :: String -> String -> IO ()
errorM :: String -> String -> IO ()
criticalM :: String -> String -> IO ()
alertM :: String -> String -> IO ()
emergencyM :: String -> String -> IO ()

Как вы, конечно же, догадались, они пишут в лог сообщения. Притом сообщения имеют восемь уровней приоритета, где наименьшим является уровень debug, а наибольшим – emergency. Первым аргументом эти функции принимают имя логера. Логеры в hslogger создаются динамически по мере использования и образуют иерархическую структуру. Например, логер с именем «foo» является родителем логера с именем «foo.bar». Вторым аргументом функции принимают непосредственно сообщения.

В действительности, приведенные выше функции являются обертками над функцией logM:

logM :: String -> Priority -> String -> IO ()

… где Proority определен таким образом:

data Priority = DEBUG | INFO | NOTICE | WARNING | ERROR | CRITICAL |
                ALERT | EMERGENCY

Полученных знаний уже вполне достаточно для того, чтобы написать простейшее приложение, использующее hslogger:

import System.Log.Logger

-- 'comp' is short for 'component'
comp = "LoggingExample.Main"

main = do
  noticeM comp "Just a notice"
  warningM comp "Just a warning"

Если скомпилировать и запустить программу, мы увидим сообщение «Just a warning». По умолчанию все сообщения с приоритетом warning и выше выводятся в stderr, а остальные сообщения игнорируются. Поэтому сообщение только одно.

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

updateGlobalLogger :: String -> (Logger -> Logger) -> IO ()

Применяет изменения к логеру с заданным именем.

setLevel :: Priority -> Logger -> Logger

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

Если теперь скомпилировать такую программу:

import System.Log.Logger

comp = "LoggingExample.Main"

main = do
  updateGlobalLogger comp (setLevel NOTICE)
  noticeM comp "Just a notice"
  warningM comp "Just a warning"

… то мы увидим оба сообщения, как notice, так и warning.

Писать сообщения в stderr – это, конечно, очень круто, но все же полезнее хранить логи в файлах. Эта проблема решается в hslogger с помощью так называемых хэндлеров. Хэндлеры цепляются к логерам и как-то обрабатывают сообщения, записываемые как в заданный логер, так и в логеры, дочерние по отношению к нему. Один логер может иметь множество хэндлеров. Вот некоторые функции для работы с этим хозяйством.

fileHandler :: FilePath -> Priority -> IO (GenericHandler Handle)

Создает новый хэндлер, который пишет сообщения с приоритетом не меньше заданного в указанный файл. Если указанного файла не существует, он создается. Если же файл существует, сообщения дописываются в его конец. GenericHandler является экземпляром класса типов LogHandler.

close :: LogHandler a => a -> IO ()

Закрывает указанный хэндлер. В случае с файловым хэндлером закрывается соответствующий файл.

addHandler :: LogHandler a => a -> Logger -> Logger

Принимает хэндлер и логер, возвращает логер с добавленным хэндлером.

setHandlers :: LogHandler a => [a] -> Logger -> Logger

Полностью заменяет список хэндлеров в логере.

Рассмотрим пример:

import System.Log.Logger
import System.Log.Handler.Simple

comp = "LoggingExample.Main"

main = do
  fh <- fileHandler "./logging-example.log" WARNING
  updateGlobalLogger comp $ addHandler fh
  noticeM comp "Just a notice"
  warningM comp "Just a warning"

Теперь в файл loggin-example.log пишутся все сообщения уровня warning и выше. Но все это как-то тупо, потому что в логах не хранится ни время записи сообщения, ни имя логера – ничего. За форматирование сообщений в hslogger отвечают форматеры. У каждого хэндлера есть свой форматер, притом, понятное дело, в одном экземпляре. Рассмотрим следующие функции.

simpleLogFormatter :: String -> LogFormatter a

Принимает форматную строку и возвращает новый форматер. Форматная строка может содержать метки, начинающиеся со знака доллара. При форматировании сообщения эти метки заменяются на некие данные. Метка $msg заменяется на само сообщение, $loggername – на имя логера, $prio – на приоритет сообщения, $tid – на id нитки, $pid – на id процесса (не работает в Windows), $time – на текущее локальное время, а $utcTime – на текущее время в UTC.

setFormatter :: LogHandler a => a -> LogFormatter a -> a

Устанавливает форматер в хэндлере.

Перепишем код следующим образом:

import System.Log.Logger
import System.Log.Handler.Simple
import System.Log.Handler (setFormatter)
import System.Log.Formatter

comp = "LoggingExample.Main"

setCommonFormatter x =
  let f = simpleLogFormatter "$utcTime $prio $loggername: $msg" in
  setFormatter x f

main = do
  fh <- fileHandler "./logging-example.log" WARNING
  let fh' = setCommonFormatter fh
  updateGlobalLogger comp $ addHandler fh'
  noticeM comp "Just a notice"
  warningM comp "Just a warning"

Теперь в loggin-example.log будет писаться что-то вроде:

2014-01-26 09:28:37 UTC WARNING LoggingExample.Main: Just a warning

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

openlog :: String -> [Option] -> Facility -> Priority ->
           IO SyslogHandler

Принимает (1) имя программы, которое будет дописываться в начало каждого сообщения, (2) настройки syslog, (3) facility и (4) минимальный приоритет сообщений. Возвращает новый хэндлер, записывающий сообщения в локальный syslog. В *nix запись производится через /dev/log, в Windows хэндлер шлет UDP-пакеты на localhost:514.

Определение Option и Facility:

data Option = PID |  -- писать pid отправителя
              PERROR -- отправлять копию каждого сообщения в stderr

data Facility = KERN | USER | MAIL | DAEMON | AUTH | SYSLOG | LPR |
                NEWS | UUCP | CRON | AUTHPRIV | FTP | LOCAL0 | LOCAL1 |
                LOCAL2 | LOCAL3 | LOCAL4 | LOCAL5 | LOCAL6 | LOCAL7

Также hslogger «из коробки» умеет ходить в syslog по сети. Подробности вы найдете в документации к модулю System.Log.Handler.Syslog на Hackage.

В очередной раз перепишем нашу программу:

import System.Log.Logger
import System.Log.Handler.Simple
import System.Log.Handler.Syslog
import System.Log.Handler (setFormatter)
import System.Log.Formatter

comp = "LoggingExample.Main"

setCommonFormatter x =
  let f = simpleLogFormatter "$utcTime $prio $loggername: $msg" in
  setFormatter x f

main = do
  fh <- fileHandler "./logging-example.log" WARNING
  let fh' = setCommonFormatter fh

  sh <- openlog "LoggingExample" [PID] LOCAL0 NOTICE
  let sh' = setCommonFormatter sh

  updateGlobalLogger comp ( addHandler sh' .
                            addHandler fh' .
                            setLevel NOTICE )

  noticeM comp "Just a notice"
  warningM comp "Just a warning"

В файл /var/log/syslog и stderr будут писаться сообщения уровня notice и выше, а в файл logging-example.log – не ниже warning.

Ничего сложного, не так ли? Мы рассмотрели только основные возможности hslogger. Более подробное описание этого пакета вы найдете на Hackage.

В качестве домашнего задания можете (1) попробовать прикрутить логирование на удаленный syslog (hint: в Ubuntu см /etc/rsyslog.conf), (2) прикрутить логирование к ранее написанным нами телефонной книге или key-value хранилищу, а также (3) поиграться с иерархиями логеров.

Исходники к этой заметке лежат тут. Как их собирать описано здесь.

Дополнение: Логирование в Haskell при помощи fast-logger