nginx unresponsive after a while

[Maxim Dounin]

Hello!

On Sun, Jun 12, 2022 at 06:15:05PM -0400, minderdl wrote:

> I've upgraded from Debian 9 to 11 (via 10) just recently, i.e. from nginx
> "1.10.3-1+deb9u7" to "1.18.0-6.1". I'm also running ispconfig on this
> machine, which modifies configuration. But therefore, I try to post complete
> configurations at this point in time.
> 
> Shortly after the upgrade nginx became unresponsive. After restarting the
> service, it works again, then it takes some days until it's unresponsive
> again.
> 
> In the error.log I only see these lines, but many of them:
> 2022/06/08 23:45:01 [alert] 592#592: 768 worker_connections are not enough
> 
> Now, then running: lsof | egrep '^nginx .* sock'
> I get a long list (well, 760+x or so) of these:
> nginx       592                   www-data    3u     sock                0,8
>       0t0      69062 protocol: TCP
> 
> Thus, it seems that nginx still has a lot of open connections which prevent
> new requests. Note that this is NOT a high traffic site. It's the very
> opposite in fact.
> 
> I enabled debug log and tried to figure out when a connection was left, and
> it seems to be this:

[...]

> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http special response: 497, "/cgi-bin/ViewLog.asp?"
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http script copy: "https://"
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http script var: "192.168.0.14"
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http script copy: ":8080"
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http script var: "/cgi-bin/ViewLog.asp"
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http set discard body
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http read discarded body
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 recv: eof:1, avail:0
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 recv: fd:18 0 of 152
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http set discard body
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http read discarded body
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 xslt filter header
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 HTTP/1.1 302 Moved Temporarily

[...]

> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 writev: 360 of 360
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http write filter 0000000000000000
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http copy filter: 0 "/cgi-bin/ViewLog.asp?"
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http finalize request: 0, "/cgi-bin/ViewLog.asp?" a:1, c:2
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http request count:2 blk:0
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http run request: "/cgi-bin/ViewLog.asp?"
> 2022/06/10 00:05:26 [debug] 1548997#1548997: *2544 http reading blocked

Interesting, thanks for reporting this.

It looks like an issue specific to a particular Debian package.  
Debian seems to ship the nginx 1.18.0 package with a leftover 
patch to add ngx_http_discard_request_body() call to error_page 
handling with redirects:

https://sources.debian.org/patches/nginx/1.18.0-6.1/CVE-2019-20372.patch/

And it looks like your configuration uses error_page with 
redirect, so this affects your configuration.

Due to this extra/leftover patch the 
ngx_http_discard_request_body() function is always called twice, 
since the same call is already present in nginx 1.18.0.  

Further, the first call detects a connection close by the client 
and returns, and the second one results in a socket leak (due to 
shortcut call to ngx_http_close_request() in case of c->read->eof 
in ngx_http_finalize_request()).

An obvious fix would be to remove the leftover patch in question 
from the package.

Also it might be a good idea to switch to a package from 
nginx.org: nginx 1.18.0 is obsolete more than a year ago, current 
stable version is nginx 1.22.0.  See 
http://nginx.org/en/linux_packages.html for details.

For the record, the relevant code should be already sufficiently 
resilient to such duplicate calls after 4a9d28f8f39e 
(http://hg.nginx.org/nginx/rev/4a9d28f8f39e), nginx 1.19.9, though 
it might make sense to re-visit ngx_http_discard_request_body() 
anyway.

-- 
Maxim Dounin
http://mdounin.ru/