Linux环境下通过journal命令查看和管理日志

前言

就在半月之前,负责打包更新的服务器突然登录不上去了,赶紧找来运维的同事帮忙解决,发现系统日志中有很多 systemd-journald[424]: Failed to open runtime journal: No space left on device 字样的错误,被告知磁盘满了需要清理,但是我当时登录不上去,只能让他们帮忙重启后利用单用户模式上去删除临时文件试试,但重启后发现问题解决了,很是诧异,查询服务器后台监控平台,发现磁盘空间还有50%,inode只占用了0.02%,这怎么会磁盘满了呢?

问题分析

后来经过分析,应该是journal默认将系统日志存储在/run/log/journal目录中,而 /run是一个临时文件系统,通常挂载在内存中,用于存储运行时产生的临时文件,如进程 ID 文件、锁文件等,如果登录所需的文件或进程受到 /run 空间不足的影响,可能会导致登录问题。例如,如果 sshd 进程的运行所需的文件被存储在 /run 中并且空间不足,那么可能无法正常登录。

1
2
3
4
$ df -h
Filesystem Size Used Avail Use% Mounted on
devtmpfs 7.8G 0 7.8G 0% /dev
tmpfs 7.8G 868K 7.8G 1% /run

所以系统重启后,这个空间释放了也就能通过ssh登录了,并且重启后journal日志清空也证实了这一点。

关于这个空间限制多数说的是10%,但是如果真是的所处分区的10%,那么不会导致我登录不上的,所以我倾向于是系统内存10%或者硬盘最大10%,默认最大限制4G,具体限制等我有空时查查文档吧,先贴一段看起来很靠谱的描述

SystemMaxUse=, SystemKeepFree=, SystemMaxFileSize=, SystemMaxFiles=, RuntimeMaxUse=, RuntimeKeepFree=, RuntimeMaxFileSize=, RuntimeMaxFiles=
限制日志文件的 大小上限。 以 “System” 开头的选项用于限制磁盘使用量, 也就是 /var/log/journal 的使用量。 以 “Runtime” 开头的选项用于限制内存使用量, 也就是 /run/log/journal 的使用量。 以 “System” 开头的选项仅在 /var/log/journal 目录确实存在且可写时才有意义。 但以 “Runtime” 开头的选项永远有意义。 也就是说, 在系统启动早期 /var 尚未挂载时、 或者系统管理员禁止在磁盘上存储日志的时候, 仅有 “Runtime” 开头的选项有意义。 journalctl 与 systemd-journald 工具会忽略日志目录中 所有后缀名不等于 “.journal” 或 “.journal~” 的文件。 换句话说,日志目录中不应该存在后缀名不等于 “.journal” 或 “.journal~” 的文件, 因为这些文件 永远不会被清理。

SystemMaxUse= 与 RuntimeMaxUse= 限制全部日志文件加在一起最多可以占用多少空间。 SystemKeepFree= 与 RuntimeKeepFree= 表示除日志文件之外,至少保留多少空间给其他用途。 systemd-journald 会同时考虑这两个因素, 并且尽量限制日志文件的总大小,以同时满足这两个限制。

SystemMaxUse= 与 RuntimeMaxUse= 的默认值是10%空间与4G空间两者中的较小者; SystemKeepFree= 与 RuntimeKeepFree= 的默认值是15%空间与4G空间两者中的较大者; 如果在 systemd-journald 启动时,文件系统即将被填满并且已经超越了 SystemKeepFree= 或 RuntimeKeepFree= 的限制,那么日志记录将被暂停。 也就是说,如果在创建日志文件时,文件系统有充足的空闲空间, 但是后来文件系统被其他非日志文件过多占用, 那么 systemd-journald 只会立即暂停日志记录, 但不会删除已经存在的日志文件。 注意,只会删除已归档的日志文件以释放空间。 也就是说,即使在完成日志清理之后, 日志所占用的空间仍然可能大于 SystemMaxUse= 或 RuntimeMaxUse= 的限制。

SystemMaxFileSize= 与 RuntimeMaxFileSize= 限制单个日志文件的最大体积, 到达此限制后日志文件将会自动滚动。 默认值是对应的 SystemMaxUse= 与 RuntimeMaxUse= 值的1/8 , 这也意味着日志滚动 默认保留7个历史文件。

日志大小 可以使用以1024为基数的 K, M, G, T, P, E 后缀, 分别对应于 1024, 1024², … 字节。

SystemMaxFiles= 与 RuntimeMaxFiles= 限制最多允许同时存在多少个日志文件, 超出此限制后, 最老的日志文件将被删除, 而当前的活动日志文件 则不受影响。 默认值为100个。

以上描述来自 《journald.conf 中文手册》,另外 《Systemd日志管理服务:Journald以及重要配置选项》 这篇博文也提到了默认日志数据将仅存储在内存中,在系统关闭时会删除该数据。

journal 和 syslog 对比

提到系统日志除了journal比较常见以外,还有 syslog 也是比较基础的服务,两者都是日志服务,并且在系统中合理分工,相互配合,它们服务于不同的目标并且具有不同的特性。syslog是Linux系统的一套日志框架,它既可以记录日志到本地文件,也可以通过网络发送到接收syslog的服务器,以实现对多个设备的syslog消息进行统一的存储或解析。而journal是改进型的日志管理服务,主要收集来自内核、系统早期的启动阶段的日志以及系统守护进程在启动和运行中的标准输出和错误。

在CentOS 7及更高版本中,journalctl成为了查看和管理系统日志的主要工具,它从/var/log/journal/和/run/log/journal/等路径获取日志信息。同时,systemd-journald会将日志信息写入到socket文件/run/systemd/journal/syslog中,然后由rsyslog服务监听这个socket文件,从而实现对日志的统一管理和处理。因此,可以说syslog和journalctl在日志管理中各司其职,共同保障了Linux系统日志的完整性和可用性。

以上提到了一些名词,先说明一下来清楚其中的关系,journal日志使用journalctl工具管理,依赖systemd-journald服务,syslog日志可以用文本工具来查看,view、more、cat等命令都可以用,也可以借助其他工具查看特定信息,比如用dmesg命令查看syslog中内核相关日志,syslog依赖的服务名通常是 rsyslogd

journalctlsyslog 都是 Linux 系统中用于处理和查看系统日志的工具,我们从以下几个方面来对比下两者的区别:

  • 存储方式:

    • syslog 使用文本文件来存储日志信息,可以通过文本编辑器查看,通常存储在 /var/log/syslog/var/log/message
    • journalctl 使用 systemd-journald 服务来存储二进制格式的日志文件。通常存储在 /run/log/journal//var/log/journal/
  • 日志内容:

    • syslog 使用文本格式,记录在文本文件中。日志信息包含时间戳、主机名、应用程序名等
    • journalctl 使用二进制格式,可以存储更多的元数据,例如进程 ID、用户 ID、SELinux 上下文等。这使得日志更加结构化,支持更高级的查询和过滤
  • 查询和过滤:

    • syslog 的查询和过滤通常使用命令行工具(例如 grep)或者专用的工具(例如 logrotate
    • journalctl 提供了更丰富和强大的查询和过滤功能,可以按时间、服务单元、日志级别等多个条件进行过滤。这使得查找和分析特定事件更加方便
  • 实时查看:

    • syslog 通常使用 tail 命令实时查看日志文件的末尾
    • journalctl 可以使用 -f--follow 选项来实时查看最新的日志
  • 服务和依赖关系:

    • syslog 是一个通用的日志服务,可以由多个日志守护进程(如 rsyslogsyslog-ng)实现
    • journalctlsystemd 系统中的一部分,依赖于 systemd-journald 服务
  • 配置文件的路径:

    • syslog 的配置文件在 /etc/rsyslog.conf
    • journalctl 的配置文件在 /etc/systemd/journald.conf

总体而言,journalctlsystemd 系统的一部分,提供了更现代化、结构化和强大的日志管理功能,但这并不意味着 syslog 是过时的。在一些系统中,两者可能同时存在,而且一些工具和服务可能仍然使用传统的 syslog。选择使用哪一个取决于系统的需求和管理员的偏好。

下面分别展示一下systemd-journaldrsyslogd 两个服务查询信息:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
[root@demo ~]# systemctl status systemd-journald
● systemd-journald.service - Journal Service
Loaded: loaded (/usr/lib/systemd/system/systemd-journald.service; static; vendor preset: disabled)
Active: active (running) since Mon 2023-12-04 20:26:34 CST; 2 weeks 3 days ago
Docs: man:systemd-journald.service(8)
man:journald.conf(5)
Main PID: 7099 (systemd-journal)
Status: "Processing requests..."
CGroup: /system.slice/systemd-journald.service
└─7099 /usr/lib/systemd/systemd-journald

Dec 04 20:26:34 demo systemd-journal[7099]: Permanent journal is using 8.0M (max allowed 4.0G, trying to leave 4.0G free of 183.5G available → c…imit 4.0G).
Dec 04 20:26:34 demo systemd-journal[7099]: Time spent on flushing to /var is 21.108ms for 1873 entries.
Dec 04 20:26:34 demo systemd-journal[7099]: Journal started
Hint: Some lines were ellipsized, use -l to show in full.
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
[root@demo ~]# systemctl status rsyslogd
Unit rsyslogd.service could not be found.
[root@demo ~]# systemctl status rsyslog
● rsyslog.service - System Logging Service
Loaded: loaded (/usr/lib/systemd/system/rsyslog.service; enabled; vendor preset: enabled)
Active: active (running) since Mon 2023-12-04 19:46:04 CST; 2 weeks 3 days ago
Docs: man:rsyslogd(8)
http://www.rsyslog.com/doc/
Main PID: 913 (rsyslogd)
CGroup: /system.slice/rsyslog.service
└─913 /usr/sbin/rsyslogd -n

Dec 04 19:46:04 demo systemd[1]: Starting System Logging Service...
Dec 04 19:46:04 demo rsyslogd[913]: [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="913" x-info="http://www.rsyslog.com"] start
Dec 04 19:46:04 demo systemd[1]: Started System Logging Service.
Dec 04 20:26:34 demo rsyslogd[913]: imjournal: journal reloaded... [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/0 ]
Dec 10 03:22:01 demo rsyslogd[913]: [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="913" x-info="http://www.rsyslog.com"] rsys...was HUPed
Dec 15 01:35:01 demo rsyslogd[913]: imjournal: journal reloaded... [v8.24.0-57.el7_9.3 try http://www.rsyslog.com/e/0 ]
Dec 17 03:07:01 demo rsyslogd[913]: [origin software="rsyslogd" swVersion="8.24.0-57.el7_9.3" x-pid="913" x-info="http://www.rsyslog.com"] rsys...was HUPed
Hint: Some lines were ellipsized, use -l to show in full.

journal 和 syslog 配置

两个服务的配置文件都有很多内容,在此只展示其中部分重要的参数,先看一下 /etc/systemd/journald.conf

1
2
3
4
5
6
7
8
[Journal]
Storage=persistent #开启持久化存储
#Compress=yes #开启压缩功能
#Seal=yes
SystemMaxUse=40% #设置系统最大占用率为40%
StorageOption=size #设置存储选项为按大小进行存储
StorageOption=autorotate #设置存储选项为自动轮换
StoragePath=/export/log/journal #设置日志文件的存储路径

再看一下 /etc/rsyslog.conf 配置文件

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
# Include all config files in /etc/rsyslog.d/
$IncludeConfig /etc/rsyslog.d/*.conf #将包含 `/etc/rsyslog.d/` 目录下的所有以 `.conf` 结尾的配置文件,可以将配置分散到多个文件使得管理更加灵活

# Turn off message reception via local log socket;
# local messages are retrieved through imjournal now.
$OmitLocalLogging on #不再通过本地日志套接字接收消息,本地消息现在通过 `imjournal`(Journal 日志服务)来检索


#### RULES ####

# Log all kernel messages to the console.
# Logging much else clutters up the screen.
#kern.* /dev/console

# Log anything (except mail) of level info or higher.
# Don't log private authentication messages!
*.info;mail.none;authpriv.none;cron.none /var/log/messages #将所有信息级别(info)以及除了邮件、认证、和 cron 之外的其他日志,都记录到 `/var/log/messages` 文件中

# The authpriv file has restricted access.
authpriv.* /var/log/secure #将所有 authpriv(私密认证)级别的日志记录到 `/var/log/secure` 文件中

# Log all the mail messages in one place.
mail.* -/var/log/maillog #将所有邮件相关的日志记录到 `/var/log/maillog` 文件中


# Log cron stuff
cron.* /var/log/cron #将所有 cron 服务相关的日志记录到 `/var/log/cron` 文件中

# Everybody gets emergency messages
*.emerg :omusrmsg:* #将所有紧急级别(emergency)的日志消息发送到用户消息队列

# Save news errors of level crit and higher in a special file.
uucp,news.crit /var/log/spooler #将所有 uucp 和 news 的 crit 级别及更高级别的日志记录到 `/var/log/spooler` 文件中

# Save boot messages also to boot.log
local7.* /var/log/boot.log #表示保存启动消息到boot.log文件中

使用journalctl查看和管理日志

查看日志

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
# 查看所有日志(默认情况下只保存本次启动的日志)
$ sudo journalctl

# 显示尾部指定行数的日志,默认10行
$ sudo journalctl -n 20

# 实时滚动显示最新日志
$ sudo journalctl -f

# 查看指定时间的日志
$ sudo journalctl --since yesterday
$ sudo journalctl --since="2023-12-22 16:52:18"
$ sudo journalctl --since "30 min ago"
$ sudo journalctl --since "2023-12-22 16:52:18" --until "2023-12-22 23:52:18"
$ sudo journalctl --since 09:00 --until "1 hour ago"

# 查看内核日志,过滤掉应用日志
$ sudo journalctl -k

# 查看系统本次启动的日志
$ sudo journalctl -b
$ sudo journalctl -b -0

# 查看上一次启动的日志
$ sudo journalctl -b -1

# 查看指定优先级及其以上级别的日志,共有8级 0: emerg 1: alert 2: crit 3: err 4: warning 5: notice 6: info 7: debug
# -b 不加任何参数时,表示显示当前引导周期的日志。这意味着只显示自最近一次启动以来的日志。
# -b N: N 是一个整数,表示要显示第 N 个引导周期的日志。例如,-b 0 表示显示最新的引导周期,-b 1 表示显示上一个引导周期,以此类推
$ sudo journalctl -p err -b

# 日志默认分页输出,--no-pager 改为正常的标准输出
$ sudo journalctl --no-pager

# 以单行 JSON 格式输出
$ sudo journalctl -b -u nginx.service -o json

# 以多行 JSON 可读性更好的格式输出
$ sudo journalctl -b -u nginx.service -o json-pretty

查看指定服务日志

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20

# 查看指定服务的日志
$ sudo journalctl /usr/sbin/sshd

# 查看指定进程的日志
$ sudo journalctl _PID=1

# 查看某个路径的脚本的日志
$ sudo journalctl /bin/bash

# 查看指定用户的日志
$ sudo journalctl _UID=1000 --since today

# 查看某个 Unit 的日志
# 单元(unit)通常是 systemd 服务的一个抽象,用于表示系统中正在运行的各种服务或任务
$ sudo journalctl -u nginx.service
$ sudo journalctl -u nginx.service --since today

# 合并显示多个 Unit 的日志
$ journalctl -u nginx.service -u ssh.service --since today

查看调整存储

1
2
3
4
5
6
7
8
9
10
11
12
13
14
# 显示日志占据的硬盘空间
$ sudo journalctl --disk-usage

# 仅保留500MB大小的日志文减
$ sudo journalctl --vacuum-size=500M

# 指定日志文件保存多久
$ sudo journalctl --vacuum-time=1years

# 仅保留最近一个月的日志文件
$ sudo journalctl --vacuum-time=1m

# 仅保留最近2天的日志文件
$ sudo journalctl --vacuum-time=2d

回到文章开头的问题

通过梳理知识,我发现通过 systemctl 命令查询 systemd-journald 服务状态可以看到日志存储路径和存储限制,分别展示一下,先看存储到内存的:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
root@demo1:~# systemctl status systemd-journald
● systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static; vendor preset: enabled)
Active: active (running) since Fri 2023-12-22 10:25:43 CST; 10h ago
Docs: man:systemd-journald.service(8)
man:journald.conf(5)
Main PID: 1132 (systemd-journal)
Status: "Processing requests..."
Tasks: 1
Memory: 272.0K
CPU: 204ms
CGroup: /system.slice/systemd-journald.service
└─1132 /lib/systemd/systemd-journald

Dec 22 10:25:43 demo1 systemd-journald[1132]: Runtime journal (/run/log/journal/) is 8.0M, max 159.9M, 151.9M free.
Dec 22 10:25:43 demo1 systemd-journald[1132]: Journal started
root@demo1:~# df -h
Filesystem Size Used Avail Use% Mounted on
udev 7.8G 0 7.8G 0% /dev
tmpfs 1.6G 9.3M 1.6G 1% /run
/dev/sda1 83G 29G 51G 36% /
tmpfs 7.9G 0 7.9G 0% /dev/shm
tmpfs 5.0M 0 5.0M 0% /run/lock
tmpfs 7.9G 0 7.9G 0% /sys/fs/cgroup
/dev/sdb 1017G 903G 115G 89% /export
tmpfs 1.6G 0 1.6G 0% /run/user/111
tmpfs 1.6G 0 1.6G 0% /run/user/1001

默认存储到 /run/log/journal/中,分区一共1.6G,最大max 159.9M,当前用了 8.0M,按这个来推算果然限制是10%,再看看持久化的情况

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
root@jenkins2004:~# systemctl status systemd-journald
● systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static; vendor preset: enabled)
Active: active (running) since Sun 2023-08-27 09:24:15 CST; 3 months 26 days ago
TriggeredBy: ● systemd-journald-dev-log.socket
● systemd-journald.socket
● systemd-journald-audit.socket
Docs: man:systemd-journald.service(8)
man:journald.conf(5)
Main PID: 375 (systemd-journal)
Status: "Processing requests..."
Tasks: 1 (limit: 19123)
Memory: 42.7M
CGroup: /system.slice/systemd-journald.service
└─375 /lib/systemd/systemd-journald

8月 27 09:24:15 jenkins2004 systemd-journald[375]: Journal started
8月 27 09:24:15 jenkins2004 systemd-journald[375]: Time spent on flushing to /var/log/journal/cc9ad539032546a1bd39a773d37e415f is 613.827ms for 1229 entries.
8月 27 09:24:15 jenkins2004 systemd-journald[375]: System Journal (/var/log/journal/cc9ad539032546a1bd39a773d37e415f) is 1.4G, max 4.0G, 2.5G free.
8月 27 09:24:22 jenkins2004 systemd-journald[375]: Forwarding to syslog missed 1 messages.
8月 27 09:24:53 jenkins2004 systemd-journald[375]: Forwarding to syslog missed 80 messages.
Warning: journal has been rotated since unit was started, output may be incomplete.
root@jenkins2004:~# df -h | grep -v snap
Filesystem Size Used Avail Use% Mounted on
udev 7.8G 0 7.8G 0% /dev
tmpfs 1.6G 1.6M 1.6G 1% /run
/dev/sda5 590G 369G 191G 66% /
tmpfs 7.9G 0 7.9G 0% /dev/shm
tmpfs 5.0M 0 5.0M 0% /run/lock
tmpfs 7.9G 0 7.9G 0% /sys/fs/cgroup
/dev/sda1 511M 4.0K 511M 1% /boot/efi
tmpfs 1.6G 36K 1.6G 1% /run/user/125
tmpfs 1.6G 4.0K 1.6G 1% /run/user/1002

看起来存到了 var/log/journal,最大可用空间居然到了4G,这样来分析这次的问题可能不是journal日志搞的鬼,而是很多进程吧/run目录写满了,导致journal写不进去报了开头的错误,进而引发的无法登录。

总结

  • syslog和journal在日志管理中各司其职,共同保障了Linux系统日志的完整性和可用性
  • journal默认将系统日志存储在/run/log/journal目录中,而 /run 通常挂载在内存中,当此目录被写满时可能导致ssh无法登录
  • /etc/systemd/journald.conf 配置中的 Storage 字段设置为 persistent 可以开启日志持久化
  • sudo journalctl -n 20 可以显示显示尾部最新的20行日志,-n后不加参数默认10行
  • sudo journalctl -u nginx.service 查看ssh服务器的日志
  • sudo journalctl --since="2023-12-22 16:52:18" 查看指定时间以后的日志

==>> 反爬链接,请勿点击,原地爆炸,概不负责!<<==

寒意一波接着一波,总会有看见“光”的时候(30厘米的下跌,摔得可真疼)

Albert Shi wechat
欢迎您扫一扫上面的微信公众号,订阅我的博客