一、「重启就好了」——一个会自己站起来的服务器

这台服务器每隔几天就要演一次同样的戏。我挂在上面的几个站点全打不开,SSH 也连不进去,看起来像是彻底死了。然后重启一下,它立刻活过来,跟什么都没发生过一样。前几次我都是这么收场的,处理完就关掉终端去干别的。

一开始我以为只是运气不好,撞上了点平台侧的抖动。后来发现不是——它白天晚上都来过,而且从来不会自己回去,每次都得我动手。

症状里有个很扎眼的细节:网站进不去、SSH 连不上,可 ping 是通的。它听得见我敲门,就是不肯开门。能 ping 通只证明它还有一口气,至于为什么门打不开,它一个字都不肯说。

这次我决定不再只是重启,先把最可能的原因排掉。先排的是网络,这是所有「连不上」的标准起手式:

ping -n 8 101.133.128.193
Reply from 101.133.128.193: bytes=32 time=37ms TTL=50
Packets: Sent = 8, Received = 8, Lost = 0 (0% loss)
Average = 36ms

八发八中,平均 36 ms,0 丢包。网络这条路干干净净,一点毛病都没有。

网络排完,接着排攻击。这台机器公网 IP 直接挂在外网,SSH 端口天天有人扫,出现这种症状时我第一个念头就是「有人在爆破我」。

sudo fail2ban-client status sshd
Currently failed: 0
Total failed:     0
Currently banned: 0
Banned IP list:   (空)

全是 0。我不放心,又把整份 /var/log/auth.log 从头到尾扫了一遍,Failed password 一共只出现过 1 次。这个量级,连一次像样的爆破都算不上。

不是网络,也不是被攻击。那答案只能在这台机器自己身上。我先把它的家底交代清楚。

2 核 CPU,1.6 GiB 内存(/proc/meminfo 里 MemTotal: 1651676 kB),40 GB 磁盘(/dev/vda3,ext4),Swap 是 0——swapon --show 什么都不输出。

1.6 GiB 内存上,常住着 9 个 Docker 容器:sub2api、redis、2fauth(二次验证)、bitwarden(密码库)、gitea(代码仓库)、openresty、postgresql、frps、frps-nas(通到家里的隧道)。此外还有 1Panel 的 agent 和 core、fail2ban、阿里云云盾(AliYunDun、AliYunDunMonitor)、云监控 argusagent,以及两个 Gitea 实例——一个跑在容器里,另一个是裸进程,/usr/local/bin/gitea web。

用一句话形容这台机器的居住条件:一间单人宿舍塞了九张床,过道里还站着几个没床位的。

很挤。但「挤」本身不解释它为什么连门都打不开。于是我打开了重启历史。

last -x
时间内核版本备注
9/26 01:306.8.0-142本次重启
9/23 22:346.8.0-139内核没变
9/19 19:146.8.0-139内核没变
9/18 21:456.8.0-139内核没变
9/18 21:436.8.0-139内核没变
9/7 17:026.8.0-139内核升级
9/7 17:006.8.0-139内核升级
8/26 17:486.8.0-138内核升级
8/21 18:536.8.0-138内核升级

表上九行,最早一行是 8/21 18:53。前几次备注写着内核升级,那是我自己动手的;剩下的,才是我说的那种倒下。

重启的次数不是重点,重点在内核版本那一列。8/21 和 8/26 是 6.8.0-138,9/7 那两次升到了 6.8.0-139。再往后,9/18 连着两次、9/19 一次、9/23 一次,四次重启的内核全是 6.8.0-139,一次都没换过。

如果这四次是我为了升级系统主动做的,版本号至少该动一次。它一次都没动。也就是说,它们不是我干的——是它自己倒下的,然后被扶起来。

9/18 那天还有两行,21:43 和 21:45,中间只隔了两分钟。两分钟这个间隔,比故障本身更让我不舒服。它意味着第一次重启根本没解决问题,机器只是站起来,然后立刻又倒下去。而我当时在客户端那头看到的,只是「又连不上了」,于是习惯性地重启第二次。

至于原因,我当时没往下追。反正重启一下就回来了,回来了就跟没事一样,机器不吵不闹,谁会没事去找一个已经消失的故障。这是我那段时间对这件事的全部判断:它为什么倒下我还没弄清,我只知道重启一下就好了。

二、CPU 曲线骗了我:91% 空闲的 CPU

那我总得看点东西。一台机器卡到网站都打不开,最直白的嫌疑犯就是 CPU,我先去翻了阿里云控制台。

控制台上那条曲线,从 20% 一路爬到 70%。放在一台 2 核 1.6 GiB 的机器上,这个画面太好解释了:9 个 Docker 容器,加上 1Panel 的 agent、fail2ban、阿里云云盾、云监控,全都挤在两个核上。它跑不动了,就这么简单。

它说服力强的地方在于时间线对得上。曲线往上爬的那一段,正好就是网站开始打不开、SSH 开始挤不进来的那一段。一个指标涨了,症状跟着来了,我很难不先怀疑它。

我一度以为是机器太小,甚至开始盘算要不要升配。

但曲线这东西,就像一支体温计:数字确实高,可它不会告诉你这数字是算出来的,还是等出来的。它只知道 CPU「忙」,不知道这份忙里有多少是在算,有多少是在等。这个判断我不敢直接采信,先登上去看一眼。

top -bn1 打一行快照,比盯着曲线实在得多。

top -bn1
%Cpu(s):  0.0 us,  4.3 sy,  0.0 ni, 91.3 id,  4.3 wa,  0.0 hi,  0.0 si,  0.0 st

这一行得拆开念:us 是用户态,程序自己在算的时间;sy 是内核态,内核替程序干活的时间;id 是彻底空闲,什么都没干;wa 是 CPU 闲着,但闲的原因不是在休息,是在等磁盘。四个数加在一起,差不多就是一整个 CPU。

读出来的结果是这样的:us 0.0,id 91.3。这台机器有 91.3% 的时间在彻底空闲。它根本没在算。

控制台那条曲线说的是 70%,这里说的是 91.3% 空闲。两个数不矛盾,它们量的是不同的东西——曲线量「CPU 有多忙」,top 量「CPU 里有多少活是真的在干」。决定卡不卡的,是后面那个。

后来我给自己定了个规矩:看到 CPU 高,先把 us 和 wa 分开看。us 高是真的算不过来,该优化代码、该加机器;wa 高是机器在原地等,核数加上去也白搭。这次要是照着曲线去升配,钱花了,问题一点没动。

那卡顿是从哪来的。sar 把崩溃那段的 CPU 分解摊开以后,答案就摆在表里。

时刻%user%system%iowait%idle
00:303.753.330.1692.74
00:403.495.3515.6375.52
00:507.6615.4276.920.00
01:006.5615.2378.210.00
01:1120.3718.0861.550.01
01:2111.1316.4872.390.00

从 00:30 的 0.16%,到 00:50 的 76.92%,%iowait 一口气爬满了整张表,同时 %idle 直接归零。CPU 一点空余都没有了,可它不是忙着算,是忙着等磁盘。整张表里 %user 最高也没超过 20.37。

%iowait 的口径是这样的:CPU 发出一次读盘请求,然后只能停下来等结果。等待的这段时间它什么也没算,可也不算空闲,被单独记在 wa 那一栏。所以这个数涨起来,说明 CPU 的时间不是花在计算上,是花在等磁盘回话上。

曲线上的忙不是在算,是在等。而 91.3% 的空闲,只说明它没在算。

我以为自己已经想通了:算力不够是假象,真凶是磁盘。但有个地方对不上——如果它正被磁盘拖着,我登上来的这一下怎么会这么清闲。

于是顺手敲了 uptime。

uptime
01:32:57 up 2 min,  2 users,  load average: 2.11, 1.10, 0.44

up 2 min。不是两小时,不是两天,是两分钟。这台机器刚刚重启过。

我原本以为这是个偶发问题,实际上是它刚刚死过一次。

那我看到的一切——91.3% 的空闲、刚归零的负载、干净的进程列表——都不是现场,是尸体。崩溃那一晚的数据,早就跟着重启一起消失了。

这件事的麻烦在于,机器把自己的现场打扫得很干净。ps 列出来的是一份重启后的、健康的进程表;/proc/<pid>/io 里每个进程的 IO 计数也是从零开始的。我想找的那个东西,连名字都没留下。

top、ps、/proc/<pid>/io,这些工具都只能看「此刻」。而此刻是重启后的此刻,最该被抓住的那个进程已经不在了。我当时最难受的就是这里:机器明明刚刚死过一次,我却只能看着它若无其事地呼吸。

好在 Ubuntu 默认装了 sysstat。它把「只能看此刻」这个限制撬开了一条缝。这是个后台采样器,每 10 分钟醒一次,把当时的 CPU、内存、磁盘、负载各抄一份,写进 /var/log/sysstat/。文件按天编号,sa26 就是 26 号那一份。

sar -q -f /var/log/sysstat/sa26   # 负载
sar -r -f /var/log/sysstat/sa26   # 内存
sar -b -f /var/log/sysstat/sa26   # 磁盘 IO
sar -u -f /var/log/sysstat/sa26   # CPU 分解
sar -d -p -f /var/log/sysstat/sa26  # 每设备

五个 -f 指向的都是同一天的历史采样,只是拆的维度不一样。采样一直在后台写,代价小到可以忽略,只是平时没人会想起来去看它们。

那一晚到底发生了什么,它都记着。

三、那 40 分钟:磁盘被来回读了十几遍

回放到 01:21 那一行的时候,我把手从键盘上拿开了。load average 53.49,blocked 58。这台机器只有 2 核,平时 load 在 1 附近晃。

同一行的 vda %util 是 97.33%,aqu-sz 是 256.13,await 是 110.89 ms。这三个数字不是我挑出来的,是那四十分钟里一路从基线顶上来的。

那张表是把刚才那几条回放并起来读的——-q 给负载和阻塞进程数,-b 给整体吞吐,-d -p 拆到每一块设备。

并出来的结果六行,每十分钟一行:

时刻load-1%iowait读/写 req读带宽awaitaqu-szvda %utilblocked
00:300.130.16%28 / 171.5 MB/s0.47 ms0.020.5%0
00:4025.9115.63%509 / 1757 MB/s80.58 ms42.4217.71%31
00:5037.6476.92%2306 / 6约 140 MB/s109.46 ms253.0496.29%29
01:0037.1178.21%2288 / 4约 140 MB/s111.64 ms255.8197.24%42
01:1142.4861.55%2307 / 6约 140 MB/s110.55 ms255.6696.61%31
01:2153.4972.39%2307 / 3约 140 MB/s110.89 ms256.1397.33%58

读 / 写 req 是每秒的读请求数与写请求数;两者相加约等于总 IOPS,个别行因 sar 取整会差 1。

00:30 那行是基线:%util 0.5%,await 0.47 ms,aqu-sz 0.02,磁盘这时候基本是闲的。十分钟后 %util 到 17.71%,再过十分钟 96.29%,之后就再没下过 96%。

00:40 那行值得多看两眼:%util 才 17.71%,磁盘远没满,load 已经 25.91,blocked 已经 31。排队这件事,比磁盘彻底堵死来得更早。

先看 %util。它量的是这块盘有多少比例的时间在处理 IO。97.33% 就是整整一分钟里,磁盘几乎没有一刻是空的。

你可以把它想成一条单车道公路,被一辆开得极慢的车占住了。后面的车不是走不动,是根本没轮到自己。aqu-sz 256.13 就是还在路上等着的车数,从 0.02 涨到 256,队尾早排出了这个路口。blocked 58 是坐在车里干等、别的什么都干不了的进程数。

await 那条线更直白:从 0.47 ms 到 111.64 ms,单次 IO 的等待时间慢了约 236 倍。原来一毫秒能来回几十趟,现在等一趟要 110 毫秒。

真正让我确定这不是抖动的,是 rtps 和 wtps 这两个数。前者是每秒读请求数,后者是每秒写请求数。风暴起来之后,rtps 一直卡在 2306 到 2310,wtps 在 3 到 6 之间。

2306 对 3。这就是纯读风暴的指纹。系统一般忙起来,读写会一起抬头;随机抖动也不会把速率压得这么平。而这四十分钟里,有东西在稳定地、只读地啃这块盘,几乎一个字节都不写。单次请求平均约 62 KB(areq-sz 62.00),乘上 2306 次,量级也落在 140 MB/s 上。

这个「约 140 MB/s」,我差点写错。

sar -b 那次回放里,9/26 的峰值是 bread/s = 287091。第一眼扫过去,我差点照着这个数直接把它报成 MB/s。差得远。bread/s 数的不是字节,是块,单位 512 字节,得乘一下才知道真实吞吐:287091 × 512 = 146.9 MB/s,约 140 MB/s。

单位是会骗人的。同一串数字,你当它是字节,那是几百 KB/s 的毛毛雨;你当它是兆字节,那已经不是一块盘的速度了。只有按 512 字节一块去算,它才落回这块盘该有的量级。看 sar 这类老工具的输出,先弄清楚那一列的单位,比看数字本身重要。

再算总账。约 140 MB/s 乘 40 分钟,大概 330 GB。而这块盘上一共只用了 19 GB。

330 除以 19,十几倍。那四十分钟里,磁盘上的数据被从头到尾翻了十几遍。这不是「有点忙」的量级。

磁盘这边,坏到头了。可四十分钟的满速读,账不会只记在磁盘上。

四、内存被拖下水,然后系统就出不来了

同一份 sa26,把参数换成 -r 再看一遍,内存掉得比磁盘还难看。

要看的还是 sar:

sar -r -f /var/log/sysstat/sa26

它给三个数。kbavail 是这台机器此刻还能用的内存,kbmemfree 是彻底没人要的空闲内存,kbcached 是页缓存——内核替磁盘攒下来的那份底子。

时刻kbavail(可用)kbcached(页缓存)kbmemfree
00:30485 MB617 MB120 MB
00:40207 MB368 MB80 MB
00:50227 MB347 MB97 MB
01:21207 MB317 MB84 MB

第一行是风暴前的样子:可用 485 MB,页缓存 617 MB。到最后一行 01:21,可用 207 MB,页缓存 317 MB。

被打掉的是页缓存那一列。617 掉到 317,少了将近一半。这一列是三个数里最不该动的一个。

页缓存是内核手里最好使的一张牌。你刚读过的文件,它顺手留在内存里;下次再要,直接从内存拿,不用碰盘。机器闲下来的时间越多,这张牌就攒得越大,617 MB 是这台机器平时一点点攒出来的家底。

拿桌面打个比方。页缓存就是你摊在桌面上的文件,用的时候伸手就能拿,不用跑去柜子里翻。这台机器 swapon --show 一条输出都没有,等于这张桌子压根没有抽屉。桌面一旦挤了,你没法把东西收进抽屉,能做的只有撕。

撕掉的那一下不疼,疼在后面。缓存空了,进程每次启动都得从头读盘——而这块盘此刻 %util 是 97.33%,正被那个东西满速啃着。

圈就这么闭上了。读盘越吃力,内存就越紧;内存越紧,内核就越要丢缓存;缓存丢得越多,进程就越依赖读盘。

这四十分钟里,这个圈转了很多轮,每一轮都比上一轮更紧。它之所以出不来,不在于某一次故障没被处理,而在于每一次处理都让下一次更重。

没有 Swap 的机器缺的不是容量,是缓冲垫。

内存见底的时候,系统自己会喊。那段时间 journald 记了 232 次同一句话:

systemd-journald: Under memory pressure, flushing caches.
systemd-resolved: Under memory pressure, flushing caches.

232 次,systemd-journald 和 systemd-resolved 轮着来,喊的都是同一件事。这是内存压力落在日志里最直白的指纹。

喊完之后,服务开始一个个倒:

00:44:41  user@1000.service: State 'stop-sigterm' timed out. Killing.
00:44:41  user@1000.service: Main process exited, code=killed, status=9/KILL
00:49:37  fwupd-refresh.service: start operation timed out. Terminating.
00:49:47  Failed to start fwupd-refresh.service

用户会话这一行,是让进程停,它连收到信号都来不及,最后被 KILL 掉。fwupd-refresh 更干脆,起都起不来。这些是内存不够落在进程层面的样子。

这里面最扎眼的一条,是我自己。

00:41~01:26  sshd[xxxxx]: fatal: userauth_pubkey: send packet: Connection reset by peer

从 00:41 到 01:26,每 1 到 2 分钟一次。那不是别人,是我手上这个终端。命令敲到一半,窗口断掉,重新连,再断。

那种感觉很难形容。我在排查一台正在把我赶出门的服务器。它连让我把一条命令敲完的余力都没有。

顺手 ping 一下是通的——八发八中,平均 36 ms,0 丢包。网一点问题都没有。是这台机器没空理我。

01:30,它最后不响了。

01:30:22  System Journal (/var/log/journal/…) is 3.8G, max 3.9G, 26.0M free.
01:30:23  File /var/log/journal/…/system.journal corrupted or uncleanly shut down, renaming and replacing.
01:30:37  Time jumped backwards, rotating.

中间那行的 uncleanly shut down,是内核给的判词:这个日志文件不是被正常关掉的。

这句话不是随口一写,它有判据。

正常关机的时候,系统会往 last -x 里留一条 shutdown system down。8/18 20:27:35 那次就有——那条记录相当于走之前打了个招呼。9/26 这一次,last -x 从头翻到尾,没有这条。

所以它不是被关掉的,是倒下的。硬崩溃,然后被平台强制重启。

一台 1.6 GiB 的机器为什么会走到这一步,还差一个解释。

for f in overcommit_memory overcommit_ratio swappiness dirty_ratio min_free_kbytes; do
  printf "%-20s %s\n" "$f" "$(cat /proc/sys/vm/$f)"; done
overcommit_memory        0
overcommit_ratio         50
swappiness               0
dirty_ratio              30
min_free_kbytes          45056

再看内核记账的那两个数:

grep -E "MemTotal|CommitLimit|Committed_AS" /proc/meminfo
MemTotal:        1651676 kB
CommitLimit:      825836 kB
Committed_AS:    5063648 kB

CommitLimit 是 825,836 kB,内核愿意许出去的内存承诺上限。Committed_AS 是 5,063,648 kB,约 4.83 GB,已经许出去了。实际承诺是上限的 613%。

翻成大白话:这台机器一共敢答应 825 MB,可它对进程已经答应了 4.83 GB——账面上早就透支了。

swappiness 那一栏是 0。

这事能发生,是因为容器那头不封顶。docker inspect 挨个看过去:

/sub2api     mem=0
/redis       mem=0
/2fauth      mem=0
/bitwarden   mem=0
/gitea       mem=536870912
/openresty   mem=0
/postgresq   mem=536870912
/frps        mem=0
/frps-nas    mem=0

9 个容器里 7 个 mem=0,没有任何上限。只有 gitea 和 postgresql 各限了 512 MB。

其余 7 个跑在 1.6 GiB、没有 Swap 的机器上,谁都能要,谁都不封顶。上面那个 613%,就是这么攒出来的。

而且这不是头一回。拿 sar -b 把手头所有日期都扫一遍,bread/s > 20000 的时段一共三次:

sar -b -f /var/log/sysstat/sa<日>
日期磁盘读峰值之后的动作
9/18 19:50 → 21:4133 →约 114 MB/s21:43、21:45连续重启两次
9/23 18:50 → 22:3034 →约 140 MB/s22:34 重启
9/26 00:40 → 01:2157 →约 140 MB/s01:30 硬崩溃 + 重启

三次大风暴,三次都在一小时之内跟着一次重启。这个对应没有例外。

光看这三次还不够,得看那些没闹出事的。28 到 42 MB/s 的中等波动几乎天天都有,大多落在 06:14,是 apt-daily-upgrade 在干活。它天天来,机器天天没事。

所以界线不在有没有读风暴,而在有多猛。28 到 42 MB/s 是日常的量级,100 MB/s 以上是另一个量级。这三次都过了 100,前两次落在 114 到 140。

临界点大概就在 100 MB/s 这条线上。

还有一件事顺便排掉了。三次风暴的起始时刻是 19:50、18:50、00:40,对不上。如果背后是某个定时任务,这三次应该落在同一个钟点上。它没落。

所以它不是排期排出来的。

内存这条线写完了,账还没全平。01:30:22 那行里还留着一个数字:系统日志 3.8G,上限 3.9G,余量只剩 26.0M。

一台 40 GB 的机器,一份日志把自己撑到了贴着限额。我当时扫过去就放下了,没顺着它往下追。

五、139 万行日志,和一个每 16 秒敲一次门的人

先给 /var/log 称个重量。

sudo du -sh /var/log
4.3G    /var/log

4.3 G。这台机器的系统盘是 40 GB,已经用掉 19 GB 了,日志一个人吃掉两成多。这个数字不对劲,Ubuntu 自己会做日志轮转,/var/log 平时不该长成这样。

日志这东西不挑食,什么都会往里写。我想知道这 4.3 G 到底是谁写的,就把 syslog 按程序来源排了个序。

awk '{print $3}' /var/log/syslog | sed 's/\[.*//' | sort | uniq -c | sort -rn
1390678  systemd          ← 一个进程写了 139 万行
   6121  1panel-agent
   1586  kernel:
   1039  CRON
    648  1panel-core
    468  systemd-resolved
    276  dbus-daemon

第一名 1,390,678,第二名 6121。第二名连它的零头都够不上。整份文件 99% 的行数,出自 systemd 一个进程。

这本身就是条线索。不是一个程序在干活、别的在旁边帮腔,是一个程序在把同一句话重复了一百多万遍。

systemd 是那套管开机、管服务、管登录的底层系统。它话多不奇怪,多到这个地步就很奇怪了。它到底在念叨什么,光看统计看不出来,得蹲一次现场。

auth.log 是记登录的那本账。我用 tail 挂在它后面,等它自己往外冒。-n 0 的意思是先把已有的内容全部跳过,只给我看新发生的。

sudo tail -n 0 -f /var/log/auth.log
01:40:37.321  Accepted publickey for admin from 223.90.24.107 port 61923
01:40:37.324  pam_unix(sshd:session): session opened for user admin
01:40:37.332  systemd-logind: New session 69 of user admin.
01:40:37.654  Received disconnect from 223.90.24.107 port 61923:11: disconnected by user
01:40:37.666  systemd-logind: Removed session 69.

盯了 15 秒,就这么一次登录。我把第一行和最后一行的时间戳相减:01:40:37.666 减 01:40:37.321,345 毫秒。

一个真人 SSH 上来干活,不可能 345 毫秒内把事办完再走。真人登录要敲命令,要看输出,要停一下。这一次连上、认证、立刻断开,中间没有任何一条命令。这不是有人在用我的机器,是有个程序在打卡。

那五行我来回看了几遍,越看越确定:它只是把门推开,又关上。

那它多久来一次。按小时统计 Accepted 的行数:

awk '/Accepted/ {print substr($1,1,13)}' /var/log/auth.log | sort | uniq -c
222  2026-09-25T06
190  2026-09-25T07
…
230  2026-09-25T23

每小时 190 到 230 次,一天不落。再往前翻,从 9/13 起这个节奏就没断过。一小时 3600 秒,摊到两百来次上,差不多就是每 16 秒一趟。

现在能给它画个像了:有人每隔 16 秒来敲一次门,敲完就走,但每敲一次就在门口留一张便条。便条越攒越高,就是那 139 万行。

敲门的是谁。我把来源 IP 排了个序:

24054  Accepted publickey for admin from 223.90.24.41
19321  Accepted publickey for admin from 223.90.24.64
 3572  Accepted publickey for admin from 223.90.24.107
    2  Accepted publickey for root from 127.0.0.1

全是 223.90.24.x。这几个地址我不陌生,是家里那条宽带的出口 IP。

我前半天一直在防外面的人。fail2ban 里干干净净,整份日志的 Failed password 只有一次,我还挺得意。结果站在门外的不是谁,是我自己家。127.0.0.1 上那 2 次 root 登录是我自己的,剩下四万多次,全从我家那条宽带里出来。

前面那些防爆破的功夫,防的是一个基本没露过面的外部对手。

这里有件事得说清楚:auth.log 只记来源 IP,不记客户端跑了什么命令。所以我只能确定它从家里来,确定不了它是哪个程序。服务端反推不出客户端是谁,这个得回家里那台机器上自己查。

账还没算完。我把会话的两个数拉出来对了一下:session opened 50,862 次,session closed 只有 39,925 次。差出来的这部分,是 22% 的会话没来得及正常关闭。正常断开是会在日志里留一条 session closed 的,没留下来的,多半是连接断得连收尾都没走完。

一次登录要走完整流程——认证、开会话、写日志、关会话,一趟下来大约 25 行。50,862 乘 25,127 万行。跟 syslog 里 systemd 那 139 万行,对上了。

两个完全独立的统计口径,算出来落在同一个量级,那 139 万行就不再是个孤零零的怪数字了。

再换个角度验一次。抽最近 20 万行看来源画像:

journalctl -n 200000 -o short | awk '{print $5}'
161702 systemd        ← 80.9%
 17383 sshd
 10426 systemd-logind
  2837 (systemd)
  2304 1panel-agent
  1574 (sd-pam)
  1217 sudo
   672 kernel:

systemd 一家 161,702 行,占 80.9%。再加上 sshd、systemd-logind、(systemd)、(sd-pam)、sudo,凡是跟登录会话沾边的,合计约 89%。20 万行里能挤进前八的,除了 1Panel 的 agent,剩下的全在登录这条链上。这台机器日夜不停写的,几乎只有「有人登录了」这一件事。

事情看着已经讲完了:家里一个程序每 16 秒登录一次,systemd 老老实实把每一次都记下来,记出了 139 万行。

但日志还有一块对不上。

journalctl 自己算的账是这样:

journalctl --disk-usage
Archived and active journals take up 2.4G in the file system.

du 量出来的账是这样:

sudo du -sh /var/log/journal
3.9G    /var/log/journal

2.4 G 对 3.9 G,差了 1.5 G。

两个工具量同一堆文件,给出两个数,这种时候我第一反应是自己路径敲错了。路径没错,是它们数的范围不一样。

差额藏在哪里:

sudo find /var/log/journal -type f -name "*.journal*" -printf "%s %p\n" | sort -rn | head
83886080  /var/log/journal/27464bd7…/user-1000@e2ad27cb…-00065ac9dd273d1c.journal
83886080  /var/log/journal/27464bd7…/user-1000@e2ad27cb…-00065ac0f95af15a.journal
83886080  /var/log/journal/27464bd7…/user-1000@e2ad27cb…-00065ab7d5999c7b.journal
…(还有更多,每个正好 83886080 字节 = 80 MiB)

user-1000@ 开头的一摞文件,每一个都正好 83,886,080 字节,也就是 80 MiB。

那个 1000 是 admin 的 UID。这些不是系统日志,是用户级日志。

机制是这样的:每次有人 SSH 登录,systemd 会给这个用户拉起一个独立的用户实例,实例一起来就建一个自己的 journal 文件,默认封顶 80 MiB。我这边每 16 秒登录一次,那边就每 16 秒新开一个 80 MiB 的文件。一晚上下来就是一摞。

这套用户实例是给多用户的服务器准备的,让每个人有自己的服务入口和日志空间。放在这台只有一个管理员的机器上,它正好被那个 16 秒的循环喂成了一台不停新建文件的机器。

而 journalctl --disk-usage 默认只统计系统日志,用户日志它压根不看。它报 2.4 G,du 量到 3.9 G,差额就是这么来的——只数了自己管的那些,没数分出去的那一份,像数东西只数了客厅,没数储藏间。

顺带踩到一个坑:systemd 的 SystemMaxUse= 只管系统日志,管不住用户日志。我试过设 MaxUse= 和 MaxFileSize=,那些残留下来的用户日志文件照样是 80 MiB,一点没小。这两行配置对着用户日志喊,对方听不见。

139 万行查到这里,源头是自家那个每 16 秒来一趟的程序,放大器是每次登录都新开的 80 MiB 用户日志。

日志这头,到头了。它把窟窿捅得更大,但它不是挖第一个窟窿的人。真正让这台机器出不来的那件事在内存那一头——磁盘被读满的时候,它连一块能把东西先挪出去的地方都没有。要修,就得从这块地方入手。

六、给没有 Swap 的机器垫一块缓冲垫

缺的那块缓冲垫,得自己给它垫上。摆在面前的有两条路。

一条是在磁盘上加个 swapfile,一条是在内存里划一块压缩盘。我先试的是最老实的那条。

建文件、mkswap、swapon,几行命令,教科书上都这么写。但这次不行,因为瓶颈就是磁盘本身。swapfile 的每一次换出和换回都要落在这块盘上,而崩溃那四十分钟里,它的 %util 已经到了 97.33%。盘一点余量都没有了,再往上挂一个持续读写的文件,只会让它更早塌掉。

换成第二条:zram。它在内存里划一块压缩块设备,数据写进去先压,读出来再解,全程不碰磁盘。

这是个真空收纳袋——不常用的被子抽掉空气塞进床底,占的地方比原来小得多,拿出来还是那床被子。zram 压的就是内存里的匿名页,代价是按压缩后的体积占一点真实内存。

改之前,这台机器的 vm.swappiness 是 0。

这个值容易被读成「把 Swap 关掉」,它真正的语义是:尽量别把匿名页换出去,优先丢弃页缓存。

所以只装 zram、不动 swappiness,等于白装。机器多了一块能换出的空间,内核还是宁可丢缓存,也不用它。

zram 给的是「换出去的地方」,swappiness 决定的是「内核愿不愿意换」。这两件事得一起改,缺一个都不成立。

装得上去,也拆得下来。这条才是敢在生产机器上动手的前提。

实际改下来是五个文件,全部新增,现有文件一个都没动。日志那头也在里面——把它封个顶,再把会话那几类噪音丢掉:

  • /usr/local/sbin/zram-swap.sh——zram 管理脚本,幂等,可以反复执行
  • /etc/systemd/system/zram-swap.service——oneshot 单元,已 enabled,挂在 swap.target.wants 上,开机自动起
  • /etc/sysctl.d/99-zram.conf——vm.swappiness 从 0 改成 100,vm.page-cluster 从 3 改成 0
  • /etc/systemd/journald.conf.d/99-size.conf——SystemMaxUse=500M
  • /etc/rsyslog.d/10-drop-session-noise.conf——丢掉 systemd 和 systemd-logind 这两类会话日志

zram 参数是 ZRAM_SIZE_MB=800(大约 RAM 的一半)、ZRAM_ALGO=zstd、ZRAM_PRIO=100。page-cluster 是换页时一次预读几页,从 3 改成 0,是不想为了一个页把一整串都从 zram 里解出来。

journald 那份走的是 drop-in 目录,原文件 /etc/systemd/journald.conf 一个字没碰。这台机器上挂着四个站点,动手之前我先按时间戳 20260926-015121 把要碰的四份配置各备了一份:/etc/rsyslog.conf.bak-20260926-015121、/etc/systemd/journald.conf.bak-20260926-015121、/etc/rsyslog.d.bak-20260926-015121/、/etc/logrotate.d/rsyslog.bak-20260926-015121。

动手前先用 systemd-analyze verify 查单元依赖环、rsyslogd -N1 查配置语法、bash -n 查脚本语法。单元文件是整体重写,不是 sed -i 就地改;备份和改动分成两步执行。

这套习惯不是天生就有的。上个月我在同一台机器上用 sed -i 直接改过一个生产文件,栽了一次,之后才改成现在这样:先复制一份到安全的地方,再在副本上动手。

排查归排查,动手归动手,混着来最后分不清是病没好,还是自己添了新病。

效果当天就看得出来。

指标改前改后
IO 完全停滞率(/proc/pressure/io full avg60)36.75%0.2%
磁盘 tps / 读带宽2306 / 约 140 MB/s3~23 / 2 MB/s 以下
MemAvailable207 MB950 MB
MemFree73 MB249 MB
journal 体积3.9 G489 M
/var/log 总体积4.3 G915 M
磁盘占用19 G (50%)15 G (40%)
syslog 增速每次登录 +25 行40 秒新增 0 行
load average53.490.85
四个网站—全部 HTTP 200

第一行那个 io full avg60 是 PSI,内核自己记的压力指标。它量的东西很具体:过去一分钟里,有多少时间所有任务都被 IO 卡到完全推不动。36.75% 意味着三分之一以上的时间里,这台机器是真的不动了。它落到 0.2%,才算这台机器从「撑着」变成了「活着」。

那 800 M 的 zram 究竟花掉多少真实内存,zramctl 说得最清楚:

zramctl
NAME       ALGORITHM DISKSIZE   DATA COMPR TOTAL STREAMS MOUNTPOINT
/dev/zram0 zstd          800M 329.2M 57.6M 80.2M       2 [SWAP]

三个数各说各的。DISKSIZE 800M 是逻辑容量,内核眼里这块「盘」有多大;DATA 329.2M 是写进去的数据量,压完只剩 COMPR 57.6M;TOTAL 80.2M 才是它真正从物理内存里占走的量。

压缩比 5.7 : 1。写进去 329.2 M 的东西,实际掏了 80.2 M 内存就撑住了。这点挺反直觉——内核那边看着有 800 M 换页空间可用,物理侧只掏了 80 M 出头。

四个站点的外部实测一起回来了:blog.liuhangyv.top 0.725s、lhy-git.liuhangyv.top 0.283s、gitea.liuhangyv.top 0.247s、1panel.liuhangyv.top 0.251s,全部 200。

变化最大的是 buff/cache 那一栏。它稳定在 860 MB,不再被拿去救急。内核在内存压力下的取舍,从「把页缓存丢掉」换成了「把匿名页压起来」。那条正反馈的死循环,被从根上切断了。

回滚的路径在动手之前就写好了:

sudo systemctl disable --now zram-swap.service
sudo rm -f /usr/local/sbin/zram-swap.sh /etc/systemd/system/zram-swap.service
sudo rm -f /etc/sysctl.d/99-zram.conf && sudo sysctl -w vm.swappiness=0 vm.page-cluster=3
sudo systemctl daemon-reload
sudo rm -f /etc/systemd/journald.conf.d/99-size.conf /etc/rsyslog.d/10-drop-session-noise.conf
sudo systemctl restart systemd-journald rsyslog

有两件事我没解决,不打算糊过去。

第一件:那 140 MB/s 的读风暴是谁发起的,我还是没定位到。/proc/<pid>/io 只记实时值,不存历史,等我登上去,产生风暴的进程早跟着重启一起消失了。我能证明的只有行为特征——纯读、零写、单次请求约 62 KB、速率稳得不像话。

名字点不出来。但它是周期性的,下次再发作,一条命令就能当场点名:

sudo pidstat -d 2 30

pidstat 是挨着进程记 IO 的。它真跑起来那会儿,每 2 秒出一行,采 30 次,谁在啃盘,当场就有名字。

第二件:家里那个每 16 秒 SSH 登录一次的东西,我也查不到身份。auth.log 只记来源 IP,不记客户端进来之后跑了什么。能确定的只有它来自 223.90.24.x,自家的宽带。服务端不可能反推出客户端是哪个程序,只能回到客户端那一头自己找。是监控脚本,是 IDE 的远程连接,还是哪个在轮询的 bot,我在服务端这头看不见。

「重启一下就好了。」这句话我说了很久。它确实好了,只是重启从来不修任何东西,它只是把现场擦掉。

第一部分结尾我写过一句:「它为什么倒下我还没弄清,我只知道重启一下就好了。」到这儿,前半句只答了一半。答上的是机制:读风暴打满磁盘,内存被连带击穿,没有退路的内核只能丢缓存,丢完缓存又逼着进程回去读盘,转成一个出不来的圈。没答上的那一半,是圈的起点到底是谁。

所以这事没结束。我做了一件很小的事:把 sudo pidstat -d 2 30 存进笔记,标好用途。等它下次发作,我不急着重启了,先跑这条命令,把那个名字点出来。