nginx blocking request till current request finishes

Question

Boiling my question down to the simplest possible: I have a simple Flask webserver that has a GET handler like this:

@app.route('/', methods=['GET'])
def get_handler():
    t = os.environ.get("SLOW_APP")
    app_type = "Fast"
    if t == "1":
       app_type = "Slow"
       time.sleep(20)
    return "Hello from Flask, app type = %s" % app_type 

I am running this app on two different ports: one without the SLOW_APP environment variable set on port 8000 and the other with the SLOW_APP environment variable set on port 8001. Next I have an nginx reverse proxy that has these two appserver instances in its upstream. I am running everything using docker so my nginx conf looks like this:

upstream myproject {
  server host.docker.internal:8000;
  server host.docker.internal:8001;
}

server {
  listen 8888;
  #server_name www.domain.com;
  location / {
    proxy_pass http://myproject;
  }
}

It works except that if I open two browser windows and type localhost, it first hits the slow server where it takes 20 seconds and during this time the second browser appears to block waiting for the first request to finish. Eventually I see that the first request was serviced by the "slow" server and the second by the "fast" server (no time.sleep()). Why does nginx appear to block the second request till the first one finishes?

Answer 1

No, if the first request goes to the slow server (where it takes 20 sec) and during that delay if I make a request again from the browser it goes to the second server but only after the first is finished.

I have worked with our Engineering Team on this and can share the following insights:

Our Lab environment

Lua

load_module modules/ngx_http_lua_module-debug.so;
...
upstream app {
    server 127.0.0.1:1234;
    server 127.0.0.1:2345;
}
server {
    listen 1234;
    location / {
        content_by_lua_block {
            ngx.log(ngx.WARN, "accepted by fast")
            ngx.say("accepted by fast")
        }
    }
}
server {
    listen 2345;
    location / {
        content_by_lua_block {
            ngx.log(ngx.WARN, "accepted by slow")
            ngx.say("accepted by slow")
            ngx.sleep(5);
        }
    }
}
server {
    listen 80;
    location / {
        proxy_pass http://app;
    }
}

This is the same setup as it would be with another 3rd party application we are proxying traffic to. But I have tested the same with an NGINX configuration shared in your question and two NodeJS based applications as upstream.

NodeJS

Normal

const express = require('express');
const app = express();
const port = 3001;

app.get ('/', (req,res) => {
  res.send('Hello World')

});

app.listen(port, () => {
  console.log(`Example app listening on ${port}`)
})

Slow

const express = require('express');
const app = express();
const port = 3002;

app.get ('/', (req,res) => {
  setTimeout( () => {
    res.send('Hello World')
   }, 5000);
});

app.listen(port, () => {
  console.log(`Example app listening on ${port}`)
})

The Test

As we are using NGINX OSS the Loadbalancing protocol will be RoundRobin (RR). Our first test from another server using ap. The Result:

Concurrency Level:      10
Time taken for tests:   25.056 seconds
Complete requests:      100
Failed requests:        0
Total transferred:      17400 bytes
HTML transferred:       1700 bytes
Requests per second:    3.99 [#/sec] (mean)
Time per request:       2505.585 [ms] (mean)
Time per request:       250.559 [ms] (mean, across all concurrent requests)
Transfer rate:          0.68 [Kbytes/sec] received
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.7      0       5
Processing:     0 2505 2514.3   5001    5012
Waiting:        0 2504 2514.3   5001    5012
Total:          1 2505 2514.3   5001    5012
Percentage of the requests served within a certain time (ms)
  50%   5001
  66%   5005
  75%   5007
  80%   5007
  90%   5010
  95%   5011
  98%   5012
  99%   5012
 100%   5012 (longest request)

50% of all requests are slow. Thats totally okay because we have one "slow" instance. The same test with curl. Same result. Based on the debug-log of the NGINX server we saw that the request were processed as they came in and were sent to either the slow or the fast backend (based on roundrobin).

2021/04/08 15:26:18 [debug] 8995#8995: *1 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *1 get rr peer, current: 000055B815BD4388 -100
2021/04/08 15:26:18 [debug] 8995#8995: *4 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *4 get rr peer, current: 000055B815BD4540 0
2021/04/08 15:26:18 [debug] 8995#8995: *5 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *5 get rr peer, current: 000055B815BD4388 -100
2021/04/08 15:26:18 [debug] 8995#8995: *7 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *7 get rr peer, current: 000055B815BD4540 0
2021/04/08 15:26:18 [debug] 8995#8995: *10 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *10 get rr peer, current: 000055B815BD4388 -100
2021/04/08 15:26:18 [debug] 8995#8995: *13 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *13 get rr peer, current: 000055B815BD4540 0
2021/04/08 15:26:18 [debug] 8995#8995: *16 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *16 get rr peer, current: 000055B815BD4388 -100
2021/04/08 15:26:18 [debug] 8995#8995: *19 get rr peer, try: 2
2021/04/08 15:26:18 [debug] 8995#8995: *19 get rr peer, current: 000055B815BD4540 0

So given that means the behaviour of "nginx blocking request till current request finishes" is not reproducible on the instance. But I was able to reproduce your issue in the Chrome Browser. Hitting the slow instance will let the other browser window waiting till the first one gets its response. After some memory analysis and debugging on the client side I came across the connection pool of the browser.

https://www.chromium.org/developers/design-documents/network-stack

The Browser makes use of the same, already established connection to the Server. In case this connection is occupied with the waiting request (Same data, same cookies...) it will not open a new connection from the pool. It will wait for the first request to finish. You can work around this by adding a cache-buster or a new header, new cookie to the request. something like:

http://10.172.1.120:8080/?ofdfu9aisdhffadf. Send this in a new browser window while you are waiting in the other one for the response. This will show an immediate response (given there was no other request to the backend because based on RR -> IF there was a request to the slow one the next one will be the fast one).

Same applies if you send request from different clients. This will work as well.