システム出力の仕組みと管理

Linux での問題解決においては、まずシステムからのメッセージや構成情報などを集めて読み取ることが基本中の基本となります。
ここでは、システム出力や構成情報について基本的な事項を扱います。

システム出力については、エラーや警告、動作状況などがリアルタイムに出力されるた非常に有用です。
ただし、ただこれを漠然と集めていても効果は薄いでしょう。
より効果的にシステム出力を扱うためには、その仕組みと特性を理解しておく必要があります。

そこで、まずシステム出力の仕組みについておさらいしておきます。

現在のLinux のシステム出力は、原始的なコンソール出力のほかに、systemd-journald(とrsyslogd)もしくは、noshとdeamon tools による出力の２つが主流？のようです。なお、ここでは noshのlogging については扱いません。systemd-journald の場合だけとします。

概要

まず、カーネルから立ち上がるメッセージはリングバッファに格納されます。また、このリングバッファとのやり取りは、このバッファにマップされている仮想ファイルである /proc/kmsgまたは/dev/kmsg を経由することでやり取りすることができます。
次に、ユーザースペースから立ち上がるメッセージですが、こちらは、syslog関数の他に、journaldの提供する機能によって各種ログとして保存され、メッセージを抽出することができます。

正確ではないですが、かなり大雑把に説明すると、Linux ではこのような仕組みによって、システム出力が作成され記録されます。
また、私も細部までを理解しきれてはいませんが、図示すると以下のようになるでしょうか。

以下では、ここで登場した Linux ログメッセージモジュールについても簡単にまとめておきます。

カーネルメッセージと printk()

カーネルメッセージとは、主に、カーネル領域で実行される関数/モジュールが printk() 関数を呼び出すことで出力されるメッセージのことです。

printk関数(print kernel)は、与えられたメッセージに、指定されたログレベルを付加して、メッセージをリングバッファに格納するという動作を行います。使用方法は以下のとおりです。

printk(KERN_DEBUG "%s:%i: This is DEBUG message\n", __FILE__, __LINE__);

先頭に付加された KERN_DEBUG がログレベルを表します。これは文字列そのものですが、printk ではこのようにログレベルを指定します。
引数であると勘違いしないでください。KERN_DEBUGは実際には文字列を表し、ビルド時のプリプロセス処理「文字列リテラルの連結」によって、その後ろに位置するフォーマット文字列と連結されて処理されます。

許可されるログレベルは /include/linux/kern_levels.h に定義されています。

#define KERN_SOH	"\001"		/* ASCII Start Of Header */
#define KERN_SOH_ASCII	'\001'
 
#define KERN_EMERG	KERN_SOH "0"	/* system is unusable */
#define KERN_ALERT	KERN_SOH "1"	/* action must be taken immediately */
#define KERN_CRIT	KERN_SOH "2"	/* critical conditions */
#define KERN_ERR	KERN_SOH "3"	/* error conditions */
#define KERN_WARNING	KERN_SOH "4"	/* warning conditions */
#define KERN_NOTICE	KERN_SOH "5"	/* normal but significant condition */
#define KERN_INFO	KERN_SOH "6"	/* informational */
#define KERN_DEBUG	KERN_SOH "7"	/* debug-level messages */
 
#define KERN_DEFAULT	KERN_SOH "d"	/* the default kernel loglevel */

printk() 使用時にログレベルが指定されていない場合には、デフォルト値が適用されます。デフォルト値はカーネルビルド時のマクロ CONFIG_DEFAULT_MESSAGE_LOGLEVEL によって決定されます。これは通常は KERN_WARNING と同等です。

なお、ログレベルは小さいほうが優先度が高いです。
このため、付加されているログレベルが、あらかじめ設定されているコンソールログレベルよりも小さければ、コンソールにもメッセージを表示する動作となります。

ログレベルなどの設定

なお、ログレベルの設定/表示については、カーネルビルド時だけでなく、実行時でも、procfsもしくはsysctlを使用して行うことができます。以下のように、デフォルトのメッセージログレベルや他のprintk関連の設定を修正したり表示することができます。

sysctl:

ell@pop-os:~$ sudo sysctl -a | grep kernel\.printk
kernel.printk = 4	4	1	7
kernel.printk_delay = 0
kernel.printk_devkmsg = ratelimit
kernel.printk_ratelimit = 5
kernel.printk_ratelimit_burst = 10

procfs:

ell@pop-os:~$ cat /proc/sys/kernel/printk
4	4	1	7

kernel.printk および、/proc/sys.kernel/printk の値は /kernel/printk/printk.c に定義されている以下の配列から取得されます。

int console_printk[4] = {
	CONSOLE_LOGLEVEL_DEFAULT,	/* console_loglevel */
	MESSAGE_LOGLEVEL_DEFAULT,	/* default_message_loglevel */
	CONSOLE_LOGLEVEL_MIN,		/* minimum_console_loglevel */
	CONSOLE_LOGLEVEL_DEFAULT,	/* default_console_loglevel */
};

また、これらの要素の説明は Documentation の sysctl/kernel.txt に下記のように記載されています。

先にも述べましたが、 console_loglevel よりも高い優先順位を持つメッセージはコンソールに表示されます。デフォルト値はコンパイル時のマクロ DEFAULT_CONSOLE_LOGLEVEL によります。ほかも似たようにデフォルト値はビルド時のマクロによるので、残り２つについては割愛します。

ちなみにですが、コンソールログレベルは minimum_console_loglevel よりも低い値に設定することはできません、設定しようとすれば、minimum_console_loglevel の値となります。

sysctl の他の要素についても簡単に説明しておきます。

リングバッファ

Linux では、printk メッセージをユーザースペースの systemd-journald に直接送信することはできないため、まず printk() 出力をリングバッファに格納します。systemd-journald の環境では、リングバッファは主に /dev/kmsg を経由してアクセスできます。dmesg も同じです。

リングバッファって何？と思うかもしれませんが、リングバッファの実態は 文字配列 です。/kernel/printk/printk.c で下記のように定義されています。この配列には、printkによるメッセージのレコードが、 printk() がカーネルもしくはモジュール内で呼び出された順番に格納されています。

/* record buffer */
#define LOG_ALIGN __alignof__(struct printk_log)
#define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)
#define LOG_BUF_LEN_MAX (u32)(1 << 31)
static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
static char *log_buf = __log_buf;
static u32 log_buf_len = __LOG_BUF_LEN;

また、各 printk() 実行によって発行される各メッセージレコードのフォーマットは、下記のリストのように定義されています。こちらの定義も /kernel/printk/printk.c に記載があるので気になる方は自分の目で確かめておきましょう。
ナノ秒のタイムスタンプ、レコード全体の長さ、テキストバッファの長さ、ディクショナリバッファの長さ、syslogファシリティなどなど。

struct printk_log {
	u64 ts_nsec;		/* timestamp in nanoseconds */
	u16 len;		/* length of entire record */
	u16 text_len;		/* length of text buffer */
	u16 dict_len;		/* length of dictionary buffer */
	u8 facility;		/* syslog facility */
	u8 flags:5;		/* internal record flags */
	u8 level:3;		/* syslog level */
}

さて、リングバッファは文字配列でしたが、その大きさはユーザーが定義するものです。つぎの２つの方法で設定することができます。

1. コンパイル時マクロ-CONFIG_LOG_BUF_SHIFTの設定。先に抜粋したコードより明らかです。
2. ブート時のカーネルパラメータ-log_buf_len。log_buf_len=n[KMG]のカタチで指定します。nは２の累乗の必要があります。

デフォルトで CONFIG_LOG_BUF_SHIFT に何が設定されているかは /boot/config-* で確認できます。私の環境では以下のようになりました。

ell@pop-os:~$ sudo grep CONFIG_LOG_BUF_SHIFT /boot/config-$(uname -r)
CONFIG_LOG_BUF_SHIFT=18

この場合には、約 256 KB ということになります。
なお、リングバッファという名称からもおわかりのことと思いますが、リングバッファの領域を最後まで使い切ると、再度先頭に戻って記録を続けるようになります。したがって、メッセージの量がある程度以上になると、最初に記録されたメッセージが上書きされることを認識しておきましょう。

/dev/kmsg

/dev/kmsg はリングバッファへの読み書きを行うために printk によって公開されているインターフェースのうちの一つです。/drivers/char/mem.c にて作成されます。

ell@pop-os:~$ ls -l /dev/kmsg
crw-r--r-- 1 root root 1, 11 Mar 28 22:08 /dev/kmsg

/dev/ksmg は基本的に読み書き可能なキャラクタ型デバイスで、どのユーザー空間プログラムもこのデバイスを open して読み書きできます。

この char型ドライバ用のコールバックハンドラは先に述べたとおり、printk.c 内部で実装されています。/dev/kmsg を読む際に、open/readのコールバックハンドラとして登録されている devkmsg_open と devkmsg_read を経由しますが、この場合には、このドライバは /dev/kmsg の読み取りに対して、 log_first_idx から log_next_idx までのリングバッファーを読むことを可能にします。
つまり、本質的に /dev/kmsg はリングバッファ全体を取得します。また、読み取ってもリングバッファから削除されることはありません。ただ読み込まれるだけです。

なお、このインターフェースは dmesg と systemd-journald で使用されていますが、/dev/kmsg 自体を cat で読み取ることが可能です。

ell@pop-os:~$ sudo cat /dev/kmsg | head -n 2
5,0,0,-;Linux version 4.18.0-16-generic (buildd@lcy01-amd64-016) (gcc version 7.3.0 (Ubuntu 7.3.0-27ubuntu1~18.04)) #17pop0~18.04.1-Ubuntu SMP Fri Mar 8 17:51:15 UTC 2019 (Ubuntu 4.18.0-16.17pop0~18.04.1-generic 4.18.20)
6,1,0,-;Command line: initrd=\x5cEFI\x5cPop_OS-ded7c8db-810f-4d55-a0c2-75b26e918d5b\x5cinitrd.img root=UUID=ded7c8db-810f-4d55-a0c2-75b26e918d5b ro quiet loglevel=0 systemd.show_status=false splash

dmesg

dmesgは/dev/kmsgインターフェースで動作するユーティリティです。/dev/kmsg を介してリングバッファから任意にカーネルメッセージを取り出すことができます。

ell@pop-os:~$ dmesg

なお、dmesgだけではシェルへ出力結果を表示するのみで、さらにデフォルトではリングバッファから最大で 16KB 分のメッセージしか読み取りません。そのため、オプションなしでの実行ではリングバッファからすべてを読み取ることはできませんので注意してください。
リングバッファ全体のカーネルメッセージを読み取る際には、 -s オプションでサイズを指定して実行します。

私の環境では 256 KB なので以下のようになります。

ell@pop-os:~$ dmesg -s 262144 #256KB

また、dmesg コマンドでもコンソールログレベルを指定できます。

ell@pop-os:~$ dmesg -n LOG_LEVEL

これ以上の詳細は man ページか -h オプションを参照してください。

ell@pop-os:~$ dmesg -h
 
Usage:
 dmesg [options]
 
Display or control the kernel ring buffer.
 
Options:
 -C, --clear                 clear the kernel ring buffer
 -c, --read-clear            read and clear all messages
 -D, --console-off           disable printing messages to console
 -E, --console-on            enable printing messages to console
 -F, --file <file>           use the file instead of the kernel log buffer
 -f, --facility <list>       restrict output to defined facilities
 -H, --human                 human readable output
 -k, --kernel                display kernel messages
 -L, --color[=<when>]        colorize messages (auto, always or never)
                               colors are enabled by default
 -l, --level <list>          restrict output to defined levels
 -n, --console-level <level> set level of messages printed to console
 -P, --nopager               do not pipe output into a pager
 -r, --raw                   print the raw message buffer
 -S, --syslog                force to use syslog(2) rather than /dev/kmsg
 -s, --buffer-size <size>    buffer size to query the kernel ring buffer
 -u, --userspace             display userspace messages
 -w, --follow                wait for new messages
 -x, --decode                decode facility and level to readable string
 -d, --show-delta            show time delta between printed messages
 -e, --reltime               show local time and time delta in readable format
 -T, --ctime                 show human-readable timestamp (may be inaccurate!)
 -t, --notime                don't show any timestamp with messages
     --time-format <format>  show timestamp using the given format:
                               [delta|reltime|ctime|notime|iso]
Suspending/resume will make ctime and iso timestamps inaccurate.
 
 -h, --help                  display this help
 -V, --version               display version
 
Supported log facilities:
    kern - kernel messages
    user - random user-level messages
    mail - mail system
  daemon - system daemons
    auth - security/authorization messages
  syslog - messages generated internally by syslogd
     lpr - line printer subsystem
    news - network news subsystem
 
Supported log levels (priorities):
   emerg - system is unusable
   alert - action must be taken immediately
    crit - critical conditions
     err - error conditions
    warn - warning conditions
  notice - normal but significant condition
    info - informational
   debug - debug-level messages
 
For more details see dmesg(1).

journaldとログファイル

systemd-journald は単一のモノリシックログマネジメントサービスです。さまざまなソースからロギングデータを収集してjournalsというバイナリとして保存します。
＊journalsは構造化およびインデックス化されたデータで、ログの検索性に優れます。

journald がログを集める方法とソースは多岐にわたります。
主に以下の５つがあります。

• /dev/kmsgからカーネルメッセージを取得します。
• glibcのsyslog()関数呼び出しによるメッセージを/dev/logから取得します。
• journal-API(sd_journal_print)によるメッセージを取得します。
• systemdサービスの標準出力/標準エラー出力を取得します。
• kernel-audit-subsystemからのauditログ

上記のとおり、journald はカーネル起動時からのメッセージ(カーネル初期化フェーズ、初期RAMディスクの記録などブートプロセスでのメッセージ)から、カーネル起動後のメインシステムランタイムのメッセージ、各種デーモンサービスのメッセージ、他に伝統的なLinuxのログ出力まで、ほとんどすべてのシステム出力を網羅して記録しています。

UNIX哲学的なところで、systemdやjournaldについては意見が割れたりすることも多いですが、問題解決の側面からjournaldを見た時、その網羅性と検索性から journald はかなり強力なトラブルシューティングツールといえます。

journald のログの保存場所

journalのログはデフォルトで /run/log/journal/ として公開されるディレクトリに保存されますが、これは小型リングバッファに過ぎません(揮発性のメモリ上のファイルシステム)。ログ記録されるデータ量は空きメモリ量によりますし、データ量が限界を迎えれば古いログエントリから順に削除されていきます。
このように、ここに保存されるログは揮発性で、また、OS の再起動時に失われてしまいます。つまり直近の起動後の直近のログのみを保存しています。

しかし、これではトラブルシュートのときに困ります。
そのため、よりクリティカルなシステムでは、journaldのログは、できるだけ永続化させた状態にして、ログデータをきっちり残して運用することを個人的におすすめします。

なお、journaldのログデータを永続的に保存するためには、 /var/log/journal/ ディレクトリを作成して、journald を再起動させます。journald起動時に /var/log/journal/ が存在する場合にはログデータは永続的に保存されます。

ell@pop-os:~$ mkdir -p /var/log/journal/
ell@pop-os:~$ sudo systemctl restart systemd-journald

「そんなことしたら永続化させた場合の保存データ量はどうなってしまうだ」と心配される方もいるかもしれないので一点補足ですが、「/var/log/journal」を使用してログデータを永続化しても、無制限にログが保存されていくわけではありません。

ログのデータ量が当該ディレクトリの属するファイルシステムの全容量に対して10%以上になるか、当該ディレクトリの属するファイルシステムの空き容量が15%以下になると、古いエントリーから順に削除されていきます。
保存容量については、設定ファイル /etc/systemd/journald.conf の SystemMaxUse と SystemKeepFree で制御することもできます。詳細は man を参照してください。

ell@pop-os:~$ cat /etc/systemd/journald.conf 
 ...
#SystemKeepFree=
#SystemMaxFileSize=
 ...

なお、現在、Ubuntu や RHEL などの主要な Linux ディストリビューションでは、デフォルトで rsyslogd と journald が併存しており、ログの保存はデフォルトで rsyslog が担当しています。

後ほど、別枠で扱いますが、
冒頭にも記載したように伝統的なsyslog宛のメッセージもjournald が/dev/log より奪取しており、すべてのシステム出力をまず journald が受持ます。
その後、rsyslogdがimjournal入力モジュール経由で、journaldからデータ受け取り、各種ログファイルに保存していくのです。しかし、この場合 journald が永続化されていなく、rsyslogd が起動していない場合などにはログが溢れることがありますので注意してください。

プライオリティレベルとファシリティ

プライオリティはログを書き込む際の優先順位、ファシリティはログの目的別分類を制御するもので、それぞれ下記の表のようになっています。syslog の場合と同様です。

プライオリティレベル: 優先順位

ファシリティレベル: 目的別分類

次はログの確認方法を確認します。

journalログの確認方法

ell@pop-os:~$ journalctl
ell@pop-os:~$ journalctl -l --no-pager

パラメータなしで呼ばれた場合、採取された最も古いエントリから始まるすべてのログデータを表示します。上記 -l -no-pager なしの場合は less を通した出力です。-l -no-pager は less を通さない出力です。

最新の起動時から現在までのすべてのメッセージを表示する場合には以下のようにします。

ell@pop-os:~$ journalctl -b 

ブートを複数回おこなっており、過去の特定の起動時からその終了時までのメッセージを表示する際には、 -b オプションに任意のパラメータを付加してオフセットを設定することができます。 -b -0 は最新のもの、 -b -1 は一つ前のシステム出力、 -b -2 は２つ前の起動時から終了までのシステム出力となり、以後続きます。

また、以下のようにすることで、指定できる起動記録の数字を確認できます。

ell@pop-os:~$ journalctl --list-boots
-4 7c773947d52640dd9798c3ad8c6675b2 Fri 2019-03-22 02:04:47 JST—Wed 2019-03-27 0
-3 2392a189f552439bb4aa86ef2b8d2436 Wed 2019-03-27 23:56:13 JST—Thu 2019-03-28 0
-2 e369f5014fda492bb6f0b22f1b7794b0 Thu 2019-03-28 02:07:02 JST—Thu 2019-03-28 2
-1 da82dce3fb544ce29f154bf118e6d391 Thu 2019-03-28 22:08:45 JST—Tue 2019-04-02 0
 0 4e0b91855ba043c68d665c844985f45f Tue 2019-04-02 00:25:20 JST—Wed 2019-04-03 0

しかし、上記の方法はシステムを頻繁に再起動しない場合にはログが膨大になることもあります。そのような場合には時間によるフィルタリングが役立ちます。
時間によるフィルタリングは下記のようにします。

ell@pop-os:~$ journalctl --since="2019-04-02 00:00:00"
ell@pop-os:~$ journalctl --since="2019-04-02 00:00:00" --until="2019-04-02 01:00:00"
ell@pop-os:~$ journalctl --since "20 min ago"

-f オプションは tail -f のように働きます。つまりライブビューです。

ell@pop-os:~$ journalctl -f

-n オプションは最新のログエントリーを指定した数だけ表示します。

ell@pop-os:~$ journalctl -n 10

優先度によるフィルタリングは -p オプションで行います。
先に説明したプライオリティのコードを小文字で指定します。

ell@pop-os:~$ journalctl -p err

ユニットで絞る場合には -u オプションを使います。

ell@pop-os:~$ journalctl -u hoge.service

journalログの詳細の確認方法

jounarlログの全フィールドを伴う完全構造化エントリーを表示するには -o verbose オプションを使用します。

ell@pop-os:~$ journalctl -o verbose -n 1 -l --no-pager
-- Logs begin at Fri 2019-03-22 02:04:47 JST, end at Wed 2019-04-03 02:17:01 JST. --
Wed 2019-04-03 02:17:01.592087 JST [s=4979d79a4c3b4a598212fb74662f4299;i=19f64;b=4e0b91855ba043c68d665c844985f45f;m=40be40797;t=5858f4e27a641;x=c3fee30d3ac2e608]
    _MACHINE_ID=552b55dba08fd69801ad20fe5c93c396
    _HOSTNAME=pop-os
    PRIORITY=6
    _UID=0
    _GID=0
    _SELINUX_CONTEXT=unconfined
    _SYSTEMD_SLICE=system.slice
    _CAP_EFFECTIVE=3fffffffff
    _TRANSPORT=syslog
    _COMM=cron
    _EXE=/usr/sbin/cron
    _SYSTEMD_CGROUP=/system.slice/cron.service
    _SYSTEMD_UNIT=cron.service
    SYSLOG_FACILITY=10
    SYSLOG_IDENTIFIER=CRON
    _CMDLINE=/usr/sbin/CRON -f
    _AUDIT_LOGINUID=0
    MESSAGE=pam_unix(cron:session): session closed for user root
    _AUDIT_SESSION=8
    _BOOT_ID=4e0b91855ba043c68d665c844985f45f
    _SYSTEMD_INVOCATION_ID=71b4d40f28bb465b88e6b69eb2764a43
    SYSLOG_PID=14342
    _PID=14342
    _SOURCE_REALTIME_TIMESTAMP=1554225421592087

ちなみに、これらのメタデータの各フィールドによってフィルタリングすることができます。

下記は、指定されたフィールドで発生する値を一覧表示します。

journalctl -F fieldname

特定条件のみに合致するログエントリーのみを表示する場合には下記のようにします。例えば _PID= を使用すれば特定のプロセス ID から生まれたログに出力を絞ることができます。

journalctl fieldname=value

論理AND で複数条件を指定するには各条件をスペースで区切ります。
論理 OR で複数条件を指定するには + で区切ります。

journalctl fieldname1=value fieldname2=value ...
journalctl fieldname1=value + fieldname2=value ...

( おまけの rsyslogd )

rsyslogd によるログファイルは journald から収集したログエントリが保存されていきますが、rsyslogd により保存されるログファイルの一覧は /etc/rsyslog.conf /etc/rsyslog.d/* 設定ファイルに定義されてあります。

デフォルトでは /etc/rsyslog.d/ ディレクトリにある 50-default.conf ファイルの内容によって決まります。基本的にファシリティとプライオリティでフィルタされます。

ファシリティ.プライオリティ 出力先

下記は 50-default.conf の例ですが、cronとしてマークされたログメッセージが cron.log ファイルに書き込まれることを示しています。この場合、アスタリスク * はsyslogdに任意の優先順位(プライオリティ)でエントリーを送信するように指示しています。

cron.* /var/log/cron.log

rsyslogdのログファイルを操作するのに、journalctlのような特別なツールは必要なく、もっと UNIX 的です。しかし、rsyslogd をよく知りたいのであれば、どの標準ログファイルにどのような情報が保存されているのかを知る必要があります。
下記表に、最も一般的なrsyslogdログファイルとその目的を示します。

rsyslogdの管理についても見ておきましょう。

ログ管理

デフォルトでは、rsyslogdはログのローテーション、圧縮、削除をユーザーの助けを借りずに裏で処理します(logrotate)。ただし、特別な処理が必要なログがある場合に備えて、それがどのように行われているかを知っておく必要があります。

logrotateの動作を確認するためには、/var/log/ディレクトリの内容をいくつかリストしてみるのがわかりやすいと思います。たとえば、auth.logに注目してみると、それが 3つの異なる形式で表示されているかもしれません。

• auth.log:現在アクティブなバージョンで、新しい認証メッセージが書き込まれています。
• auth.log.1:使用外に切り替えられた最新のファイルです。必要に応じてすぐに呼び戻すことができるように、非圧縮形式で維持されています。
• auth.log.2.gz:.gzファイル拡張子からわかるように、必要になる可能性が低いため、スペース節約のために圧縮されています。

ell@pop-os:~$ ls /var/log/ | grep auth
auth.log      <--現在アクティブなバージョン
auth.log.1    <--最も最新のリタイアしたバージョン
auth.log.2.gz
auth.log.3.gz
auth.log.4.gz <--gzip圧縮された古いバージョン

7日後に次のローテーション日が来ると、
auth.log.2.gz は auth.log.3.gz に、auth.log.1は圧縮され auth.log.2.gz に名前変更されます。 auth.log は auth.log.1になり、新しいファイルも作成され、auth.logという名前が付けられます。

デフォルトのログローテーションサイクルは/etc/logrotate.confファイルで制御されます。下記リストに示されている値は、1週間毎にファイルをローテーションし、4週間後に最も古いファイルを削除するルールになっています。つまり、ログファイルは４週間保管されます。

ell@pop-os:~$ cat /etc/logrotate.conf 
...
#rotate log files weekly
weekly
#keep 4 weeks worth of backlogs
rotate 4
#create new (empty) log files after rotating old ones
create
#packages drop log rotation information into this directory
include /etc/logrotate.d

/etc/logrotate.d/ディレクトリには、個々のサービスまたはアプリケーションのログローテーションを管理するための。カスタマイズされた設定ファイルが含まれています。 そのディレクトリの内容をリストすると、下記の設定ファイルが表示されます。

ell@pop-os:~$ ls /etc/logrotate.d/
alternatives  apt          dpkg  rsyslog            ufw
apport        cups-daemon  ppp   speech-dispatcher

下記は apt の例です。

$ cat /etc/logrotate.d/apt 
/var/log/apt/term.log {
  rotate 12
  monthly
  compress
  missingok
  notifempty
}
 
/var/log/apt/history.log {
  rotate 12
  monthly
  compress
  missingok
  notifempty
}

ログファイルは１月毎にローテーションされ、かつ１２ヶ月保管されます。

procfs からの情報収集

procfs は /proc にマウントされている Linux の仮想ファイルシステムです。/proc 以下に存在する仮想ファイルに対して読み書きを行うことで、カーネル情報へのアクセスやデバッグ、パラメータの表示/変更を行うことができます。

特にテキストストリームとしてプロセス情報にアクセスできることが特別な機能の一つではないでしょうか。トラブルシュートにも役立つ多くの Linux コマンドがこのファイルシステムに依存しています。

ここでは情報ソースとしての procfs を簡単におさらいしておきます。

仮想ファイルシステム？

/proc ファイルシステムのファイルとディレクトリは仮想的なものです。データは実際には記憶装置には存在していません。代わりに、それらを読み込もうとするたびに、それらの内部のディレクトリ、ファイル、データが、生のカーネルデータからメモリ内に動的に作成されています。

プロセス情報

各プロセスは、その PID で識別されるエントリを /proc 下に持ちます。以下は /proc ディレクトリ内の重要なファイルです。

• /proc/PID/cmdline:にはプロセス開始時に使用されたコマンドが含まれています。
• /proc/PID/cwd:はプロセスの現在の作業ディレクトリへのリンクです。
• /proc/PID/environ:にはプロセスが利用可能な環境変数のリストが含まれています。
• /proc/PID/exe:はそのプロセスで実行されているプログラムへのリンクです。
• /proc/PID/fd:はプロセスが開いている各ファイルへのリンクを含むディレクトリです。
• /proc/PID/io:はプロセスのI/O統計情報を含みます。
• /proc/PID/mem:はプロセスのメモリ内容です。
• /proc/PID/smaps:はプロセスの各マッピングのメモリ消費量を表示します。
• /proc/PID/stack:はプロセスのカーネルスタック内の関数呼び出しのシンボリックトレースを含みます。
• /proc/PID/stat:はプロセスステータス情報を含みます。
• /proc/PID/statm:には、プロセスのメモリ使用量情報が含まれています。
• /proc/PID/status:はstatとstatmを人間が読みやすいように整形します。

下記にプロセス情報を取得する例をいくつか記載します。

i) プロセスの情報を単に知りたいなら cat /proc/PID/status を行えばいいですが、たまに /proc/PID/stat の９番目の項目をみるとプロセスの情報をフラグという形で多く入手することもできます。

ell@pop-os:~$ sudo cat /proc/1655/stat | awk '{printf "%x\n", $9}' 
400000

フラグは linux/sched.h にあります。

#define PF_IDLE			0x00000002	/* I am an IDLE thread */
#define PF_EXITING		0x00000004	/* Getting shut down */
#define PF_EXITPIDONE		0x00000008	/* PI exit done on shut down */
#define PF_VCPU			0x00000010	/* I'm a virtual CPU */
#define PF_WQ_WORKER		0x00000020	/* I'm a workqueue worker */
#define PF_FORKNOEXEC		0x00000040	/* Forked but didn't exec */
#define PF_MCE_PROCESS		0x00000080      /* Process policy on mce errors */
#define PF_SUPERPRIV		0x00000100	/* Used super-user privileges */
#define PF_DUMPCORE		0x00000200	/* Dumped core */
#define PF_SIGNALED		0x00000400	/* Killed by a signal */
#define PF_MEMALLOC		0x00000800	/* Allocating memory */
#define PF_NPROC_EXCEEDED	0x00001000	/* set_user() noticed that RLIMIT_NPROC was exceeded */
#define PF_USED_MATH		0x00002000	/* If unset the fpu must be initialized before use */
#define PF_USED_ASYNC		0x00004000	/* Used async_schedule*(), used by module init */
#define PF_NOFREEZE		0x00008000	/* This thread should not be frozen */
#define PF_FROZEN		0x00010000	/* Frozen for system suspend */
#define PF_KSWAPD		0x00020000	/* I am kswapd */
#define PF_MEMALLOC_NOFS	0x00040000	/* All allocation requests will inherit GFP_NOFS */
#define PF_MEMALLOC_NOIO	0x00080000	/* All allocation requests will inherit GFP_NOIO */
#define PF_LESS_THROTTLE	0x00100000	/* Throttle me less: I clean memory */
#define PF_KTHREAD		0x00200000	/* I am a kernel thread */
#define PF_RANDOMIZE		0x00400000	/* Randomize virtual address space */
#define PF_SWAPWRITE		0x00800000	/* Allowed to write to swap */
#define PF_MEMSTALL		0x01000000	/* Stalled due to lack of memory */
#define PF_UMH			0x02000000	/* I'm an Usermodehelper process */
#define PF_NO_SETAFFINITY	0x04000000	/* Userland is not allowed to meddle with cpus_allowed */
#define PF_MCE_EARLY		0x08000000      /* Early kill for mce process policy */
#define PF_MEMALLOC_NOCMA	0x10000000	/* All allocation request will have _GFP_MOVABLE cleared */
#define PF_FREEZER_SKIP		0x40000000	/* Freezer should not count it as freezable */
#define PF_SUSPEND_TASK	0x80000000 /* This thread called freeze_processes() and should not be frozen */

ii） /proc/[pid]/fd/ ディレクトリはプロセスが開いているファイルに関する情報を教えてくれます。プロセスで使用されている入力ファイルを見つけるには：

ell@pop-os:~$ sudo ls -l /proc/1634/fd/0
lr-x------ 1 ell ell 64 Apr  5 01:22 /proc/1634/fd/0 -> /dev/null

iii) プロセスで使用されているソケットを見つけるには:

ell@pop-os:~$ sudo ls -l /proc/1655/fd | sed -n '/socket/{s/.*\[//;s/\]//p}'
33099
32390
32399
33522
33100
33368
31531
31533

これらのソケットに関する情報は netsat -ae で取得できます。

iv) コマンドライン引数を確認するには:

ell@pop-os:~$ sudo cat /proc/1655/cmdline ; echo
/usr/lib/gnome-settings-daemon/gsd-media-keys

v) プロセスの親プロセスIDを取得するには:

ell@pop-os:~$ sudo grep PPid /proc/1655/status
PPid:	1364

vi)プロセスの作業ディレクトリは:

ell@pop-os:~$ sudo ls -l /proc/1634/cwd
lrwxrwxrwx 1 ell ell 0 Apr  5 01:23 /proc/1634/cwd -> /home/ell

一般的なシステム情報

重要なものに下記の表のようなものがある。

i) システムのメモリ状態を知るためには /proc/meminfo をcatします。フリーなメモリ量を確認するには:

ell@pop-os:~$ cat /proc/meminfo | grep Free
MemFree:          568492 kB
SwapFree:              0 kB
HugePages_Free:        0

ii) 最新の起動後のシステム統計は、/proc/statファイルから収集できます。前回の再起動以降にシステムが持っていたプロセス数を調べるには:

ell@pop-os:~$ cat /proc/stat | grep processes
processes 33319

iii) 1分、5分、15分ごとのシステム負荷平均を調べるには、以下のようにします:

ell@pop-os:~$ cat /proc/loadavg | awk '{print "1 min:\t" $1 "\n5 min:\t" $2 "\n15 min:\t" $3 }' 
1 min:	0.00
5 min:	0.00
15 min:	0.00

iv) /proc/partitions は以下のようにパーティション情報を教えてくれます:

ell@pop-os:~$ cat /proc/partitions 
major minor  #blocks  name
 
 202        0    8388608 xvda
 202        1    8386543 xvda1

vi) /proc/mountsからはマウントされているファイルシステムの情報を取得できます:

ell@pop-os:~$ cat /proc/mounts | head -n 3
sysfs /sys sysfs rw,nosuid,nodev,noexec,relatime 0 0
proc /proc proc rw,nosuid,nodev,noexec,relatime 0 0
devtmpfs /dev devtmpfs rw,nosuid,size=485720k,nr_inodes=121430,mode=755 0 0

vii) CPUの情報は以下のように取得します:

cat /proc/cpuinfo

viii) swapの使用率は下記のように取得します:

cat /proc/swaps

ix) システムの起動時間を取得します:

cat /proc/uptime

x) NFSで共有されているファイルシステムを一覧表示します:

cat /proc/fs/nfsd/exports

xi) /proc/kcore は、コアファイル形式でシステムの物理メモリへのアクセスを提供します。カーネルデータ構造の現在の状態を調べるためにgdbによって使用されたりします。

procfs のさらに詳しい情報が知りたい場合には/usr/src/linux/Documentation/filesystems/proc.txtをまず参照するようにしてください。

設定ファイルからの情報収集

トラブルシューティングをする上ではシステムの設定がどのようになっているか把握することも重要です。一般的に下記のようなものがあります。

ディストリビューションやインストールされているソフトウェアによっても異なり、他にもさまざまな設定ファイルが存在しますので調査してみてください。

ユーティリティを使う

問題調査時にはさまざまなツールが利用できます。
ツールを利用することで、/proc/から情報を収集するよりもより早く的確な情報収集が可能になる場合があります（多くの場合そうです）。またダンプやトレースなどの情報も得ることができます。
こちらについてはメモついでに、また別の機会に紹介させていただきます。調査に使用できるツールを紹介しだすと、きりがないのでここではあつかいません。

ログの読み方

ログメッセージをしっかり読みましょう。プライオリティに注目するのは当然ですし、いい方法ですが、しかし、それだけを見て騒ぐのはナンセンスです。メッセージの意味をしっかり読まれることを推奨します。

幸いにも Linux システムに存在するソフトウェアのほとんどがオープンソースです。メッセージの意味がとりにくくても、ソースを読むことで利用者が自力で調べることができます。また、Linux システムを選択した以上、それを読んで意味を理解するのも利用者の努めであるのではないでしょうか？

時刻合わせをしましょう

ログの時刻が盛大にずれているとしたら、せっかく取得したログには何の意味もありません。サーバーの時刻同期はしっかり取っておきましょう。またタイムゾーンもしっかり把握しておきましょう。UTC の時刻を JST で眺めても何もわかりません。以外にこんなポカミスが多かったりし悲しい思いをするときがあります。僕自身も。。