Настройка логирования вывода скриптов Bash

Настройка логирования вывода скриптов Bash

Приветствую!

Многие пользователи Linux🐧 систем сталкиваются с необходимостью записать вывод той или иной команды/скрипта в файл-журнал📑.

Цели тут могут быть разные: сохранение истории действий, поиск и устранение ошибок, мониторинг процессов и т.д🧑‍💻.

В этой заметке мы рассмотрим несколько способов настройки журналирования (оно же логирование) в Linux на примере популярной командной оболочкиBash.

Подписывайтесь на наш телеграм @r4ven_me📱, чтобы не пропустить новые публикации на сайте😉. А если есть вопросы или желание пообщаться по тематике – заглядывайте в Вороний чат @r4ven_me_chat🧐.

Предисловие

Решая одну задачу с помощью сценария Bash во время традиционной настройки логирования, вспомнил о возможности задать файл лога прямо внутри самого скрипта🤔. Далее об этих способах (и не только) расскажу подробнее😉.

Примеры из статьи подразумевают ваше понимание механизма управления стандартными потоками командной оболочки. Поэтому, если вы не знаете, что это за механизм — рекомендую ознакомиться с моей предыдущей статьей: Перенаправление ввода и вывода: операторы “>”, “<“, “|”, чтобы лучше понимать дальнейший контекст🙂.

Подготовка

Условно у нас есть Bash скрипт с названием script.sh:

nvim ./script.sh
#!/bin/bash

ls -l /

ls -l /wrong_path

Давайте сделаем его исполняемым и попробуем запустить:

chmod +x script.sh

./script.sh

Команда chmod +x script.sh добавляет флаг выполнения файлу, что его можно было запускать, как программу. Подробнее про такие флаги смотрите тут.

Скрипт выведет состав корневой директории:

итого 945516
drwxr-xr-x   2 root root      4096 фев  3 19:54 backup
lrwxrwxrwx   1 root root         7 фев 16  2022 bin -> usr/bin
drwxr-xr-x   2 root root      4096 авг 13  2024 bin.usr-is-merged
drwxr-xr-x   4 root root      4096 дек 18 13:36 boot
drwxr-xr-x   2 root root      4096 фев 16  2022 cdrom
drwxr-xr-x  20 root root      4140 мар 10 15:08 dev
drwxr-xr-x 171 root root     12288 фев 15 00:13 etc
drwxr-xr-x   4 root root      4096 мая 12  2024 home
lrwxrwxrwx   1 root root         7 фев 16  2022 lib -> usr/lib
lrwxrwxrwx   1 root root         9 фев 16  2022 lib32 -> usr/lib32
lrwxrwxrwx   1 root root         9 фев 16  2022 lib64 -> usr/lib64
drwxr-xr-x   2 root root      4096 ноя  8 09:50 lib.usr-is-merged
lrwxrwxrwx   1 root root        10 фев 16  2022 libx32 -> usr/libx32
drwx------   2 root root     16384 фев 16  2022 lost+found
drwxr-xr-x   3 root root      4096 янв 22  2023 media
drwxr-xr-x   4 root root      4096 июн 13  2023 mnt
drwxr-xr-x   6 root root      4096 авг 12  2024 opt
dr-xr-xr-x 315 root root         0 мар 10 15:07 proc
drwx------  12 root root      4096 фев 25 22:32 root
drwxr-xr-x  40 root root      1080 мар 10 15:48 run
lrwxrwxrwx   1 root root         8 фев 16  2022 sbin -> usr/sbin
drwxr-xr-x   2 root root      4096 авг 22  2024 sbin.usr-is-merged
drwxr-xr-x   2 root root      4096 янв  4  2022 srv
-rw-------   1 root root 968110080 фев 16  2022 swapfile
dr-xr-xr-x  13 root root         0 мар 10 15:59 sys
drwxr-xr-x   2 root root      4096 июн  4  2022 timeshift
drwxrwxrwt  18 root root      4096 мар 10 15:58 tmp
drwxr-xr-x  14 root root      4096 янв  4  2022 usr
drwxr-xr-x  11 root root      4096 авг  6  2024 var

И также ошибку:

ls: невозможно получить доступ к '/wrong_path': Нет такого файла или каталога

В первом случае команда вывела информацию в стандартный вывод (stdout), а вторая в стандартный вывод ошибок (stderr). Теперь давайте настроим логирование вывода этих двух потоков.

Настройка логирования во время запуска команды

Запись вывода скрипта можно настроить общепринятым способом: перенапрвлением при его запуске. Например:

./script.sh > script.log 2>&1

# альтернативный вариант (для bash)
./script.sh &> script.log

В этот раз вывод скрипт пустой. Все потому, что конструкция > script.log перенаправила стандартный вывод скрипта в указанный файл (в нашем случае script.log), а 2>&1 — перенаправила вывода ошибок в первый дескриптор, которым является стандартный вывод, который в свою очередь записал все в файл.

Напомню про номера дескрипторов:
0 – стандартный ввод (stdin)
1 – стандартный вывод (stdout)
2 – стандартный вывод ошибок (stderr)

Альтернативная конструкция &> выполняет тоже самое, что и 2>&1 только выглядит более лаконично. А еще она не поддерживается в ванильной оболочке Shell (sh). Поэтому в дань уважения и для наглядности далее будем использовать конструкцию 2>&1.

При необходимости разделить потоки в разные файлы используйте такой формат:

./script.sh > script.log 2> script_error.log

Тут мы явно указали, куда направлять поток 2-го дескриптора (stderr).

Оператор > при каждом новом запуске скрипта будет перезаписывать целевой файл. Если необходимо дополнять лог файл — используйте оператор >>.

С первым и самым распространенным способом более-менее понятно. Но Linux не был собой, если бы не имел других способов решения одной и той же задачи🐧.

Настройка логирования в самом скрипте

Настроить логирование всего вывода скрипта можно непосредственно внутри него с помощью вот таких конструкций:

# запись только stdout
exec > script.log

# запись stderr в тот же файл
exec > script.log 2>&1

# запись stderr в отдельный файл
exec > script.log 2> error.log

exec — это встроенная команда оболочки, которая выполняет замену текущего процесса на другой, переданный ей в качестве аргумента. Но в данном случае аргумента нет и поэтом она заменяет текущий процесс самим скриптом. Но т.к. в команде exec > script.log осуществляется перенаправление потока, вывод всего скирпта отправляется в указанный файл🤯.

Пример нашего скрипта с применением этой конструкции может выглядеть так:

⚠️Важно добавлять конструкцию перенаправления до команд, вывод которых необходимо логировать.

#!/bin/bash

exec > script.log 2>&1

ls -l /

ls -l /wrong_path

В таком случае, при запуске:

./script.sh

Его поведение будет аналогично предыдущему варианту запуска:

./script.sh > script.log 2>&1

Вроде все понятно и просто. Но разберем пару очевидных нюансов и доработаем нашу конструкцию.

Нюанс №1: в примере выше вывод будет записан в файл, но не выведется в консоль. И на такой случай есть решение, в виде конструкции подстановки процесса (работает только в современных оболочках, таких как Bash):

exec > >(tee script.log) 2>&1

Т.к. механизм перенаправления с помощью оператора > подразумевает запись в файл, то конструкция >(command) создает виртуальный файл (дескриптор) с содержимым вывода скрипта, которое передается на в ввод указанной внутри конструкции команде. В нашем случае – это команда дублирования stdout и в консоль и в файл — tee (дословно “тройник”, “т-образный”).

При использовании tee с ключом -a (append) вывод будет добавляться в файл, а не перезаписываться после каждого запуска скрипта.

Визуально работу tee с потоками можно представить по букве T:

stdout — T — file
         |
       stdout

К слову, существует и конструкция подстановки команды для ввода ИЗ файла, принцип тот же самый, но порядок обратный: вывод команды подстановки в виртуальный файл и далее в команду-получателя. Выглядит так:
< <(command)

Нюанс №2: лог файл создаться в директории, откуда был запущен скрипт, что не всегда удобно.
Давайте доработаем, указав вместо имени файла лога – переменную $0, которая содержит имя запускаемой команды. В нашем случае это относительный путь и имя исполняемого файла.
В итоге скрипт может выглядеть так:

#!/bin/bash

exec > >(tee "${0}".log) 2>&1

ls /

ls wrong_path

У переменной $0 есть свои особенности, когда скрипт с ее использованием вызывается из другого скрипта. В таких случаях рекомендуется использовать служебную ${BASH_SOURCE[0]} вместо $0, разумеется если оболочка – Bash.

В результате своей работы скрипт напишет свой вывод, как обычно в консоль и параллельно в файл с именем скрипта и суффиксом .log, который создаться в директории, где находится сам скрипт, а не откуда он был запущен.
При такой конструкции тоже есть особенность: если скрипт называется script.sh то лог файл получит имя script.sh.log. Что вроде бы не страшно, но нравится не всем (в т.ч. мне).

Убрать расширение (все символы после точки) можно модернизировав переменную используя возможности синтаксиса Bash:

#!/bin/bash

exec > >(tee "${0%.*}".log) 2>&1

ls -l /

ls -l /wrong_path

Ну вот, теперь, если скрипт будет запущен, например так:

/opt/bin/script.sh

Он напишет свой вывод в консоль и в файл /opt/bin/script.log.

Казалось бы одна короткая строчка, а сколько нюансов возможностей🤯

Логирование в системный журнал

Помимо записи вывода в файл, его также можно перенаправить в системный журнал (он же Syslog или Journald).

Про то, что это такое мы говорил в одной из прошлых теоретических заметок. Рассчитывая на ваше понимание данной сущности Linux систем давайте рассмотрим, как можно направить потоки вывода скрипта в этот журнал.

Традиционным способом отправки данных в системный лог является утилита logger. В дальнейших командах с этой утилитой мы будем использовать два ключа:

  • -t (--tag) — указание метки записи для будущей фильтрации
  • -p (--priority) — указание категории (facility) и приоритета (severity) записи

Если предпочитаете нативный способ передачи данных в Journald, воспользуйтесь командой systemd-cat:

echo "Тестовое сообщение" | systemd-cat

Во время запуска команды

И так. Перенаправление вывода с помощью logger во время запуска команды выглядит следующим образом:

Подразумевается, что команда перенаправления в самом скрипте отсутствует или закомментирована.

./script.sh | logger -t test -p local0.info

Где:

  • test — это произвольная метка записи
  • local0 — пользовательская категория (от local0 до local7)
  • info — важность

Полный список категорий и уровней важности смотрите тут.

В примере выше в системный журнал не падает вывод ошибок. Исправим:

./script.sh 2>&1 | logger -t test -p local0.info

Смотреть записи в системном журнале можно с помощью утилиты journalctl в случае Journald и cat|less|grep и др. в случае обычных файлов Syslog:

# если используется journald
journalctl --no-pager -t "test"

journalctl --no-pager --facility=local0 --priority=info -t "test"

# если используется syslog (debian/ubuntu)
grep "test" /var/log/syslog

Ключ --no-pager отключает постраничный режим просмотра, как в less.

Если нужно отправлять вывод и в файл и в системный журнал, то вспоминаем про механизм подстановки процесса:

./script.sh > >(tee -a ./script.log | logger -t test -p local0.info) 2>&1

Ну а если нужно разделять стандартный вывод и вывод ошибок по категориям и в разные файлы, то можно сделать так:

./script.sh > >(tee -a ./script.log | logger -t test -p local0.info) 2> >(tee -a ./script_error.log | logger -t test -p local0.err)

Смотрим категорию info:

journalctl --no-pager --facility=local0 --priority=info -t "test"

Или ошибки отдельно:

journalctl --no-pager --facility=local0 --priority=err -t "test"

Как видно, уровень важности err подсвечивается красным.

В самом скрипте

Аналогичным образом можно настроить отправку вывода скрипта в системный журнал внутри самого скрипта:

# Перенаправление stdout в logger с тегом "test" и приоритетом local0.info
exec > >(logger -t test -p local0.info)

# Перенаправление stdout и stderr в logger с тегом "test" и приоритетом local0.info
exec > >(logger -t test -p local0.info) 2>&1

# Перенаправление stdout в файл и в logger, stderr также перенаправляется в stdout
exec > >(tee -a "${0%.*}".log | logger -t test -p local0.info) 2>&1

# Перенаправление stdout в файл и в logger, stderr в отдельный файл и в logger с другим приоритетом
exec > >(tee -a "${0%.*}".log | logger -t test -p local0.info) 2> >(tee -a "${0%.*}"_error.log | logger -t test -p local0.err)

Последний вариант слишком длинный для одной строки. Оформим его чуть компактнее:

exec \
    > >(tee -a "${0%.*}".log | logger -t test16 -p local3.info) \
    2> >(tee -a "${0%.*}"_error.log | logger -t test16 -p local3.err)

Ну и напоследок интересный и наверное более применимый на практике вариант логирования. Что он делает:

  • отправляет stdout+stderr в системный журнал с тегом в виде имени скрипта, например script.sh
  • отправляет stdout+stderr в файл <имя_скрипта>.log в директории, откуда был запущен скрипт
    • к каждой логируемой строке в файле добавляет префикс в формате: год-месяц-день часы:минуты:секунды.3милисек
  • отправляет весь вывод скрипта в консоль.
exec > >(
    tee >(logger -t "$(basename "${BASH_SOURCE[0]}")") |
    while IFS= read -r line; do
        echo "$(date +"[%Y-%m-%d %H:%M:%S.%3N]") - $line"
    done |
    tee -a "${BASH_SOURCE[0]%.*}.log"
) 2>&1

⚠️Обратите внимание, что вместо $0 тут используется специфичная переменная Bash: ${BASH_SOURCE[0]}, которую упоминал ранее.

Послесловие

Сегодня мы с вами разобрали такую важную и базовую часть командной строки, как логирование вывода. Возможно с первого раза трудно уяснить в голове все эти “перенаправления” и непростой синтаксис Bash. Но понимание, как и с многими другими вещами, приходит с практикой. Попробуйте применить рассмотренные сегодня конструкции в своих скриптах.

Спасибо, что читаете😌 Не забывайте про нашу телегу📱и чат 💬 там же!


Всех благ!

Подписаться
Уведомить о
0 комментариев
Старые
Новые Популярные
Межтекстовые Отзывы
Посмотреть все комментарии