特殊的nginx日志格式

简述

描述 nginx 记录 upstream 日志时的三种日志格式。

access日志

我们经常会通过查看nginx的日志文件来排查一些问题;

但是默认的日志格式输出的内容太少，可以根据实际需求，加上一些内容。

默认的 nginx 日志格式

1
2
3


log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                  '$status $body_bytes_sent "$http_referer" '
                  '"$http_user_agent" "$http_x_forwarded_for"';

个人比较推荐的日志格式

1
2
3
4
5
6
7
8


log_format  main 'local:$hostname:$server_port:$msec:$connection:$connection_requests '
        '$request_id '
        '[$time_iso8601] $status $request_time $bytes_sent $body_bytes_sent '
        '"$remote_addr" "$http_x_forwarded_for" '
        '"$upstream_addr" "$upstream_status" "$upstream_response_time" '
        '$request_length "$content_length" "$host" "$http_host" '
        '"$server_protocol" "$request_method" "$request_uri" "$http_referer" '
        '"$http_content_type" "$http_user_agent" "$request_body"';

upstream 相关日志格式

默认是没有记录 upstream 上游服务器的日志的；推荐将其开启，以方便排查一些问题；

比如响应超时或返回内容错误时，可以快速通过nginx日志确定到是哪个上游服务器出现的错误;

通常会记录 “$upstream_addr” “$upstream_status” “$upstream_response_time” 这三个变量

1
2
3


    upstream_addr           # 本次请求发送给具体哪个上游服务器处理的
    upstream_status         # 上游服务器响应的状态码
    upstream_response_time  # 上游服务器的处理耗时

下面来说一下三种场景下这三个变量值的情况

一、常规情况

1
2
3


"$upstream_addr" "$upstream_status" "$upstream_response_time"\
"172.17.8.146:19001" "200" "0.088"
"172.17.8.146:19002" "404" "0.011"

普通情况就是这样，一次请求只发送给了1个上游应用，并获取到了正确的响应。

二、较为特殊的情况

1
2


"$upstream_addr" "$upstream_status" "$upstream_response_time"
"172.17.8.146:19001,172.17.8.146:19001" "500,200" "0.088,0.002"

注意这里是逗号分隔符

这种情况说明此次请求被发送给了多个上游服务器；
先发给了第一个服务器, 判断失败后，又发请求给了第二个服务器。

即当 upstream 组内有多个服务，且发生某个上游处理错误时，会再次转发给下一个服务器进行处理。

如：

上游服务器连接或响应超时, 参考 proxy_connect_timeout, proxy_read_timeout；
上游应用响应错误的内容，如 500, 503等，参考 proxy_next_upstream

注意: 如果没有控制总耗时，则会将组内的全部服务都轮一遍。

三、特别特殊的场景

1
2


"$upstream_addr" "$upstream_status" "$upstream_response_time"
"172.17.8.146:9000 : 172.17.8.146:9000" "404 : 404" "0.047 : 0.046"

注意这里是 冒号和空格 的分隔符

我第一次看到也觉得非常奇怪，怎么会有这样的;

当一笔请求，涉及到"多次不同"的后端请求时，则会出现这种情况；

场景二与这个的的区别是 nginx 向上游发送的时相同的请求；

举例

用户请求一张图片，如果这张图片在上游不存在(服务器返回404)，则更换为请求一张 404.png 的图片响应给用户。

1
2
3
4
5
6
7
8


location ^~ /static/img/ {
    proxy_intercept_errors on;
    proxy_connect_timeout 3;
    proxy_read_timeout 3s;
    proxy_pass http://10.2.1.2:9000;

    error_page 404 /static/img/404.png;
}

或者是用户请求一个接口，如果响应一个异常，则 nginx 再次发出一个不同请求;

知识积累

用 elk 等做 nginx 日志分析的时候，还是要将能解析的进一条线，不能解析的进一条线，这样方便找异常。

微信搜索IT运维小秋