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後面定義的名字，出現這個，表明沒有一個可用的後端服務，問題大了，服務徹底不可啦！