[devel] I: утилита logoved-report для обработки логов. 3-Правила Логовед.

Igor Vlasenko vlasenko на imath.kiev.ua
Пт Сен 21 20:49:25 MSK 2018 

3. Создание своих правил Логовед.

Работая с утилитой logoved-report, вы наверняка столкнетесь
с ошибками, которые хотелось бы распознать,
но logoved-report о них не знает.

Нет проблем - просто создаем свое правило .logoved в ./db/.

3.1 Синтаксис правил Логовед.

Для начала посмотрим, как выглядит какое-то простое правило Логовед.

$ cat db/sisyphus_check/summary.logoved 
PATTERN=^sisyphus_check: check-summary ERROR: invalid package summary

Мы видим однострочный файл с PATTERN=...,
аргумент для PATTERN без кавычек.
Легко догадаться, что с таким правилом логовед выполнит некий аналог
запуска утилиты pcregrep "$PATTERN" /path/to/logs.

Синтаксис текущей версии достаточно прост.
#==============================================
# допускаются комментарии;
# записи имеют вид 
KEY=VAL
# где VAL не берется в кавычки и может содержать пробелы,
# где KEY могут повторяться, а допустимые KEY это
TYPE=
SCOPE=
PATTERN=
PATTERN_SEQ=
MULTILINE_PATTERN_BEGIN=
MULTILINE_PATTERN_BODY=
MULTILINE_PATTERN_END=
DESCRIPTION=
STATISTICS=
STATISTICS_HEADER=
FIX=
# после ключевого слова __END__ все остальное игнорируется.
__END__
после ключевого слова __END__
может быть фрагмент лог файла для примера.
#==============================================

Однако с правилом db/sisyphus_check/summary.logoved не все так просто.
В каждом правиле Логовед должны присутствовать 
TYPE= и SCOPE=.
Тем не менее, в summary.logoved эти значения явно не указаны.
Откуда они берутся? При загрузке базы Логовед используются
файлы 00default для установки значений по умолчанию.

Для db/sisyphus_check/summary.logoved
это файл db/00default, откуда берутся

TYPE=error
SCOPE=run

и файл db/sisyphus_check/00default
где SCOPE переопределяется в

SCOPE=hasher::sisyphus_check

Таким образом, после загрузки, с учетом файлов 00default,
внутри программы правило db/sisyphus_check/summary.logoved
выглядит как

TYPE=error
SCOPE=hasher::sisyphus_check
PATTERN=^sisyphus_check: check-summary ERROR: invalid package summary

но при наличии файлов 00default мы можем писать только
PATTERN=^sisyphus_check: check-summary ERROR: invalid package summary
остальное придет от файлов 00default как значения по умолчанию.

3.2 Параметры правил Логовед.

3.2.1 Параметр SCOPE.

Поговорим сначала о параметре SCOPE.
Поиск по всему лог файлу -- плохая идея.
Подходящий аналог -- искать макрос в спек-файле и найти его в %changelog.
Для лог-файла тоже есть ряд примеров, когда
поиск находит совсем не то, что нужно.

библиотека Logoved-Stream разбивает на секции

 hasher::chroot::users
 hasher::chroot::install
 hasher::chroot::srpm::repack
 hasher::chroot::srpm
 rpmbuild::prep
 rpmbuild::build
 rpmbuild::install
 rpmbuild::install::brp
 rpmbuild::check
 rpmbuild::files
   rpmbuild::files::processing
   rpmbuild::files::find_requires
   rpmbuild::files::requires
   rpmbuild::files::listed_twice
 rpmbuild::write
 hasher::time
 hasher::sisyphus_check
 beehive::time
а в случае ошибок еще возникают секции
 hasher::chroot::error
 hasher::chroot::apt
 hasher::chroot::file_conflict
 rpmbuild::error

Чтобы указать нужную нам область поиска,
используется параметр SCOPE.

Просто перечислим нужные нам секции 
с помощью SCOPE. Например, для сообщений
в процессе сборки (не для сообщений от
от скриптов, входящих в rpmbuild)
нам понадобится

SCOPE=rpmbuild::prep
SCOPE=rpmbuild::build
SCOPE=rpmbuild::install
SCOPE=rpmbuild::check
SCOPE=rpmbuild::error

Конечно, такая запись довольно громоздка,
даже если ее указывать только в файлах 00default.
В Логовед БД в модуле lib/Logoved/DB/Stream/Listener/Factory.pm
определены следующие сокращения для наборов секций:

    apt
	hasher::chroot::apt
	hasher::chroot::file_conflict
    run
	rpmbuild::prep
	rpmbuild::build
	rpmbuild::install
	rpmbuild::check
	rpmbuild::error
    conf
	rpmbuild::prep
	rpmbuild::build
	rpmbuild::error
    build
	rpmbuild::prep
	rpmbuild::build
	rpmbuild::install
	rpmbuild::error
    check
	rpmbuild::build
	rpmbuild::install
	rpmbuild::check
	rpmbuild::error


Также в базе логовед этим сокращениям соответствуют
наборы правил (подкаталоги), для которых файл 00default
содержит соответствующий SCOPE.

 db/run - сообщения об ошибке при запуске
 db/conf - сообщения при конфигурировании, от configure, cmake.
 db/build - сообщения от компилятора, линковщика, других сборочных утилит
 db/check - сообщения о неудаче тестирования

в
 db/sisyphus_check/
 как мы видели, по умолчанию указан
SCOPE=hasher::sisyphus_check

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

3.2.1 Параметры PATTERN* и связанные с ними FIX и STATISTICS.

Параметры PATTERN* позволяют указать нам шаблоны поиска.
значение - регулярное выражение perl,
что значит, что надо экранировать @$%(){}*+,
если они используются как простые символы:
\@, \$ \%, \(, \), \{, \}, \*, \+

Чтобы упростить регулярные выражения perl,
из входящих строк лог файла перед применением
регулярных выражений удаляется конец - символ перевода строки "\n".

3.2.1.1 однострочный PATTERN=

Самый простой вариант -- однострочный PATTERN=

Пример:

$ cat db/run/command-not-found/perldoc.logoved 
PATTERN=perldoc: command not found
FIX=buildrequires --add /usr/bin/perldoc

В одном правиле можно указать несколько PATTERN,
достаточно, чтобы сработал только один из них:

$ cat db/apt/E-package-not-found.logoved 

# E: Couldn't find package libtau-common
PATTERN=^E: Couldn't find package (\S+)
PATTERN=^E: Невозможно найти пакет (\S+)
STATISTICS=%{GROUP:1}
STATISTICS_HEADER=E: Невозможно найти пакет:

3.2.1.2 многострочный PATTERN_SEQ=

Более сложный - многострочный шаблон PATTERN_SEQ=
фиксированной длинны.

последовательность
PATTERN_SEQ=
PATTERN_SEQ=
PATTERN_SEQ=
совпадает, если 1я строка совпадет с 1м паттерном,
2-я со вторым и т.д.

Пример1:

$ cat db/conf/automake-version/1.logoved 
PATTERN_SEQ=you need automake version \S+ or later
PATTERN_SEQ=^error: Bad exit status from /\S+ \(\%
__END__
./bootstrap: you need automake version 1.5 or later
error: Bad exit status from /usr/src/tmp/rpm-tmp.3287 (%build)

Пример2:

$ cat db/conf/automake-version/2.logoved
PATTERN_SEQ=You must have automake \S+ installed to compile
PATTERN_SEQ=Install the appropriate package for your distribution,
PATTERN_SEQ=or get the source tarball
PATTERN_SEQ=^error: Bad exit status from /\S+ \(\%
__END__
You must have automake 1.7.x installed to compile .
Install the appropriate package for your distribution,
or get the source tarball at http://ftp.gnu.org/gnu/automake/
error: Bad exit status from /usr/src/tmp/rpm-tmp.64887 (%prep)

В отличие от PATTERN, в правиле логовед из-за ограничений
синтаксиса может быть только одна последовательность PATTERN_SEQ=.
Но есть синтаксический сахар. Во flat режиме подпути,
состоящие из одних цифр, отбрасываются. Поэтому
лог файлы, подпадающие под правила
conf/automake-version/1.logoved
conf/automake-version/2.logoved
в отчете попадут в одну и ту же папку
LOGS/conf-automake-version .

3.2.1.3 шаблон MULTILINE_PATTERN_* переменной длинны.

многострочный шаблон 
MULTILINE_PATTERN_BEGIN=
MULTILINE_PATTERN_BODY=
[...]
MULTILINE_PATTERN_BODY=
MULTILINE_PATTERN_END=
применяется, когда образец может иметь переменное число строк.

Начало сопоставления задается шаблоном MULTILINE_PATTERN_BEGIN,
затем может идти что угодно, лишь бы оно подпадало хотя бы
под один из шаблонов вида MULTILINE_PATTERN_BODY=,
окончание сопоставления задается шаблоном MULTILINE_PATTERN_END.

Пример 1:
# python2/import-error.logoved
MULTILINE_PATTERN_BEGIN=^Traceback \(most recent call last\):
MULTILINE_PATTERN_BODY=^\s\s
MULTILINE_PATTERN_END=^ImportError: No module named (\S+)
FIX=buildrequires --add python2.7(%{MULTILINE_END_GROUP:1})
__END__
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/nose/suite.py", line 207, in run
    self.setUp()
  File "/usr/lib/python2.7/site-packages/nose/suite.py", line 290, in setUp
    self.setupContext(ancestor)
  File "/usr/lib/python2.7/site-packages/nose/suite.py", line 313, in setupContext
    try_run(context, names)
  File "/usr/lib/python2.7/site-packages/nose/util.py", line 471, in try_run
    return func()
  File "/usr/src/RPM/BUILD/python-module-fs-2.0.17/tests/test_ftpfs.py", line 90, in setUpClass
    from pyftpdlib.test import ThreadedTestFTPd
  File "/usr/lib/python2.7/site-packages/pyftpdlib/test/__init__.py", line 40, in <module>
    import sendfile
ImportError: No module named sendfile

Пример 2:
# python3/import-error-module.logoved
MULTILINE_PATTERN_BEGIN=^Traceback \(most recent call last\):
MULTILINE_PATTERN_BODY=^\s\s
MULTILINE_PATTERN_END=^ModuleNotFoundError: No module named '(\S+)'
FIX=buildrequires --add python3(%{MULTILINE_END_GROUP:1})
__END__
cd /usr/src/RPM/BUILD/ibus-table-chinese-1.8.2-Source/tables/array && /usr/bin/ibus-table-createdb -n array30-big.db -s /usr/src/RPM/BUILD/ibus-table-chinese-1.8.2-Source/tables/array/array30-big.tab
Traceback (most recent call last):
  File "/usr/share/ibus-table/engine/tabcreatedb.py", line 29, in <module>
    import tabsqlitedb
  File "/usr/share/ibus-table/engine/tabsqlitedb.py", line 32, in <module>
    import sqlite3
ModuleNotFoundError: No module named 'sqlite3'
make[2]: *** [tables/array/CMakeFiles/convert_array.dir/build.make:69: tables/array/array30-big.db] Error 1
make[2]: Leaving directory '/usr/src/RPM/BUILD/ibus-table-chinese-1.8.2-Source'
make[1]: *** [CMakeFiles/Makefile2:897: tables/array/CMakeFiles/convert_array.dir/all] Error 2
make: *** [Makefile:154: all] Error 2
error: Bad exit status from /usr/src/tmp/rpm-tmp.11890 (%build)

3.2.2 Параметры FIX и STATISTICS.

Раз у нас есть регулярное выражение, то мы можем выделить в образце
нужный нам фрагмент текста как ГРУППУ, просто взяв его в регулярном
выражении в простые круглые скобки.

Вернемся к правилу apt/E-package-not-found.logoved
там есть 
PATTERN=^E: Couldn't find package (\S+)
PATTERN=^E: Невозможно найти пакет (\S+)
в которых выделена одна группа (группа №1,
к ней можно обращаться как %{GROUP:1}).
к примеру, для образца
E: Couldn't find package libtau-common
значением группы №1 станет libtau-common.

Что мы можем сделать со значением группы?
можем сосчитать частоту (статистка по умолчанию)
добавим в правило параметр
STATISTICS=%{GROUP:1}
и для красоты заголовок - строку перед статистикой
STATISTICS_HEADER=E: Невозможно найти пакет:

получим в LOGS/apt-E-package-not-found
файл статистики, и сразу станет ясно, что чинить в первую очередь.

$ cat apt-E-package-not-found/00statistics 
E: Невозможно найти пакет:
  5: gnustep-Etoile-DocGenerator
  5: gdk-pixbuf-devel
  4: python-module-setuptools-tests
[...]
  1: kdepim-devel

Пример2:
db/conf/pkgconfig.logoved
содержит набор
PATTERN=^Package (\S+) was not found in the pkg-config search path
PATTERN=^configure: error: Package requirements \((\S+)\) were not met:
PATTERN=^No package '(\S+)' found
ругани на отсутствующий .pc файл.

В каждом из шаблонов выделена группа №1.

Простую статистику по частоте для нее считать не имеет смысла.
Имело бы смысл разделить .pc файлы на отсутствующие в Сизифе
и присутствующие в Сизифе, затем уже отдельно
в каждой группе статистику по частоте. Но это пока не реализовано.
Зато легко указать правило, как улучшить
(а то и починить) пакет.
Имя .pc файла -- готовый компонент для добавления в 
BuildRequires пакета. Соответствующая опция FIX имеет вид

FIX=buildrequires --add pkgconfig(%{GROUP:1})

В случае набора PATTERN_SEQ все группы в наборе
получают сплошную нумерацию. 

Набор
PATTERN_SEQ=bla (\S+) was (\S+)
PATTERN_SEQ=error: 
PATTERN_SEQ=foo '(\S+)' 

содержит группы
%{GROUP:1}
%{GROUP:2}
%{GROUP:3}

В случае MULTILINE_PATTERN_*,
%{GROUP:xx} нет, а есть отдельно
%{MULTILINE_BEGIN_GROUP:хх}
%{MULTILINE_END_GROUP:хх}

в python3/import-error-module.logoved, к примеру, будет
для
MULTILINE_PATTERN_BEGIN=^Traceback \(most recent call last\):
MULTILINE_PATTERN_BODY=^\s\s
MULTILINE_PATTERN_END=^ModuleNotFoundError: No module named '(\S+)'

FIX=buildrequires --add python3(%{MULTILINE_END_GROUP:1})

3.2.3 Параметр DESCRIPTION.

DESCRIPTION=В каких-то случаях сообщения об ошибках
DESCRIPTION=могут быть недостаточно информативными.
DESCRIPTION=В таких случаях хорошо бы составить описание
DESCRIPTION=ошибки для пользователя.
DESCRIPTION=
DESCRIPTION=Для этого просто добавим DESCRIPTION=
DESCRIPTION=перед каждой строкой.
DESCRIPTION=
DESCRIPTION=Исходное сообщение будет сохранено в файл
DESCRIPTION=00description в каталоге отчета.

3.2.4 Ключевое слово __END__

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

4. За пределами правил Логовед.

В некоторых случаях возможностей правил Логовед
может не хватить. В таком случае можно спуститься
на уровень ниже, в библиотеку Logoved-Stream.
Там можно зарегистрировать обработчик
(Listener) для указанного SCOPE=
с нужным кодом, что занимается
программным анализом поступающего потока.
в интерфейсе 4 метода:
write (<линия лог файла>)
commit () - вызывается после окончания данных
success() - когда секция завершилась успешно.
error() - когда секция завершилась неуспешно.

Успешной работы!


-- 

I V

Подробная информация о списке рассылки Devel