Nginx日志$upstream_addr多个值

最近在排查一个线上问题的时候，发现nginx日志$upstream_addr字段居然返回了2个值，形如"192.168.1.1:80, api-servers"，其中api-servers是指代的是你的upstream后面接group name，部分只有一个值"api-servers"。正常情况下，这个地方应该是类似“192.168.1.1:80”这样，即一个请求落到一个后端服务。

查询官方文档:

$upstream_addr

keeps the IP address and port, or the path to the UNIX-domain socket of the upstream server. If several servers were contacted during request processing, their addresses are separated by commas, e.g. “192.168.1.1:80, 192.168.1.2:80, unix:/tmp/sock”. If an internal redirect from one server group to another happens, initiated by “X-Accel-Redirect” or error_page, then the server addresses from different groups are separated by colons, e.g. “192.168.1.1:80, 192.168.1.2:80, unix:/tmp/sock : 192.168.10.1:80, 192.168.10.2:80”. If a server cannot be selected, the variable keeps the name of the server group.

细读上面的文档，当请求尝试链接了多个后端服务器的时候，上述逗号分割多值记录的情况就会发生，冒号分割是另外一种状况，这里不讨论。当值为server group name的时候，“If a server cannot be selected” 这英文表意不明，写这个文档的人英文应该不是母语，是所有后端不可用，还是在默认限定的选择数目内都不可用，有知道的高手可以探讨下。总之，如果你的服务是注册到upstream里面的，服务池里面的服务，此时应该是不可用了，要自己去排错，多值记录给了你个线索。

在我们的场景中，是使用consul注册服务的，判定为某个机房的consul集群异常了，导致旧的服务没有被摘除，新的也没有及时更新，落到旧服务的请求没有可用的server, 返回502状态码。

昨天对这个有疑问，今天来测试验证。

1. Nginx 配置

➜  cat /etc/nginx/conf.d/test.com.conf
upstream backend-servers{
        server 127.0.0.1:9527;
        server 127.0.0.1:9528;
        server 127.0.0.1:9529;
        server 127.0.0.1:9530;
        server 127.0.0.1:9531;
        server 127.0.0.1:9532;
        server 127.0.0.1:9533;
        server 127.0.0.1:9534;
        server 127.0.0.1:9535;
        server 127.0.0.1:9536;
        server 127.0.0.1:9537;
        server 127.0.0.1:9538;
        server 127.0.0.1:9539;
        server 127.0.0.1:9540;
        server 127.0.0.1:9541;
        server 127.0.0.1:9542;
        server 127.0.0.1:9543;
        server 127.0.0.1:9544;
        server 127.0.0.1:9545;
        server 127.0.0.1:9546;
        server 127.0.0.1:9547;
        server 127.0.0.1:9548;
        server 127.0.0.1:9549;
        server 127.0.0.1:9550;
        server 127.0.0.1:9551;
        server 127.0.0.1:9552;
        server 127.0.0.1:9552;
        server 127.0.0.1:9553;
        server 127.0.0.1:9554;
        server 127.0.0.1:9555;
        server 127.0.0.1:9556;
        server 127.0.0.1:9557;
        server 127.0.0.1:9558;
        server 127.0.0.1:9559;
        server 127.0.0.1:9560;
        server 127.0.0.1:9561;
        server 127.0.0.1:9562;
}
server {
        listen 80;
        server_name test.com;

        access_log /data/log/test.com.log access;

        location /{
                proxy_pass http://backend-servers;
        }
}

2. 用Flask模拟运行backend-server

➜  test cat server1.py
from flask import Flask

app = Flask(__name__)

@app.route("/")
def hello_world():
    return "<p>Hello, 9527!</p>"

if __name__ == '__main__':
    app.run(host="0.0.0.0", port=9527)

➜  test cat server2.py
from flask import Flask

app = Flask(__name__)

@app.route("/")
def hello_world():
    return "<p>Hello, 9528!</p>"

if __name__ == '__main__':
    app.run(host="0.0.0.0", port=9528)

如下图所示

3. 测试抓包查看日志验证

• 用命令curl测试

    curl -H "Host:test.com" http://127.0.0.1 
  

• tcpdump 抓包看nginx是否会连接失效的backend-server

    sudo tcpdump -i lo port 9528
  

• 查看日志结果

  

  通过启动关停flask server, 再查看nginx $upstream_addr字段的值，看看nginx不同情况记录什么内容。

结论，当有一个可用的服务的时候，upstream_addr记录的是这个可用后端的ip:port； 非动态注册(测试用例就是写死的upstream)，Nginx会去重试连接那些失效server，此时upstream_addr显示多个值，尝试链接了多少个，就逗号分割记录多少个； 当关停所有flask后，upstream_addr显示为“backend-servers”,即upstream后面定义的名字，出现这个，表明没有一个可用的后端服务，问题大了，服务彻底不可啦！