koh’s blog

Sys Admin who loves automation

今更ながらjournalctlが便利

journald linux

For English
何故か食わず嫌いしていたjournalctlですが、使ってみたら結構便利だったので使い方まとめ。

そもそもjournalctlとは

man journalctl によると

NAME
       journalctl - Query the systemd journal

SYNOPSIS
       journalctl [OPTIONS...] [MATCHES...]

DESCRIPTION
       journalctl may be used to query the contents of the systemd(1) journal as written by
       systemd-journald.service(8).

systemd-journaldによって書かれたjournalを読み込むのに使われるとのこと。
じゃあjournaldは何かということで man systemd-journaldをみる。

DESCRIPTION
       systemd-journald is a system service that collects and stores logging data. It creates and
       maintains structured, indexed journals based on logging information that is received from a
       variety of sources:

ざっくりいうといろんなログを集めて整理して管理しますよってことです。
ここで言ういろんなログはこちら。よく見るログはだいたい網羅されてますね。

  • Kernel log messages, via kmsg
  • Simple system log messages, via the libc syslog(3) call
  • Structured system log messages via the native Journal API, see sd_journal_print(3)
  • Standard output and standard error of service units. For further details see below.
  • Audit records, originating from the kernel audit subsystem

journalctlを使ってみる

それでは実際に見てみましょう。
環境はVagrant上のCentOS 7.5.1804

素でコマンドを発行すると上記のログがすべて表示されます。
時間軸は上が古いものになり、lessのようなページャで表示されます。

% sudo journalctl

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST, end at Sat 2019-04-13 14:26:56 JST. --
Apr 13 14:05:21 localhost.localdomain systemd-journal[84]: Runtime journal is using 6.1M (max allowed 49.5M, trying to leave 74.3M free of 489.6M available <E2><86><92> current limit 49.5M).
Apr 13 14:05:21 localhost.localdomain kernel: Initializing cgroup subsys cpuset
Apr 13 14:05:21 localhost.localdomain kernel: Initializing cgroup subsys cpu
<省略>
Apr 13 14:20:01 Vag2 systemd[1]: Stopping User Slice of root.
Apr 13 14:20:32 Vag2 systemd[1]: Starting Cleanup of Temporary Directories...
Apr 13 14:20:32 Vag2 systemd[1]: Started Cleanup of Temporary Directories.
Apr 13 14:23:18 Vag2 sudo[2428]:  vagrant : TTY=pts/0 ; PWD=/home/vagrant ; USER=root ; COMMAND=/bin/journalctl

毎回すべてのログが表示されると見づらいので、オプションで絞り込むようなイメージです。
ではいくつか主要なオプションを紹介します。

カーネルメッセージ

-kでカーネルメッセージが見られます。dmesgと同じです。

% sudo journalctl -k

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST, end at Sat 2019-04-13 14:34:48 JST. --
Apr 13 14:05:21 localhost.localdomain kernel: Initializing cgroup subsys cpuset
Apr 13 14:05:21 localhost.localdomain kernel: Initializing cgroup subsys cpu
Apr 13 14:05:21 localhost.localdomain kernel: Initializing cgroup subsys cpuacct
Apr 13 14:05:21 localhost.localdomain kernel: Linux version 3.10.0-862.11.6.el7.x86_64 (builder@kbuilder.dev.centos.org) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-28) (GCC) ) #1 SMP Tue Aug 14 21:49:04 UTC 2018
Apr 13 14:05:21 localhost.localdomain kernel: Command line: BOOT_IMAGE=/vmlinuz-3.10.0-862.11.6.el7.x86_64 root=/dev/mapper/centos-root ro net.ifnames=0 biosdevname=0 crashkernel=auto rd.lvm.lv=centos/root rd.lvm.lv=centos/swap rhgb quiet LANG=en_US.UTF-8

特定ユニット

-uで特定のユニットのログを確認できます。
haproxyの場合以下のような感じです。

% sudo journalctl -u haproxy

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST, end at Sat 2019-04-13 15:00:48 JST. --
Apr 13 14:05:31 Vag2 systemd[1]: Started HAProxy Load Balancer.
Apr 13 14:05:31 Vag2 systemd[1]: Starting HAProxy Load Balancer...
Apr 13 14:05:31 Vag2 haproxy-systemd-wrapper[1019]: haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -Ds
Apr 13 15:00:45 Vag2 systemd[1]: Reloaded HAProxy Load Balancer.
Apr 13 15:00:45 Vag2 haproxy-systemd-wrapper[1019]: haproxy-systemd-wrapper: re-executing on SIGUSR2.
Apr 13 15:00:45 Vag2 haproxy-systemd-wrapper[1019]: haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -Ds -sf 1036

ログレベル

-pでログの重要度を指定できます。 指定するには下記の一覧の数字 or 文字列で指定します。

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

% sudo journalctl -p err

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST, end at Sat 2019-04-13 14:48:50 JST. --
Apr 13 14:05:31 Vag2 systemd[1]: Failed to start Crash recovery kernel arming.

複数指定もできます。

% sudo journalctl -p err -p warning

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST, end at Sat 2019-04-13 14:49:58 JST. --
<省略>
Apr 13 05:05:29 Vag2 kernel: 00:00:00.000268 main     Executable: /opt/VBoxGuestAdditions-5.2.18/sbin/VBoxService
                             00:00:00.000268 main     Process ID: 906
                             00:00:00.000269 main     Package type: LINUX_64BITS_GENERIC
Apr 13 05:05:29 Vag2 kernel: 00:00:00.003419 main     5.2.18 r124319 started. Verbose level = 0
Apr 13 14:05:31 Vag2 chronyd[647]: Forward time jump detected!
Apr 13 14:05:31 Vag2 systemd[1]: Failed to start Crash recovery kernel arming.
Apr 13 14:05:31 Vag2 systemd[1]: kdump.service failed.
Apr 13 14:05:41 Vag2 kernel: 00:00:10.017183 timesync vgsvcTimeSyncWorker: Radical guest time change: 32 411 887 294 000ns (GuestNow=1 555 131 941 050 133 000 ns GuestLast=1

表示方法変更系

journalctlの出力の仕方を変えるオプションもいくつかご紹介

逆順

-rで新しいログを上に表示

% sudo journalctl -r

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST, end at Sat 2019-04-13 14:56:44 JST. --
Apr 13 14:56:44 Vag2 sudo[2609]:  vagrant : TTY=pts/0 ; PWD=/home/vagrant ; USER=root ; COMMAND=/bin/journalctl -r
Apr 13 14:56:24 Vag2 sudo[2605]:  vagrant : TTY=pts/0 ; PWD=/home/vagrant ; USER=root ; COMMAND=/bin/journalctl -r
Apr 13 14:50:01 Vag2 systemd[1]: Stopping User Slice of root.
Apr 13 14:50:01 Vag2 systemd[1]: Removed slice User Slice of root.
Apr 13 14:50:01 Vag2 CROND[2596]: (root) CMD (/usr/lib64/sa/sa1 1 1)

常時更新

-fで常に新しいログを追記してくれます。tail -f的な感じです。

% sudo journalctl -f

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST. --
Apr 13 14:50:01 Vag2 systemd[1]: Created slice User Slice of root.
Apr 13 14:50:01 Vag2 systemd[1]: Starting User Slice of root.
Apr 13 14:50:01 Vag2 systemd[1]: Started Session 8 of user root.
Apr 13 14:50:01 Vag2 systemd[1]: Starting Session 8 of user root.
Apr 13 14:50:01 Vag2 CROND[2596]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Apr 13 14:50:01 Vag2 systemd[1]: Removed slice User Slice of root.
Apr 13 14:50:01 Vag2 systemd[1]: Stopping User Slice of root.
Apr 13 14:56:24 Vag2 sudo[2605]:  vagrant : TTY=pts/0 ; PWD=/home/vagrant ; USER=root ; COMMAND=/bin/journalctl -r

ページャ無し

-no-pagerでページャ無しでそのまま表示します。

% sudo journalctl --no-pager

出力結果

-- Logs begin at Sat 2019-04-13 14:05:21 JST, end at Sat 2019-04-13 15:02:30 JST. --
Apr 13 14:05:21 localhost.localdomain systemd-journal[84]: Runtime journal is using 6.1M (max allowed 49.5M, trying to leave 74.3M free of 489.6M available → current limit 49.5M).
Apr 13 14:05:21 localhost.localdomain kernel: Initializing cgroup subsys cpuset
Apr 13 14:05:21 localhost.localdomain kernel: Initializing cgroup subsys cpu
<省略>
Apr 13 15:01:01 Vag2 anacron[2654]: Will run job `cron.daily' in 30 min.
Apr 13 15:01:01 Vag2 anacron[2654]: Will run job `cron.weekly' in 50 min.
Apr 13 15:01:01 Vag2 anacron[2654]: Jobs will be executed sequentially
Apr 13 15:02:30 Vag2 sudo[2661]:  vagrant : TTY=pts/0 ; PWD=/home/vagrant ; USER=root ; COMMAND=/bin/journalctl --no-pager

まとめ

他にもたくさんオプションありますが、使いこなせるとだいぶオペレーション早くなるのではないかと思います。
journaldに関しては世の中では賛否両論あるみたいですが、個人的には結構使いやすいんじゃないかなと思いました。