Why is $upstream_response_time in add_header a hyphen?

Given /etc/nginx/nginx.conf:

events {}

http {
    server {
        listen 8000;

        location / {
            proxy_pass  http://localhost:8001;

            add_header X-Trip-Time    $request_time;
            add_header X-Process-Time $upstream_response_time;
        }
    }
}

Running:

python3 -u -m http.server 8001 > app.log 2>&1 & sudo nginx

followed by:

curl -i localhost:8000

shows these two headers:

X-Trip-Time: 0.001
X-Process-Time: -

I've seen this related question, which says this:

In case of internal error while connecting to an upstream or when a reply is taken from the cache, the variable is set to -

But my upstream server is successfully connected to as shown by cat app.log:

127.0.0.1 - - [03/Feb/2021 19:41:44] "GET / HTTP/1.0" 200 -

What is the cause for $upstream_response_time equaling -, yet $request_time works as expected?


Solution 1:

I received this answer on the nginx mailing list:

That's because response headers are sent before the $upstream_response_time is known: it is only known when the response is fully received from the upstream server, including the response body, and this happens after the response headers are sent to the client. If you want to return something in the response headers, consider the $upstream_header_time variable instead (http://nginx.org/r/$upstream_header_time).

I couldn't find anything in the documentation about how nginx buffers responses (can only find documentation for requests) and whether it can be configured, but sure enough changing $upstream_response_time to $upstream_header_time is working and the times are very close when looking in the logs, atleast when the response body size is miniscule such as in my case.