前几天帮同事排查一个问题一台机器上跑了个数据同步脚本跑了大半天终端窗口里却干干净净一行日志都没吐出来。同事第一反应是“脚本挂了”催我赶紧杀掉重启。我说先别急“没日志”和“没进展”是完全两回事。这件事正好对应我常讲的Linux系统管理系列第13章日志系统与故障排查。今天我就用这次真实排查作为主线把日志系统的底层逻辑、长时间脚本无输出的判断方法、进程状态分析、性能监控和排查思路完整过一遍适合正在搞运维、写部署脚本、或者被各种“跑着跑着就没动静”问题折磨过的同学收藏。1. 日志系统故障现场的第一见证人1.1 一切皆日志Linux日志体系的三层结构很多朋友一听“日志系统”脑子里只有/var/log/messages或者journalctl真到排查的时候就会发现不够用。Linux的日志其实是分层的我在生产环境里习惯把它拆成三层来看内核日志、系统服务日志、应用日志。内核日志负责记录硬件、驱动、内存和文件系统这些底层信息排查OOM、磁盘IO异常、网卡丢包时主要看它。传统上用dmesg在systemd环境下用journalctl -k更顺手能直接按时间范围过滤。系统服务日志包括sshd、crond、nginx这类服务的运行记录和认证信息这类日志通常由rsyslog统一管理落在/var/log/messages、/var/log/secure、/var/log/cron这些文件里。应用日志则是业务程序自己输出的可能写到应用目录下的某个*.log文件也可能写到/var/log/下独立子目录位置千奇百怪。这里有个特别容易踩坑的点systemd时代journald会捕捉所有服务写到标准输出和标准错误的内容但rsyslog只是有选择地转发一部分到传统日志文件。所以有时候你在/var/log/messages里查不到某条错误用journalctl -u 服务名却能查到这不是系统丢了日志而是你看错了数据源。排查第一步永远是确认日志到底落在哪里文件还是journal对应哪个服务名否则后面全是对着空气挥拳。1.2 日志轮转与持久化磁盘满导致的“日志静默”日志系统平时不显眼但它在故障排查时能不能用取决于两件事轮转策略和持久化上限。我踩过一次很深的坑某台机器上应用日志连续几个小时没有新内容业务却能正常访问数据库也活着。第一反应是日志级别配置出了问题折腾半天才发现/分区已经100%满journald和rsyslog都在悄悄报错所有日志写入全部静默失败。检查日志的第一步压根不是grep而是先执行df -h看磁盘再执行date看时间。时间不对你后面把所有日志对齐到同一条时间线就是白费功夫。轮转配置建议用logrotate常见做法是daily加rotate 30加compress再配一个size触发避免某天日志量突增把一个文件撑到几个G。journald那边的持久化也要限一下RHEL系发行版默认把journal写到/var/log/journal如果不设上限长期运行后体积非常恐怖。我会在/etc/systemd/journald.conf里设置SystemMaxUse500M让旧日志自动清理。还有个细节日志轮转后服务如果一直持有旧文件句柄新日志还是会写进旧inode表现为df显示磁盘被占用但文件看不到内容。遇到这种情况很多服务支持用kill -HUP让它重新打开日志文件配置logrotate的postrotate脚本时别忘了配合。2. 长时间无日志输出先把“没日志”和“没输出”分开2.1 为什么脚本跑了大半天却一行日志都没有回到文章开头那个场景sh script.sh执行之后窗口里长时间没有日志。这个现象背后常见的不是一种原因而是至少三种而且每种的应对方式完全不同。第一种叫输出缓冲。这是最容易被误解的一个原因。终端环境下程序的标准输出是行缓冲打一行刷一行一旦输出被重定向到文件或管道C库的stdio会把缓冲策略切换成块缓冲只有缓冲区写满通常是4KB或8KB或者进程退出时才落盘。也就是说脚本其实一直在跑甚至CPU都在工作但日志就是攒在内存里不写出去。解决思路是启动命令时套上stdbuf -oL -eL或者给Python加-u参数让它不受缓冲影响。第二种是进程真的卡住了比如在等待一个永远不会超时的TCP连接、等待某个锁文件、或者程序逻辑里某个循环出现了死循环但没输出。这时候进程还在内存里ps能看到但它的状态和正常运行时不一样后面我会详细说怎么分辨。第三种是输出被重定向到了别处。脚本开头可能有一句exec /tmp/a.log 21或者调用某个子脚本时悄悄改了文件描述符。你盯着当前终端自然什么都看不到。排查的时候用ls -l /proc/PID/fd/直接看文件描述符指向哪里比猜快得多。2.2 三条命令确认脚本是否还在正常运行判断一个脚本是否活着不能靠感觉也不能只看“有没有日志”。我在生产环境里固定用三条命令。第一条是ps -ef | grep script.sh或者pgrep -af script.sh先把进程PID拿到手。注意ps输出里的TIME字段是累计CPU时间不是运行时长。一个同步等待型任务可能跑了三小时CPU时间还是0:00:01这不代表它是死的。第二条是ps -o pid,ppid,stat,etime,wchan:20,cmd -p PID。这里stat是最关键的字段R表示正在运行或可运行S是可中断睡眠D是不可中断睡眠T是停止状态Z是僵尸进程。如果进程停在D大概率在等磁盘或网络IO停在S可能在等锁、信号或socket。wchan会直接告诉你它阻塞在内核哪个函数上比如等待磁盘缓冲区时经常能看到wait_on_buffer。etime是累计运行时长方便确认它是不是真的跑了很久。第三条是直接进/proc/PID/看细节。cat /proc/PID/status里的State、VmRSS、Threads信息很直观cat /proc/PID/wchan和ps里的wchan是同一份信息ls -l /proc/PID/fd能看出打开的文件。如果脚本会fork子进程再用pstree -p PID看是不是卡在某个子进程身上。只看日志输出判断脚本健康度是最偷懒也最容易误判的方式。进程状态、wchan、文件描述符这三样组合起来才能还原它到底在干什么。3. 后台任务与进程信号脚本“失踪”的真实原因3.1 nohup、、setsid与终端生命周期另一种常见现象是脚本明明在跑你离开终端或者SSH断开之后它就“失踪了”。这背后的机制是终端关闭时内核会向会话首进程发送SIGHUP信号shell退出前也会向它管理的后台任务发送SIGHUP。这个信号的默认行为就是终止进程所以你的脚本其实是被信号杀死的不是自己崩溃的。要避免这种情况得先搞清楚三件事的区别。只是把任务放到当前shell的后台作业列表里它依然绑在当前会话上终端退出一样会收到信号。nohup的作用是忽略SIGHUP但进程还在原会话里只是这个信号被屏蔽了。setsid更彻底它让进程开启一个新会话完全脱离控制终端。我实测下来最稳的组合是setsid nohup sh script.sh /var/log/script.log 21 或者干脆用tmux这种终端复用器把任务放在一个独立会话里随时可以attach回来。如果进程已经出现“莫名消失”的情况可以从残留痕迹反推。用ps -o pid,ppid,stat,etime -p PID看如果PPID是1说明父进程已经退出它被init或systemd收养成了孤儿进程但还活着。如果进程完全消失了就去journalctl里查会话关闭和信号发送的记录。老系统上还可以看/var/log/messages里的session相关日志定位是否发生了SIGHUP。3.2 定时任务环境变量缺失与信号使用细节定时任务是“脚本无日志输出”的重灾区因为它和交互式shell的运行环境完全不一样。cron执行脚本时PATH通常只包含/usr/bin:/bin你昨天还在终端里跑得好好的命令放进crontab可能根本找不到可执行文件。更坑的是很多人写cron脚本时习惯在后面加2/dev/null结果命令找不到、权限报错这些最关键的线索全被吞了日志文件自然永远空白。我处理过一个典型case备份脚本每天凌晨3点执行任务明明跑了备份文件也产生了但脚本的标准输出和错误输出全部丢进了系统mail的“黑洞”。后来在脚本开头加上export PATH$PATH:/usr/local/bin并把输出重定向到独立日志文件问题立刻清晰了。所以crontab里每一条任务我都建议这样写0 3 * * * cd /data/scripts ./backup.sh /data/logs/backup_$(date \%F).log 21再加一条; echo exit$? /data/logs/backup_$(date \%F).log保底至少能知道退出码。信号方面有个容易被忽略的好工具kill -0 PID并不会真的发送信号它只是探测进程是否存在很适合写监控脚本。真正要终止进程时先用kill -TERM给它机会清理临时文件、释放锁等几秒没退出再升级到kill -KILL。一上来就kill -9是最粗暴的做法进程没有机会写任何退出日志现场直接没了后续复盘很难开展。4. 系统性能监控从负载指标逆推脚本卡在哪4.1 把CPU、IO、内存指标和脚本状态对上当脚本状态看起来像是“活着但不动”性能监控就是定位阻塞点的利器。我常用的组合是vmstat 1、iostat -x 1、top -H -p PID和pidstat -p PID 1。它们负责回答不同问题CPU到底在忙什么磁盘IO是不是瓶颈内存是不是不够用。先说IO。进程如果卡在D状态读一下iostat -x 1里的await和util。util接近100%说明磁盘确实在超负荷运转await特别高表示单个IO请求要在队列里排队很久。如果你看到r/s和w/s都很大但吞吐量不高可能是写日志文件这种顺序写被其他随机写干扰了。很多长任务脚本卡死的根因就是日志文件、数据库binlog和临时文件抢同一块盘的IO带宽。再说内存。进程一直处于S状态VmRSS却只增不减同时vmstat里的si和so不断有数值说明系统在疯狂换页内存才是瓶颈。这种场景下不用怀疑脚本逻辑先给机器加内存或者减少并发才是正路。如果进程直接消失去内核日志里找有没有oom-kill的记录这可比在应用日志里大海捞针快多了。进程状态和CPU占用结合起来看更准确。脚本没有新日志但CPU占用很高说明它在计算或者处理数据只是输出缓冲没刷新CPU占用为0TIME累计也不变那它大概率在等待某个外部资源。4.2 日志时间线对齐与定时任务的割裂问题只看性能指标的当前值是没用的必须和故障发生的时间对齐。比如任务10:32出现异常我就去查10:27到10:37这五分钟的journalctl和vmstat快照锁定到底是网络、磁盘还是应用逻辑先出问题。journalctl --since 10:30 --until 10:35 -u myservice是我每天都会用到的姿势比直接翻/var/log/messages精准得多。这里有个教训永远不要只看最后一条日志。正确做法是找到“最后一次正常日志”和“第一次异常日志”两个时间点它们之间的间隔往往就是问题真正的发生窗口。性能数据也一样不要只看峰值要看窗口内数据的变化趋势。5. 故障排查方法论一条时间线串起所有线索5.1 先保现场再动手排查第一步不是重启每次故障处理我最怕的不是问题难而是同事手快把现场毁了。进程一kill -9/proc下的状态信息、环境变量、打开的文件描述符全部消失只剩一段苍白的口头描述。正确的顺序永远是先取证再分析最后才动手修复。现场取证至少要包含这些内容进程的ps -ef输出、ps -o stat,pid,ppid,wchan,etime、/proc/PID/status、/proc/PID/fd/目录列表、/proc/PID/environ再加上故障窗口内的journalctl片段。尤其是/proc/PID/environ排查cron脚本变量问题时几乎是唯一能证明“脚本启动时到底少了什么环境变量”的证据。我自己现在的习惯是只要不是安全事件一律先cp一份原始日志到备份目录再考虑轮转或者清空。有些同事嫌日志太大不想备份但事后复盘时那几GB日志里往往就藏着一条关键错误删了再找只能拍大腿。5.2 用假设排查法缩小范围面对“脚本长时间无日志输出”这类问题脑子里的排查框架应该是列出所有可能假设每个假设用一两个命令验证验证不成立就快速换下一个。不要在一个方向上死磕太久我有过花两小时怀疑脚本逻辑最后发现只是磁盘只读导致日志写不进去的经历整个过程亏得厉害。推荐的假设优先级是这样的先确认系统时间和磁盘空间再看进程是否存在及其状态然后确认日志文件是否可写最后才进入应用代码逻辑分析。这套顺序也可以无缝迁移到专用设备场景。比如用户提到iuv5g这类设备的故障排查很多人因为不熟悉产品名就被吓住其实逻辑完全一样先固定现场信息再把各个模块日志放到同一时间轴上对齐最后用假设验证排除。设备叫什么名字不重要排查的底层方法从来都是证据驱动。6. 常见问题与排查技巧实录6.1 故障现象速查表故障现象可能原因检查命令与解决思路日志没有输出但进程存在标准输出被块缓冲stdbuf -oL启动或程序内部设置行缓冲进程状态为DIO阻塞磁盘或网络等待iostat -x 1、查看/proc/PID/wchan进程状态为S但CPU为0等待锁、socket或子进程lsof -p PID、ss -tnp查看连接脚本跑完终端断开后消失SIGHUP信号终止用setsid/nohup/tmux启动cron任务没有输出日志PATH缺失或错误输出被丢弃重定向到文件去掉2/dev/null检查/var/log/cron日志文件不更新但服务正常磁盘满或日志轮转句柄未释放df -h、logrotatepostrotate配kill -HUP进程内存持续增长后消失OOM或被killjournalctl -k查oom记录检查swap与VmRSS这张表不是标准答案更像一份排查清单。实际操作中现象有重叠很正常把进程状态、日志时间线、性能指标三个维度交叉验证比单看一列可靠。6.2 两个极其实用的巡检技巧最后分享两个很少被写进文档的技巧但都是救过我命的小操作。第一个是检查文件描述符技巧。当脚本明明写了日志/var/log/下却看不到新内容时执行ls -l /proc/PID/fd/看标准输出文件描述符。如果它指向的文件后面有(deleted)字样说明日志文件已经被logrotate或者其他进程删了但进程还在往旧inode里写。这个场景最坑的地方在于df显示磁盘空间被占用但用常规方式找不到那个“幽灵文件”。遇到这种情况重启服务或向进程发SIGHUP让它重新打开文件即可。第二个是为长任务加“心跳日志”和timeout保险。在脚本关键循环节点定期输出一行当前时间加进度哪怕每30分钟一条都能在故障时帮你大幅缩小排查范围。给危险命令包一层timeout 3600 mysqldump ...可以防止命令假死导致整个脚本永久挂起超时自动退出至少给你留一个退出码和日志而不是无声无息地卡到天荒地老。说回到文章开头那个同事。那次排查最后用ps -o wchan确认脚本正阻塞在磁盘IO等待上配合iostat发现日志盘被其他任务写满磁盘IO队列一直爆表。杀掉另一个无关的批量任务后脚本日志立刻恢复输出全程没动脚本本身一行代码。这件事之后我养成了一个习惯遇到长时间无日志输出的长任务先冷静下来问一句“这个进程的wchan到底在等什么”用状态说话比凭直觉杀进程可靠得多。这套流程我用了很久稳定复现率很高希望你下次也能用上。