Tiana随笔

Linux 服务器排查日志的基本命令

· Nginx

标签：#Linux #部署

Linux 服务器排查日志的基本命令

默认的 combined 日志能告诉我谁访问了哪个地址，但说不清慢请求是卡在 nginx 还是后端。我加了带毫秒和 upstream 耗时的 log_format，然后连踩三个坑：awk 字段偏移、面板报表变空、历史日志不跟着变。

起因：默认日志里没有我要的东西

线上跑了一个多月，nginx 用的还是默认的 combined 格式。它能告诉我谁在什么时候访问了哪个地址、返回了什么状态码，这些够我判断站点是不是活着。

不够的是另一些事。我想知道每篇文章的加载时间分布，想知道那些慢请求是卡在 nginx 还是卡在后端，想知道一个接口被调了 1200 次到底是谁在调。这些信息，默认格式里一个都没有。

所以我干了一件很典型的事：把日志格式改得更全。

改法：加一个 log_format

nginx 允许自定义日志格式，我在站点的 vhost 目录里加了一个文件，专门放时间格式和日志格式的定义。

log_format tiana_combined '$remote_addr - $remote_user [$time_local] '
                          '"$request" $status $body_bytes_sent '
                          '"$http_referer" "$http_user_agent" '
                          '$request_time $upstream_response_time';

改完 reload，日志立刻变成了我要的样子。

39.144.44.59 - - [2026-10-13 11:01:54.297 +0800] "POST /api/blog/posts/list HTTP/2.0" 200 12665 "https://www.tiana.com.cn/home" "Mozilla/5.0 ..." 0.013 0.011

能看见请求耗时 0.013 秒，后端耗时 0.011 秒。挺好的。然后我三个统计脚本全废了。

坑一：时间字段里多了两个空格

我原来的解析脚本是按空格切字段的。默认格式长这样：

39.144.107.214 - - [15/Sep/2026:13:28:20 +0800] "GET /404.html HTTP/1.1" 200 138

awk '{print $6}' 出来是 "GET，$7 是路径。位置我是背下来的。

新格式的时间戳变成了 [2026-10-13 11:01:54.297 +0800]。日期和时间之间多了一个空格，毫秒和时区之间又多了空格对应的切分，方括号还照旧。结果整个字段位置往后挪了两位：

# 新格式（字段右移）
awk '{print $7}' access.log   # 方法
awk '{print $8}' access.log   # 路径
awk '{print $10}' access.log  # 状态码

我第一次跑统计的时候没意识到这点，看到结果里「状态码」这一列全是 "GET，还在纳闷服务器怎么返回了这种东西。

时间字符串含空格的坑，做日志解析的人应该都遇到过。同样的逻辑放到 Python 里也一样，split() 出来的 token 数是固定的，格式一变全乱。

坑二：面板的日志分析报表空了

改完格式第二天，我去宝塔面板看访问统计，报表一片空白，只有零星几条。

原因不难猜：面板自带的日志分析是按默认 combined 格式写死的正则，我的自定义格式它认不出来，匹配不上的行就被丢掉了。

这里我犹豫过。回退格式，面板就正常了；不回退，我就得自己养一套解析脚本。最后我没回退，因为这个面板报表给不出我要的耗时和来源分析，我本来也要自己写。

坑三：历史日志不会跟着变

这个坑是我做汇总的时候才发现的，也是最容易被忽略的。

我以为「改了格式」的意思是「以后的日志是新格式」。实际上文件里是混着的：同一个 www.tiana.com.cn.log，前半部分是旧格式，后半部分是新格式。中间没有分隔线，没有标记，什么提示都没有。

我这一个月的日志里，旧格式 264719 行，新格式 6877 行。切换点大概在 10 月 8 日傍晚，我自己都不记得具体是哪次 reload。

所以解析脚本不能只认一种格式，得两种都试，试不通再放弃。

import re

NEW = re.compile(
    r'^(?P<ip>\S+) \S+ \S+ \[(?P<ts>\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})\.\d+ \+0800\] '
    r'"(?P<method>\S+) (?P<path>\S+) [^"]*" (?P<status>\d{3}) (?P<bytes>\d+|-)'
)
OLD = re.compile(
    r'^(?P<ip>\S+) \S+ \S+ \[(?P<ts>\d{2}/\w{3}/\d{4}:\d{2}:\d{2}:\d{2}) \+0800\] '
    r'"(?P<method>\S+) (?P<path>\S+) [^"]*" (?P<status>\d{3}) (?P<bytes>\d+|-)'
)


def parse(line):
    for pattern in (NEW, OLD):
        m = pattern.match(line)
        if m:
            return m
    return None

顺序是先试新格式再试旧的，因为新格式更严格（毫秒那段必须存在），旧格式的日期写法不会误匹配新行。

我日常真正在用的几条命令

自定义格式好看，但日常排查还是那三板斧最快。

看后端服务最近的日志：

journalctl -u tiana-blog -n 200 --no-pager
journalctl -u tiana-blog --since "30 min ago"

这个项目里后端的日志只记 /api/* 的请求，页面访问一条都不记，因为静态页是 nginx 直接吐出去的，压根不经过 Python。

实时盯着看：

tail -f /www/wwwlogs/www.tiana.com.cn.log

统计今天被拦截的扫描请求有多少：

grep -c ' 444 ' /www/wwwlogs/www.tiana.com.cn.log

按状态码分组数一遍：

awk '{print $10}' /www/wwwlogs/www.tiana.com.cn.log | sort | uniq -c | sort -rn

最后这条就是那个字段右移的坑，$10 只对新区段的日志有效。要对整个文件跑，就得先用前面那段 Python 统一转一遍。

现在的顺序

出问题的时候我现在的动作顺序是：先 journalctl 看后端有没有 500，再 tail nginx 日志看请求有没有到，最后按 IP 和路径去数一遍，判断是单个用户在刷还是一群人。

至于改格式这件事，回头看我仍然会改，耗时和上游耗时这两个字段帮我把不少问题提前定位掉了。但我下次会在改之前先把解析脚本的双格式分支写好，而不是等统计报表空了两天才反应过来。

相关文章