Linux: journalctl – примеры

By | 05/13/2017
 

Arch Linux на рабочей машине я установил>>> в декабре, на домашней – в марте>>>. Сейчас май – и мне первый раз понадобилось посмотреть системные логи, и то исключительно по причине установки драйверов NVIDIA.

В системах с systemd, таких как Arch Linux, управление логами выполняется демоном journald, а утилита его управления – journalctl.

systemd хранит логи в бинарном формате, что даёт возможность индексирования, более быстрой работы с ними, более удобного форматирования и т.д. Подробнее – тут>>>.

Кроме того для работы с логами – systemd предоставляет API-интерфейсы в файле sd-journal.h. Больше деталей – тут>>>.

Вывод логов по времени

Логи последней загрузки

По умолчанию, при вызове journalctl без опций – выведет все имеющиеся логи, при этом в логе между перезагрузками добавляется строка –Reboot–:

journalctl | grep -A 3 Reboot
Dec 22 14:40:10 localhost systemd[1]: Starting Reboot...
Dec 22 14:40:10 localhost systemd[1]: Shutting down.
Dec 22 14:40:10 localhost systemd[1]: Hardware watchdog 'iamt_wdt', version 1
Dec 22 14:40:10 localhost systemd[1]: Set hardware watchdog to 10min.
--
-- Reboot --
Dec 22 14:40:28 localhost systemd-journald[206]: Time spent on flushing to /var is 2.793ms for 0 entries.
Dec 22 14:40:28 localhost kernel: Linux version 4.8.13-1-ARCH (builduser@tobias) (gcc version 6.2.1 20160830 (GCC) ) #1 SMP PREEMPT Fri Dec 9 07:24:34 CET 2016
Dec 22 14:40:28 localhost kernel: Command line: BOOT_IMAGE=/vmlinuz-linux root=/dev/mapper/vg_arch-root rw quiet
--
Dec 26 11:13:55 localhost.localdomain systemd[1]: Starting Reboot...
Dec 26 11:13:55 localhost.localdomain systemd[1]: Shutting down.
Dec 26 11:13:55 localhost.localdomain systemd[1]: Hardware watchdog 'iTCO_wdt', version 0
Dec 26 11:13:55 localhost.localdomain systemd[1]: Set hardware watchdog to 10min.
--
-- Reboot --
...

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

journalctl -b
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 13:19:28 EEST. --
May 08 10:29:10 setevoy-arch-work systemd-journald[209]: Time spent on flushing to /var is 658us for 0 entries.
May 08 10:29:10 setevoy-arch-work kernel: Linux version 4.10.13-1-ARCH (builduser@tobias) (gcc version 6.3.1 20170306 (GCC) ) #1 SMP PREEMPT Thu Apr 27 12:15:09 CEST 2017
May 08 10:29:10 setevoy-arch-work kernel: Command line: BOOT_IMAGE=/vmlinuz-linux root=/dev/mapper/vg_arch-root rw quiet
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
May 08 10:29:10 setevoy-arch-work kernel: e820: BIOS-provided physical RAM map:
May 08 10:29:10 setevoy-arch-work kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009d7ff] usable
May 08 10:29:10 setevoy-arch-work kernel: BIOS-e820: [mem 0x000000000009d800-0x000000000009ffff] reserved
...

Предыдущие загрузки

По умолчанию journalctl в Arch уже настроен на хранение логов:

ls -l /var/log/journal/4ca5451acaf448638d3a076d1d903b97/
total 450664
-rw-r-----+ 1 root systemd-journal  8388608 Jan 13 18:05 system@000545fc020ef7dc-85683cff0564dfe0.journal~
...
-rw-r-----+ 1 root systemd-journal  8388608 May  5 18:14 user-1000@789c7a5cb406436fa6babc533024c6a2-000000000003742e-00054d08b015cdd0.journal
-rw-r-----+ 1 root systemd-journal  8388608 May  8 16:45 user-1000.journal

Если каталога нет и логов предыдущих загрузок нет – создаём каталог /var/log/journal, редактируем /etc/systemd/journald.conf, и указываем Storage=persistent.

Что бы просмотреть все прерыдущие загрузки системы – выполняем:

journalctl --list-boots
-25 875f0a15982846799932d4945d2bb2ff Thu 2016-12-22 14:36:14 EET—Thu 2016-12-22 14:40:10 EET
-24 7686218475c64db8ad527a3aa7a7fa27 Thu 2016-12-22 14:40:28 EET—Mon 2016-12-26 11:13:56 EET
...
-1 7091e72e78fa4d9b82b15920bcc67794 Wed 2017-05-03 11:51:08 EEST—Mon 2017-05-08 10:29:00 EEST
0 d16f9811579a434291c97bb071bdbfc2 Mon 2017-05-08 10:29:10 EEST—Sat 2017-05-13 13:30:00 EEST

А что бы вывести лог за определённую загрузку – указываем её смещение (первая колонка) или ID (вторая):

journalctl -b -1 | head -n 5
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 13:35:16 EEST. --
May 03 11:51:08 setevoy-arch-work systemd-journald[210]: Time spent on flushing to /var is 628us for 0 entries.
May 03 11:51:10 setevoy-arch-work kernel: Linux version 4.10.13-1-ARCH (builduser@tobias) (gcc version 6.3.1 20170306 (GCC) ) #1 SMP PREEMPT Thu Apr 27 12:15:09 CEST 2017
May 03 11:51:10 setevoy-arch-work kernel: Command line: BOOT_IMAGE=/vmlinuz-linux root=/dev/mapper/vg_arch-root rw quiet
May 03 11:51:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'

По ID:

journalctl -b 7091e72e78fa4d9b82b15920bcc67794 | head -n 5
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 13:35:16 EEST. --
May 03 11:51:08 setevoy-arch-work systemd-journald[210]: Time spent on flushing to /var is 628us for 0 entries.
May 03 11:51:10 setevoy-arch-work kernel: Linux version 4.10.13-1-ARCH (builduser@tobias) (gcc version 6.3.1 20170306 (GCC) ) #1 SMP PREEMPT Thu Apr 27 12:15:09 CEST 2017
May 03 11:51:10 setevoy-arch-work kernel: Command line: BOOT_IMAGE=/vmlinuz-linux root=/dev/mapper/vg_arch-root rw quiet
May 03 11:51:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'

Фильтрация по времени

Для фильтра по времени – journalctl предоставляет две опции – --since и --untill. Формат времени указывается в виде YYYY-MM-DD HH:MM:SS.

Кроме того – допустимо использование ключевых фильтров типа  “yesterday“, “today“, “tomorrow“:

journalctl --since yesterday
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 13:51:04 EEST. --
May 12 00:00:48 setevoy-arch-work systemd[1]: Started Verify integrity of password and group files.
May 12 00:00:48 setevoy-arch-work systemd[1]: Starting Rotate log files...
May 12 00:00:48 setevoy-arch-work systemd[1]: Starting Update man-db cache...
May 12 00:00:48 setevoy-arch-work systemd[1]: Started Rotate log files.
May 12 00:00:52 setevoy-arch-work mandb[23640]: Purging old database entries in /usr/share/man...
May 12 00:00:52 setevoy-arch-work mandb[23640]: Processing manual pages under /usr/share/man...
May 12 00:00:52 setevoy-arch-work mandb[23640]: Purging old database entries in /usr/share/man/fr.ISO8859-1...
...

Вывести логи за последние 10 минут можно так:

journalctl --since '-10min'
-- Logs begin at Thu 2017-04-13 12:09:14 EEST, end at Sat 2017-05-13 15:15:20 EEST. --
May 13 15:10:03 setevoy-arch-work NetworkManager[555]: <info>  [1494677403.6601] device (wlp3s0): set-hw-addr: set MAC address to BA:BE:3E:7B:58:04 (scanning)
May 13 15:10:03 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 15:10:03 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 15:10:03 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
May 13 15:10:03 setevoy-arch-work dhcpcd[824]: wlp3s0: new hardware address: ba:be:3e:7b:58:04

Либо скомпоновав с вызовом date():

date +%R
13:55
journalctl --since $(date +%R -d "10 mins ago")
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 13:51:04 EEST. --
May 13 13:45:47 setevoy-arch-work NetworkManager[555]: <info>  [1494672347.6517] device (wlp3s0): set-hw-addr: set MAC address to 82:EC:67:22:9E:7D (scanning)
May 13 13:45:47 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
...
May 13 13:51:04 setevoy-arch-work kernel: IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
May 13 13:51:04 setevoy-arch-work NetworkManager[555]: <info>  [1494672664.0698] device (wlp3s0): supplicant interface state: disconnected -> disabled
May 13 13:51:04 setevoy-arch-work NetworkManager[555]: <info>  [1494672664.1071] device (wlp3s0): supplicant interface state: disabled -> disconnected

Или – в промежуток между 12.00 и час тому (14.47):

journalctl --since 12:00 --until "1 hour ago"

Фильтрация по содержимому

Можно вывести информацию по определённому юниту, используя -u.

Например – находим systemd-юнит docker:

systemctl list-units --state=active | grep docker
sys-devices-virtual-net-docker0.device                                                      loaded active plugged   /sys/devices/virtual/net/docker0
sys-subsystem-net-devices-docker0.device                                                    loaded active plugged   /sys/subsystem/net/devices/docker0
var-lib-docker-devicemapper.mount                                                           loaded active mounted   /var/lib/docker/devicemapper
docker.service                                                                              loaded active running   Docker Application Container Engine
docker.socket                                                                               loaded active running   Docker Socket for the API

И проверяем только его логи:

journalctl -u docker.service
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:01:36 EEST. --
Dec 27 13:59:59 setevoywork systemd[1]: Starting Docker Application Container Engine...
Dec 27 13:59:59 setevoywork dockerd[25295]: time="2016-12-27T13:59:59.770705611+02:00" level=info msg="libcontainerd: new containerd process, pid: 25318"
Dec 27 14:00:00 setevoywork dockerd[25295]: time="2016-12-27T14:00:00.948692330+02:00" level=warning msg="devmapper: Usage of loopback devices is strongly discouraged for production use. Please use `--storage-opt dm.thinpooldev` or use `m
Dec 27 14:00:01 setevoywork dockerd[25295]: time="2016-12-27T14:00:01.193672119+02:00" level=info msg="devmapper: Creating filesystem xfs on device docker-254:0-156064-base"
...

Так же тут можно применять фильтры по времени:

journalctl -u docker.service --since today
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:08:00 EEST. --
May 13 14:07:54 setevoy-arch-work systemd[1]: Stopping Docker Application Container Engine...
May 13 14:07:54 setevoy-arch-work dockerd[826]: time="2017-05-13T14:07:54.323914025+03:00" level=info msg="Processing signal 'terminated'"
May 13 14:07:54 setevoy-arch-work dockerd[826]: time="2017-05-13T14:07:54.667003335+03:00" level=info msg="stopping containerd after receiving terminated"
May 13 14:07:55 setevoy-arch-work systemd[1]: Stopped Docker Application Container Engine.
May 13 14:07:55 setevoy-arch-work systemd[1]: Starting Docker Application Container Engine...
May 13 14:07:55 setevoy-arch-work dockerd[27117]: time="2017-05-13T14:07:55.778047142+03:00" level=info msg="libcontainerd: new containerd process, pid: 27132"
...

И проверять логи нескольких юнитов:

journalctl -u docker.service -u cronie.service
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:08:00 EEST. --
Dec 27 13:59:59 setevoywork systemd[1]: Starting Docker Application Container Engine...
Dec 27 13:59:59 setevoywork dockerd[25295]: time="2016-12-27T13:59:59.770705611+02:00" level=info msg="libcontainerd: new containerd process, pid: 25318"
...
Dec 27 14:00:02 setevoywork systemd[1]: Started Docker Application Container Engine.
Dec 27 14:43:14 setevoywork dockerd[25295]: time="2016-12-27T14:43:14.583320062+02:00" level=error msg="Handler for POST /v1.24/containers/create returned error: No such image: hello-world:latest"
Jan 05 10:28:43 setevoywork systemd[1]: Started Periodic Command Scheduler.
Jan 05 10:28:43 setevoywork crond[7995]: (CRON) INFO (Syslog will be used instead of sendmail.)
Jan 05 10:28:43 setevoywork crond[7995]: (CRON) INFO (RANDOM_DELAY will be scaled with factor 81% if used.)
...

Фильтр по пользователю, процесс или группе

Для фильтра по ID процесса – используем поле _PID:

pidof dockerd
27117
journalctl _PID=27117
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:12:08 EEST. --
May 13 14:07:55 setevoy-arch-work dockerd[27117]: time="2017-05-13T14:07:55.778047142+03:00" level=info msg="libcontainerd: new containerd process, pid: 27132"
May 13 14:07:57 setevoy-arch-work dockerd[27117]: time="2017-05-13T14:07:57.008988127+03:00" level=warning msg="devmapper: Usage of loopback devices is strongly discouraged for production use. Please use `--storage-opt dm.thinpooldev` or
...
May 13 14:08:00 setevoy-arch-work dockerd[27117]: time="2017-05-13T14:08:00.842490255+03:00" level=info msg="API listen on /var/run/docker.sock"

Либо:

journalctl _PID=$(pidof dockerd)

Аналогично – можно отфильтровать по группе пользователя – _GID:

id -g setevoy
1000
journalctl _GID=$(id -g setevoy)
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:17:24 EEST. --
Dec 22 14:40:45 localhost systemd[458]: Reached target Paths.
...
Dec 22 14:57:38 localhost sudo[2974]:  setevoy : TTY=pts/0 ; PWD=/home/setevoy/.config/openbox ; USER=root ; COMMAND=/usr/bin/pacman -S spectacle
Dec 22 14:57:44 localhost dbus-daemon[1234]: Reloaded configuration
Dec 22 14:57:45 localhost dbus-daemon[1234]: Reloaded configuration
Dec 22 14:57:45 localhost dbus-daemon[1234]: Reloaded configuration
Dec 22 14:59:01 localhost sudo[3191]:  setevoy : TTY=pts/0 ; PWD=/home/setevoy/.config/openbox ; USER=root ; COMMAND=/bin/bash
...

Или по самому UID пользователя:

journalctl _UID=$(id -u setevoy)
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:17:24 EEST. --
Dec 22 14:40:45 localhost systemd[458]: Reached target Paths.
Dec 22 14:40:45 localhost systemd[458]: Starting D-Bus User Message Bus Socket.
Dec 22 14:40:45 localhost systemd[458]: Reached target Timers.
Dec 22 14:40:45 localhost systemd[458]: Listening on D-Bus User Message Bus Socket.
Dec 22 14:40:45 localhost systemd[458]: Reached target Sockets.
Dec 22 14:40:45 localhost systemd[458]: Reached target Basic System.
Dec 22 14:40:45 localhost systemd[458]: Reached target Default.
Dec 22 14:40:45 localhost systemd[458]: Startup finished in 181ms.
Dec 22 14:46:23 localhost systemd[458]: Started D-Bus User Message Bus.
Dec 22 14:57:44 localhost dbus-daemon[1234]: Reloaded configuration
Dec 22 14:57:45 localhost dbus-daemon[1234]: Reloaded configuration
...

Подобных полей достаточно много, например – _TRANSPORT, _KERNEL_SUBSYSTEM, _KERNEL_SUBSYSTEM и т.д. См. systemd.journal-fields>>>.

Фильтр по компоненту

Достаточно передать интересующий исполняемый файл первым агрументом journalctl, что бы он вывел все записи по этому компоненту:

which dockerd
/usr/bin/dockerd
journalctl $(which dockerd)
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:22:40 EEST. --
Dec 27 13:59:59 setevoywork dockerd[25295]: time="2016-12-27T13:59:59.770705611+02:00" level=info msg="libcontainerd: new containerd process, pid: 25318"
Dec 27 14:00:00 setevoywork dockerd[25295]: time="2016-12-27T14:00:00.948692330+02:00" level=warning msg="devmapper: Usage of loopback devices is strongly discouraged for production use. Please use `--storage-opt dm.thinpooldev` or use `m
Dec 27 14:00:01 setevoywork dockerd[25295]: time="2016-12-27T14:00:01.193672119+02:00" level=info msg="devmapper: Creating filesystem xfs on device docker-254:0-156064-base"
Dec 27 14:00:01 setevoywork dockerd[25295]: time="2016-12-27T14:00:01.527633726+02:00" level=info msg="devmapper: Successfully created filesystem xfs on device docker-254:0-156064-base"
Dec 27 14:00:01 setevoywork dockerd[25295]: time="2016-12-27T14:00:01.854526788+02:00" level=info msg="Graph migration to content-addressability took 0.00 seconds"

И снова – применяем любые фильтры:

journalctl $(which dockerd) -b -1
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:25:27 EEST. --
May 03 11:51:34 setevoy-arch-work dockerd[865]: time="2017-05-03T11:51:34.121145923+03:00" level=info msg="libcontainerd: new containerd process, pid: 894"
May 03 11:51:37 setevoy-arch-work dockerd[865]: time="2017-05-03T11:51:37.578933933+03:00" level=warning msg="devmapper: Usage of loopback devices is strongly discouraged for production use. Please use `--storage-opt dm.thinpooldev` or us
May 03 11:51:37 setevoy-arch-work dockerd[865]: time="2017-05-03T11:51:37.678789135+03:00" level=warning msg="devmapper: Base device already exists and has filesystem xfs on it. User specified filesystem  will be ignored."
May 03 11:51:37 setevoy-arch-work dockerd[865]: time="2017-05-03T11:51:37.723546512+03:00" level=info msg="[graphdriver] using prior storage driver: devicemapper"
...

dmesg

Что бы получить записи от ядра – используйте -k или --dmesg:

journalctl --dmesg
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:25:27 EEST. --
May 08 10:29:10 setevoy-arch-work kernel: Linux version 4.10.13-1-ARCH (builduser@tobias) (gcc version 6.3.1 20170306 (GCC) ) #1 SMP PREEMPT Thu Apr 27 12:15:09 CEST 2017
May 08 10:29:10 setevoy-arch-work kernel: Command line: BOOT_IMAGE=/vmlinuz-linux root=/dev/mapper/vg_arch-root rw quiet
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
May 08 10:29:10 setevoy-arch-work kernel: x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' fo
...

Фильтр по уровню важности

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

journalctl -p err
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:27:56 EEST. --
Dec 22 14:36:16 localhost kernel: nouveau 0000:01:00.0: DRM: Pointer to TMDS table invalid
Dec 22 14:36:16 localhost kernel: nouveau 0000:01:00.0: DRM: Pointer to flat panel table invalid
Dec 22 14:40:09 localhost login[475]: pam_systemd(login:session): Failed to release session: Connection reset by peer
Dec 22 14:40:09 localhost lvmetad[312]: Failed to accept connection errno 11.
-- Reboot --
Dec 22 14:40:30 localhost kernel: nouveau 0000:01:00.0: DRM: Pointer to TMDS table invalid
Dec 22 14:40:30 localhost kernel: nouveau 0000:01:00.0: DRM: Pointer to flat panel table invalid
Dec 22 16:15:04 localhost systemd-coredump[23078]: Process 23011 (xneur) of user 1000 dumped core.
Stack trace of thread 23011:
0  0x00007f56c95e826b malloc_consolidate (libc.so.6)
1  0x00007f56c95e9d2a _int_malloc (libc.so.6)
2  0x00007f56c95ebd44 malloc (libc.so.6)
...

Допустимые значения уровня:

0: emerg
1: alert
2: crit
3: err
4: warning
5: notice
6: info
7: debug

Опять-таки – применяем любые фильтры, например – все ERROR за последний час:

journalctl -p err --since='-1h'
-- No entries --

Или все DEBUG, используя номер:

journalctl -p 7 --since='-1h'
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:29:28 EEST. --
May 13 13:35:15 setevoy-arch-work dhcpcd[824]: wlp3s0: new hardware address: 7a:3e:3d:ec:47:1a
May 13 13:35:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 13:35:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 13:35:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
May 13 13:35:15 setevoy-arch-work NetworkManager[555]: <info>  [1494671715.6739] device (wlp3s0): set-hw-addr: s
...

Форматирование вывода

Вывод в STDOUT

По умолчанию – journalctl выводит данные в просмотрщик по умолчанию (pager>>>).

Что бы вывести данные прямо в STDOUT – используем --no-pager:

journalctl --no-pager --since='-1h' -p info
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:33:12 EEST. --
May 13 13:40:31 setevoy-arch-work dhcpcd[824]: wlp3s0: new hardware address: 16:d0:53:2f:2c:18
May 13 13:40:31 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 13:40:31 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 13:40:31 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
May 13 13:40:31 setevoy-arch-work NetworkManager[555]: <info>  [1494672031.6481] device (wlp3s0): set-hw-addr: set MAC address to 16:D0:53:2F:2C:18 (scanning)
May 13 13:40:31 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 13:40:31 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
...

Форматы вывода

Для форматирования вывода – используем опцию -o.

Например – вывести в json:

journalctl --no-pager --since='-1h' -p info -o json
{ "__CURSOR" : "s=691e8ae367cb4b528aa95f75b57b86ba;i=53409;b=d16f9811579a434291c97bb071bdbfc2;m=6741e32890;t=54f6573808965;x=15dad728f680a50c", "__REALTIME_TIMESTAMP" : "1494672031648101", "__MONOTONIC_TIMESTAMP" : "443487037584", "_BOOT_ID" : "d16f9811579a434291c97bb071bdbfc2", "PRIORITY" : "6", "_UID" : "0", "_GID" : "0", "_MACHINE_ID" : "4ca5451acaf448638d3a076d1d903b97", "_HOSTNAME" : "setevoy-arch-work", "_TRANSPORT" : "syslog", "SYSLOG_FACILITY" : "3", "SYSLOG_IDENTIFIER" : "dhcpcd", "_COMM" : "dhcpcd", "_EXE" : "/usr/bin/dhcpcd", "_CMDLINE" : "dhcpcd -4 -q -t 30 -L enp0s25", "_CAP_EFFECTIVE" : "3fffffffff", "_SYSTEMD_CGROUP" : "/system.slice/system-netctl.slice/netctl@enp0s25.service", "_SYSTEMD_UNIT" : "netctl@enp0s25.service", "_SYSTEMD_SLICE" : "system-netctl.slice", "_SYSTEMD_INVOCATION_ID" : "c556a8ceca284169b134df15f8d2a030", "SYSLOG_PID" : "824", "_PID" : "824", "MESSAGE" : "wlp3s0: new hardware address: 16:d0:53:2f:2c:18", "_SOURCE_REALTIME_TIMESTAMP" : "1494672031648087" }
{ "__CURSOR" : "s=691e8ae367cb4b528aa95f75b57b86ba;i=5340a;b=d16f9811579a434291c97bb071bdbfc2;m=6741e4085d;t=54f6573816933;x=5cbc688470b51d31", "__REALTIME_TIMESTAMP" : "1494672031705395", "__MONOTONIC_TIMESTAMP" : "443487094877", "_BOOT_ID" : "d16f9811579a434291c97bb071bdbfc2", "PRIORITY" : "6", "_MACHINE_ID" : "4ca5451acaf448638d3a076d1d903b97", "_HOSTNAME" : "setevoy-arch-work", "_KERNEL_SUBSYSTEM" : "pci", "_KERNEL_DEVICE" : "+pci:0000:03:00.0", "_UDEV_SYSNAME" : "0000:03:00.0", "_TRANSPORT" : "kernel", "SYSLOG_FACILITY" : "0", "SYSLOG_IDENTIFIER" : "kernel", "MESSAGE" : "iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled", "_SOURCE_MONOTONIC_TIMESTAMP" : "443485576187" }
...

Или более приятный формат – json-pretty:

journalctl --no-pager --since='-10m' -o json-pretty | jq

Допустимые форматы:

  • cat: только поле сообщения
  • export: экспорт в бинарном формате для передачи или бекапирования
  • json: стандартный JSON с одной записью в строке
  • json-pretty: форматированный JSON
  • json-sse: JSON в формате Server Sent Events (SSE)
  • short: стандартный формат syslog
  • short-iso: аналогично, но дата и время в формате ISO 8601
  • verbose: подробный режим – выводить все данные лога

Логи активных процессов

Последние записи

journalctl может использоваться с опцией -n, по аналогии со знакомой всем утилитой tail для вывода последних записей:

journalctl -n
-- Logs begin at Thu 2016-12-22 14:36:14 EET, end at Sat 2017-05-13 14:54:16 EEST. --
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
May 13 14:54:15 setevoy-arch-work NetworkManager[555]: <info>  [1494676455.6425] device (wlp3s0): set-hw-addr: set MAC address to 62:C0:8B:DC:0D:AB (scanning)
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
May 13 14:54:16 setevoy-arch-work kernel: IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready
May 13 14:54:16 setevoy-arch-work NetworkManager[555]: <info>  [1494676456.0367] device (wlp3s0): supplicant interface state: disconnected -> disabled
May 13 14:54:16 setevoy-arch-work NetworkManager[555]: <info>  [1494676456.0563] device (wlp3s0): supplicant interface state: disabled -> disconnected

По умолчанию выводится 10 строк, можно указать желаемое кол-во:

journalctl -n 100

Слежение за логом

Аналогично -f в tail – используем для journalctl, что бы выводить лог постоянно:

journalctl -f
-- Logs begin at Thu 2016-12-22 14:36:14 EET. --
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
May 13 14:54:15 setevoy-arch-work NetworkManager[555]: <info>  [1494676455.6425] device (wlp3s0): set-hw-addr: set MAC address to 62:C0:8B:DC:0D:AB (scanning)
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
May 13 14:54:15 setevoy-arch-work kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
May 13 14:54:16 setevoy-arch-work kernel: IPv6: ADDRCONF(NETDEV_UP): wlp3s0: link is not ready

Как и прежде – применяем любые фильтры:

journalctl $(which dockerd) -f -o json
{ "__CURSOR" : "s=691e8ae367cb4b528aa95f75b57b86ba;i=5345a;b=d16f9811579a434291c97bb071bdbfc2;m=67a3f75d85;t=54f65d594be5a;x=b3326a8c66710996", "__REALTIME_TIMESTAMP" : "1494673677139546", "__MONOTONIC_TIMESTAMP" : "445132529029", "_BOOT_ID" : "d16f9811579a434291c97bb071bdbfc2", "PRIORITY" : "6", "_UID" : "0", "_GID" : "0", "_SYSTEMD_SLICE" : "system.slice", "_MACHINE_ID" : "4ca5451acaf448638d3a076d1d903b97", "_HOSTNAME" : "setevoy-arch-work", "SYSLOG_FACILITY" : "3", "_CAP_EFFECTIVE" : "3fffffffff", "_TRANSPORT" : "stdout", "SYSLOG_IDENTIFIER" : "dockerd", "_COMM" : "dockerd", "_EXE" : "/usr/bin/dockerd", "_CMDLINE" : "/usr/bin/dockerd -H fd://", "_SYSTEMD_CGROUP" : "/system.slice/docker.service", "_SYSTEMD_UNIT" : "docker.service", "_PID" : "27117", "_SYSTEMD_INVOCATION_ID" : "c6b1d8740b7e47558e6797ef4e0a1589", "MESSAGE" : "time=\"2017-05-13T14:07:57.139509216+03:00\" level=info msg=\"[graphdriver] using prior storage driver: devicemapper\"" }
...

Обслуживаение логов

Занимаемое место

Занимаемое логами дисковое простратнство можно получить с помощью опции --disk-usage:

journalctl --disk-usage
Archived and active journals take up 440.1M in the file system.

Проверяем:

du -sh /var/log/journal/
441M    /var/log/journal/

Удаление логов

Для уменьшения хранимых логов можно использовать либо --vacuum-size, либо --vacuum-time.

Первая указывает желаемое место, вторая – время.

Например, что бы уменьшить занятое место до 200 мб:

sudo journalctl --vacuum-size=200M
Deleted archived journal /var/log/journal/4ca5451acaf448638d3a076d1d903b97/user-1000@789c7a5cb406436fa6babc533024c6a2-0000000000012262-000547d97dbda772.journal (8.0M).
Deleted archived journal /var/log/journal/4ca5451acaf448638d3a076d1d903b97/system@5ba784db13c14692991cfac0d439f0cf-0000000000019899-0005487cf5af84bb.journal (8.0M).
...
Deleted archived journal /var/log/journal/4ca5451acaf448638d3a076d1d903b97/system@5e9c4e0252d9450d96874d1ff7ac8f23-000000000002074b-00054a1f8a703888.journal (8.0M).
Deleted archived journal /var/log/journal/4ca5451acaf448638d3a076d1d903b97/system@00054c3e2e681fae-9524e790e4cdd0b4.journal~ (48.0M).
Vacuuming done, freed 128.0M of archived journals from /var/log/journal/4ca5451acaf448638d3a076d1d903b97.

Проверяем:

du -sh /var/log/journal/
201M    /var/log/journal/

Либо – оставить логи только за последний месяц работы:

sudo journalctl --vacuum-time=1month
Deleted archived journal /var/log/journal/4ca5451acaf448638d3a076d1d903b97/user-1000@789c7a5cb406436fa6babc533024c6a2-0000000000021e29-00054a9846dc7ef6.journal (24.0M).
Deleted archived journal /var/log/journal/4ca5451acaf448638d3a076d1d903b97/system@00054d08adc18ae6-8b9e5f18861801a9.journal~ (48.0M).
Vacuuming done, freed 72.0M of archived journals from /var/log/journal/4ca5451acaf448638d3a076d1d903b97.

Ограничение размеров логов

Можно задать лимиты в файле настроек journalctl/etc/systemd/journald.conf:

  • SystemMaxUse: максимально допустимый объём занятого места на диске
  • SystemKeepFree: указывает размер места, которое должно оставаться свободным
  • SystemMaxFileSize: максимальный размер одного файла журнала

В целом – на этом всё.

man journald.conf

How To Use Journalctl to View and Manipulate Systemd Logs

И две замечательные серии постов от Lennart Poettering о systemd и его журнале:

  1. systemd for Developers I
  2. systemd for Developers II
  3. systemd for Developers III

Вторая серия больше – 13 постов, начало – systemd for Administrators, Part 1.