拓十年匠心定制 · 商业建站与技术教学双线并行 咨询热线:400-886-1026 service@lmnt.cn
ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

Linux日志系统与故障排查:定位脚本长时间无输出的实战指南

Linux日志系统与故障排查:定位脚本长时间无输出的实战指南

1. 日志系统:先弄清楚日志到底写到了哪里

说到故障排查,我见过太多人第一步就错了。他们拿到一台出问题的服务器,第一反应是“这机器是不是坏了”,然后各种乱试命令,敲了一堆看着很专业的指令,最后问题没解决,还把现场给破坏了。真正靠谱的做法恰恰相反:先冷静下来,把日志系统摸透,让日志替你说话。

日志系统是整个Linux运维体系里最容易被忽视、却最值钱的基础设施。它本质上解决一个问题:当系统或程序出现异常时,你能不能按图索骥,找到“发生了什么、什么时候发生的、影响范围有多大”。很多人觉得日志就是几个文本文件,这没错,但它背后的机制远没有看起来那么简单——信号的传递、进程的状态、文件描述符的打开情况,这些信息都会在排查故障时跟日志互相印证。

1.1 日志系统的分层结构与核心文件

我习惯把Linux日志系统分成三层来看,这样的好处是排查时可以快速定位该去看哪一层。

第一层是内核日志。由内核自己维护,通过dmesg或/var/log/dmesg查看,记录的是硬件驱动、内存、文件系统等底层事件。比如服务器突然重启,很多时候不是某个应用挂了,而是内核触发了panic,这类信息在普通应用日志里根本找不到,必须看这一层。

第二层是系统服务日志。传统Linux发行版会写到/var/log/messages(CentOS/RHEL系列)或/var/log/syslog(Debian/Ubuntu系列),由rsyslog统一收拢。这部分记录的是系统级服务、cron任务、认证信息(/var/log/secure)等。现在新一点的发行版已经全面转向systemd的journald,用journalctl来读取,日志二进制存储,带结构化字段,还能按时间、服务、优先级做过滤。

第三层是应用日志。这层最灵活,也最考验设计功力。一个成熟的业务系统,日志文件路径通常会在应用配置里显式声明,比如/var/log/myapp/access.log、/var/log/myapp/error.log。如果应用是跑在容器里的,那就得靠容器日志机制去收,再配合ELK或者Loki这类日志平台做集中处理。

排查故障时的第一判断就是:先搞清问题可能发生在哪一层,然后直奔那一层的日志文件。这一步做对了,后面能省一半时间。

1.2 日志轮转与磁盘占用:不注意就会踩坑

日志系统的头号杀手不是“没写日志”,而是“日志写爆了磁盘”。我见过很多次线上事故,罪魁祸首竟然是/var/log下某个文件撑满了整个分区,导致数据库写入失败、应用无响应。

Linux下负责日志轮转的工具是logrotate。它通过cron定时任务(通常是/etc/cron.daily/logrotate)每天执行一次,按照配置文件把日志改名、压缩、清理。配置在/etc/logrotate.conf,业务相关的通常在/etc/logrotate.d/下各放一个文件。

这里有个常见错误:如果你的日志文件是Java应用持有的,直接rename旧文件再建新文件,应用仍然写的是旧文件描述符指向的已被删除的文件,结果就是新日志文件永远为空。解决办法是配置里加copytruncate,或者用create加postrotate脚本通知应用重新打开文件。

举个例子,我在生产环境给某个业务服务配轮转时这样写:

/var/log/myapp/app.log { daily rotate 14 compress delaycompress copytruncate missingok notifempty dateext dateformat -%Y%m%d }

rotate 14表示保留14个周期,daily就是保留14天。compress压缩旧日志节省空间,delaycompress让昨天的日志不压缩,方便临时查。dateext加日期后缀,避免同名覆盖。最关键的copytruncate:先复制一份当前日志再清空原文件,不影响应用句柄。缺点是复制期间可能有少量日志丢失,但对于排查运维场景,这点损失完全可以接受。

1.3 应用日志的约定优于配置:统一的输出才有排查价值

日志系统的价值上限,很大程度上取决于应用输出日志的质量。我接手过很多项目,日志写得乱七八糟,排查全靠肉眼从万行文本里捞字段,捞完还要脑补上下文。这种痛苦,凡是做过运维的人应该都懂。

我自己的习惯是,应用日志输出至少要满足三个约定:

  • 每条日志必须带时间戳,精确到毫秒,且时间格式统一。没有时间戳的日志等于废品,因为故障排查本质上是还原时间线。
  • 关键业务操作要有唯一标识,比如订单号、请求ID,方便把一次完整操作的日志串联起来。
  • 错误日志必须带堆栈或上下文,不能只打“failed”三个字母。针对异常要记录输入参数和当前状态。

这三个约定看着简单,执行到位能省太多事。尤其是“请求ID贯穿链路”这一点,在微服务架构下几乎是刚需,没有这个标识,前端报一个错,后端几十个服务,你根本对不齐日志。

2. 故障排查:从看到故障到定位根因的完整路径

如果说日志系统是“数据库”,那故障排查就是“查询分析流程”。我见过太多人一遇到线上问题就像无头苍蝇,这里看一下那里试一下,最后问题没定位到,还把现场信息搞丢了。这里我分享一套我自己整理的排查路径,从确认故障到定位根因,每一步都有明确目的。

2.1 先确认“是不是真的故障”:用排除法减少误判

很多人拿到一个“故障”提示,第一反应就是“服务挂了”,但实际上大量问题是假故障。比如:客户说网页打不开,结果是他自己断网了;监控报警说CPU高,登录服务器一看,只是某个批处理任务跑完了正在收尾。排查的第一步,永远是确认现象本身的真实性。

我在实际操作中的习惯是:先看现象的直接表现,再根据表现决定要不要慌。以“网页打不开”为例,先在本机curl一下服务地址,看返回什么状态码;再检查网络链路是否通;最后才登录服务器看服务进程是否存活、端口是否监听。每一步都有明确证据,而不是凭感觉下结论。

这里送大家一个口诀:链路先行,状态次之,日志定案。先把可能的原因范围缩小,再深入日志看实锤。

2.2 还原时间线:用journalctl和时间戳串联线索

一旦确认是真故障,接下来最重要的事情是还原时间线。大多数故障都不是瞬时发生的,总有征兆:内存可能提前十几天就开始缓慢增长,磁盘可能提前几个小时就写满了,重启前的异常日志可能静静地躺在角落里。

我用journalctl时习惯了这样一套组合:

# 查看某个服务的所有日志,反向展示(最新的在最上面) journalctl -u your-service -r # 限定时间窗,比如今天上午9点到10点之间 journalctl -u your-service --since "2024-01-15 09:00:00" --until "2024-01-15 10:00:00" # 按日志级别过滤,只看error和crit journalctl -u your-service -p err..crit

如果日志是写到文件里的传统模式,同样道理,用grep加时间前缀过滤。关键是别只看那一条报错,要把报错前五分钟、后十分钟的日志都拉出来看,这样才能还原“故障发生之前系统在干嘛”的完整画像。

很多新手容易犯的错是:只盯着红色的ERROR看,完全没有上下文概念。实际上,99%的ERROR都要结合前后文理解,否则你只能看到“什么坏了”,看不到“为什么坏”。

2.3 日志之外的重要佐证:进程状态与系统负载

日志是主线索,但日志不是唯一证据。很多时候日志根本没有记录关键信息,或者记录得太晚。这时候要学会从日志之外找佐证,尤其是进程与系统状态。

排查故障时我必查的几项:

  • uptime:看系统负载和1/5/15分钟的平均值,判断是突然飙升还是持续累积。
  • top/htop:看CPU、内存的实时占用,按CPU或内存排序定位消耗大户。
  • ps -ef:看进程是否存在、父进程是谁、启动时间是什么时候。
  • ss -tlnp:看端口监听状态,配合netstat传统命令做对比。
  • df -h和inode:看磁盘空间和inode是否耗尽,这是两个最容易被忽视的“软性故障”。

举一个典型例子:服务突然不响应了,日志里没有任何ERROR,反而在某个时间点之后彻底沉默了。你去看磁盘,发现/var目录100%占满,再看进程还在,但应用卡在文件写入上迟迟返回不了。这种场景下日志帮不上忙,但如果懂系统状态,一眼就能定位。

日志不是故障排查的唯一武器,它是第一件武器。你得会看日志,但更得知道日志什么时候“骗”了你。

3. 长时运行脚本无日志输出的排查实战

说完了理论,来一个真实高频场景:Linux下跑了一个sh脚本,执行了很多个小时,窗口里却长时间没有任何日志输出。你怀疑它挂了,但又不敢确定,更不敢随便杀进程。这种场景在跑批处理、数据同步、长时间定时任务时特别常见。我一开始也慌过,后面总结了完整排查套路,今天详细拆开来说。

3.1 现象复现与第一步排查:脚本还活着吗

先描述一下典型情况:你写了一个shell脚本,里面有循环处理逻辑,打算输出处理进度。用nohup ./run.sh > run.log 2>&1 &扔到后台跑,本来预期每分钟都有输出,结果跑了两个小时run.log文�一寸没变。这时候你的第一反应可能是“脚本卡住了”或者“死循环了”,但注意,这只是一个假设,还不能下结论。

第一步排查就是确认进程本身是否还活着。推荐用如下组合:

ps -ef | grep run.sh pgrep -af run.sh

不要用grep run.sh直接过滤,因为很容易把grep自己匹配进去,虽然可以grep -v grep规避,但pgrep更干净。如果进程在,看它的PID,然后进一步确认它的状态。

ps输出的STAT列很有讲究。R表示运行中,S表示睡眠,D表示不可中断睡眠,Z表示僵尸,T表示已停止。如果看到状态是R,说明它还在消耗CPU;如果是S,说明它在等待某个事件;如果是D,大概率卡在磁盘或网络IO上动弹不得。

3.2 用进程信号和后台任务定位脚本状态

进程活着,不代表它“干活正常”。为了搞清楚脚本到底在干嘛,我用的第二招是发送信号探测。

这里需要理解一个重要机制:kill -0 PID不会发送任何实际信号,它只检查进程是否存在、是否有权限发送信号。如果命令返回0且没有报错,说明进程存在并且属于你。这是最无损的探活方式。

kill -0 12345 && echo "进程还在"

但探活只是第一步,我还想看看脚本当前执行到哪一行了。这时候可以看进程的/proc目录:

ll /proc/12345/fd cat /proc/12345/cmdline ls -l /proc/12345/cwd

/proc/PID/fd里能看到进程打开的文件描述符,比如它正在写哪个日志文件、读哪个数据文件。如果fd里有文件句柄,但lsof查不到,说明文件可能被删了或者路径有问题。这些线索比“进程还在”有用得多。

如果用了strace,能看到更底层的信息:

strace -p 12345 -e trace=write,read,select

这会打印进程当前正在执行的系统调用。如果一直卡在read或select上,说明它在等待外部输入或IO,而不是在疯狂计算。如果不断输出write调用,说明它其实一直在写东西,只是输出没出现在预期位置,那问题就转向“日志到底去哪了”。

3.3 缓冲区机制:为什么脚本“没输出”不等于“没运行”

这是整个排查里我见过最多人踩的坑。很多情况下,脚本根本没有任何问题,数据也在正常处理,只是你看到的文件没有及时刷新。

这背后的机制是缓冲区。当标准输出被重定向到文件(而不是终端)时,glibc会对输出做块缓冲——默认4KB大小的缓冲。也就是说,程序写了几百字节的内容,可能一直存在内存缓冲区里,要等缓冲区满了或者程序退出时才一次性写入文件。这跟你在终端直接跑脚本时的“行缓冲”完全不同,后者碰到换行符就刷一次。

搞明白这个,就理解为什么nohup.out或run.log长时间不更新了。你可以用几个方式验证和解决:

  • 看进程的实时CPU占用确认它在干活:top -p 12345,如果CPU持续波动,说明计算没停。
  • 在脚本里对关键输出主动加stdbuf -oL或unbuffer强制行缓冲。比如把命令改成:stdbuf -oL -eL python3 run.py > run.log 2>&1 &。
  • 如果是Python脚本,python -u就是unbuffered模式,一行输出立即刷新。Java服务则可以通过logback/log4j配置immediateFlush=true。

举个例子,我用rsync同步大批量文件时也碰到过类似现象。rsync有一个--progress输出进度,重定向到日志文件后,日志很久都没动静,看上去像卡死了。但用ps看CPU,rsync进程的cpu占用一直在跳,再等一会儿,等到输出量达到4KB缓冲区,日志文件一次性刷出一大批进度行。这就是典型的“假死”。

3.4 排查流程总结:一份可以直接抄的清单

说了这么多,我把这个场景的完整排查流程理成一份清单,适合贴在手边随时翻阅:

第一步:探活。pgrep -af run.sh,确认进程存在。 第二步:看状态。ps -o pid,stat,etime,cmd -p PID,判断是运行、睡眠还是卡死。 第三步:看行为。top -p PID确认CPU消耗,strace -p PID确认系统调用。 第四步:找输出。cat /proc/PID/fd确认文件句柄,lsof -p PID列出打开文件。 第五步:等结论。结合输出缓冲区机制,判断是“真没输出”还是“没刷出来”。 第六步:做决策。确认卡死才考虑杀进程(先kill,后kill -9),否则继续等或者优化日志输出方式。

这套流程最关键的一点是:每一步都要基于观察结果来判断,而不是凭“感觉”。我之前见过一位同事,脚本跑了三个小时没输出,他上来就kill -9把进程杀了,后来发现数据已经处理到99%,就差最后一点收尾,结果全部白干。排查的时间成本永远比重跑一次低。

4. 常见故障与排查技巧实录

这个章节我整理一些我在一线运维中反复遇到、且很有代表性的排查场景。每个场景我都会给出具体的排查思路和命令组合,方便你直接拿去参考。

4.1 定时任务与日志:cron脚本独特的坑点

cron任务和定时任务是日志系统的高频故障点,坑非常多。比如你设置了一个每小时的定时任务,结果它一直没执行或执行了没效果,排查难度比手动跑脚本高不少,因为cron执行环境跟你手动登录的环境完全不一样。

cron执行任务时不会加载用户的.bash_profile或.bashrc,PATH环境变量被重置为/bin:/usr/bin这种精简状态。你在交互终端能用的命令,在cron里可能找不到。这也是经典问题:脚本里调用某个自定义路径下的命令,手动跑正常,cron跑就报command not found。解决办法是脚本开头固定好环境变量:

#!/bin/bash export PATH=/usr/local/bin:/usr/bin:/bin export LANG=en_US.UTF-8

排查cron相关问题要看的日志是/var/log/cron(或journalctl -u crond)。这个日志会记录每一条任务的执行时间、执行命令、PID和返回状态,是排查定时任务的第一入口。如果任务没有出现在日志里,说明cron根本没有调度到它,重点检查cron表达式和时区。如果出现在日志里但没执行结果,就看任务的退出码或直接手动以cron的环境跑一遍脚本。

我自己吃过一个大亏:某个任务每天凌晨两点跑,偶尔会失败,但查cron日志显示执行正常,退出码为0。后来加了输出重定向,把标准输出和错误都写到文件里,才发现脚本内部一条curl命令因为SSL证书过期报错,但脚本没有set -e,后续命令继续执行,最后整体退出码仍然是0。这就是典型的“日志说正常,实际有问题”。

4.2 系统性能监控:一下就能锁定故障源的几个指标

很多故障的根源不是“某个错误”,而是资源耗尽。日志里可能只有零散的连接超时,但背后是文件描述符用尽或内存泄漏。学会看系统性能指标,能在日志给出明确线索前提前预警。

我推荐在排查故障时优先看这几个指标:

  • 文件描述符:cat /proc/PID/limits看进程的限制值,ls /proc/PID/fd | wc -l看当前打开数量。如果接近上限,服务会报“Too many open files”。
  • 内存与Swap:free -h,关注available是否长期接近0,swap使用率是否持续增长。这两个都是内存压力的信号。
  • 磁盘I/O:iostat -dx 1看每个磁盘的util和await,如果util长期高于80%且await很高,说明磁盘成了瓶颈。
  • 网络连接:ss -s看连接状态统计,配合ss -tn看大量TIME_WAIT或CLOSE_WAIT堆积。TIME_WAIT多可能是连接没复用,CLOSE_WAIT多则多半是应用没正确关闭连接。

这些指标配合日志,基本能覆盖90%的线上故障场景。如果这些都没问题,再去怀疑代码逻辑,否则排查方向容易跑偏。

4.3 我压箱底的排查命令组合

平时我不太推荐“背命令”,但有几条组合确实是高频使用的,熟练到条件反射也不为过。这里先列几条最常用的:

# 查看日志尾部并且持续跟踪 tail -f /var/log/messages # 查看最近一小时内某个关键词的所有日志 journalctl --since "1 hour ago" | grep "关键字" # 看服务状态和最近日志 systemctl status your-service -l # 查端口和进程关系(ss比netstat快) ss -tlnp | grep 8080 # 找高消耗资源的进程 top -o %CPU -o %MEM -b -n 1 | head -30

tail -f在跟踪日志时有一个细节:日志文件发生轮转后,tail -f不会自动跟随新文件名。这时候按Ctrl+C重新执行一次,或者用tail -F(大写F),它会根据文件名重新打开文件。这个小细节我曾经在轮转日志的服务器上踩过坑,当时盯着旧文件的尾部看了半天,数据纹丝不动,后来才发现文件早被logrotate改名了。

4.4 iuv5g故障排查思路:把通用方法落到具体业务系统上

把上面这些通用思路落到具体业务系统中,思路是完全一致的,区别只是观察点不同。

比如一个叫iuv5g的业务模块出现“无日志输出”的可疑故障,我的排查顺序是:先确认系统级资源有没有异常(磁盘、内存、CPU、IO),再看进程状态和相关端口,最后拉业务日志还原时间线。有些人习惯一上来就翻业务日志,忽略了环境因素,往往会走弯路。一个统一思路是:不管业务多复杂,遵循从外到内、从系统到应用、从全局到局部的路径。系统的异常会先反应在日志里,业务的异常则会先反应在操作体验上,把这两条线交叉对齐,就能定位出真正的因果链。

luv5g这类业务系统往往由多个模块组成,模块之间通过接口或消息通信,排查时还需要关注日志里有没有跨模块的traceId或会话标识。有了这个标识,才能把一条请求在多个模块间的流转过程拼出来,否则每个模块的日志都是孤岛,拼不出完整链路。

5. 最后分享几个实操心得

写到最后,聊几个没有展开讲、但在实际工作中价值很高的心得。

日志系统这块,我越来越觉得“留痕”比“事后分析”更值得投入。很多服务上线以后日志路径都没约定好,甚至有的直接打到控制台,重定向都没有,重启以后信息直接蒸发。我建议每个项目从第一天就把日志目录结构、命名规范、轮转策略定好,宁可前期多点工作量,也比故障当天满头大汗查不到日志强。

排查故障时,时间戳是我最依赖的锚点。无论看什么日志,第一件事就是定位时间线:故障影响开始的时间点、日志最后一条记录的时间点、系统负载发生变化的时间点,把这三者对齐,很多问题就清晰了。日志系统有没有统一记录事件时间的能力,决定了排查故障时能不能快速还原现场。

另外,很多“疑难杂症”其实是自己制造的。比如权限不对导致日志写不进、路径写错导致日志一直在别处增长、时区没统一导致日志时间轴错位。这些问题排查起来不难,但很耗时间,预防的唯一办法就是规范化:目录标准化、权限统一、时区强制设为UTC或本地时间并在日志格式中标明。

最后想再强调一下缓冲区那个坑。sh脚本长时间不输出,先别急着杀进程,先确认进程状态,再观察CPU和IO,同时考虑输出缓冲。这种“假死”场景里,多等几分钟往往就等到日志刷出来。遇到问题时,多一层验证,就少一分风险。这份日志系统和故障排查的思路,希望能帮你在下一次踩坑时少走点弯路。

返回列表