Opened 3 years ago

Closed 3 years ago

Last modified 15 months ago

#2169 closed defect (invalid)

Nginx causing missing body content data since v1.19.1.

Reported by: breisig@… Owned by:
Priority: critical Milestone:
Component: documentation Version: 1.19.x
Keywords: Cc:
uname -a: Linux localdev.myserver.com 4.18.0-301.1.el8.x86_64 #1 SMP Tue Apr 13 16:24:22 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.20.0
built by gcc 8.4.1 20200928 (Red Hat 8.4.1-1) (GCC)
built with OpenSSL 1.1.1g FIPS 21 Apr 2020
TLS SNI support enabled
configure arguments: --prefix=/usr --conf-path=/etc/nginx/nginx.conf --error-log-path=/var/log/nginx/error.log --pid-path=/run/nginx.pid --lock-path=/var/lib/ --http-log-path=/var/log/nginx/access.log --with-ipv6 --with-http_ssl_module --with-http_realip_module --with-http_addition_module --with-http_xslt_module --with-http_image_filter_module --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_gzip_static_module --with-http_random_index_module --with-http_secure_link_module --with-http_degradation_module --with-http_stub_status_module --without-mail_pop3_module --without-mail_imap_module --without-mail_smtp_module --without-http_autoindex_module --user=daemon --group=daemon --with-ld-opt=-ldl --http-fastcgi-temp-path=/tmp --with-http_v2_module --with-http_perl_module --with-cc-opt=-DTCP_FASTOPEN=23 --with-file-aio --add-module=./nginx-auth-ldap

Description

We are running puma + latest ruby on rails behind nginx. We have been running v1.18.0 and we recently upgraded to v1.20.0 and noticed nginx is causing missing characters. Like as if the buffer disconnects abit early.

Example. When I view the page source output using nginx v1.18.0, I see the *propery* output and the end of the stream.


<button name="button" type="button" title="Yes, I accept" class="button_base inverted no_wrap" id="btn_cookie">Yes, I accept</button>
</div>
</div>

</body>
</html>


But in v1.20.0, the page source is missing data.


<button name="button" type="button" title="Yes, I accept" class="button_base inverted no_wrap" id="btn_cookie">Yes, I accept</button>
</div>
</div>

</


It looks like the </body></html> tags are missing from the page. I have compiled nginx versions from 1.20.0 down to 1.19.0 and noticed that it started breaking in nginx 1.19.1. So something between 1.19.0 and 1.19.1 broke nginx. This is critical to fix.

Change History (5)

comment:1 by breisig@…, 3 years ago

Moved to the proper component section.

comment:2 by Maxim Dounin, 3 years ago

One of the expected changes in 1.19.1 is that extra data sent by the backend server are always discarded:

    *) Change: now extra data sent by a backend are always discarded.

When this happens, you should see a relevant warning in the error log, [warn] ... upstream sent more data than specified in "Content-Length" header.... Basically this means that the upstream server returned an invalid HTTP response, with incorrectly calculated Content-Length.

Previously such a response might happen to be sent to the client with the extra data included: if the extra data were available in the same read() operation from the backend, and, for example, gzip was used, so nginx removed the Content-Length header from the response.

The behaviour you describe suggests this is exactly what happens in your case. That is, most likely the root cause is miscalculated Content-Length on the response sent by your backend server. You may want to check if nginx complains in the logs, and fix your backend accordingly.

In my practice such errors often happen because the Content-Length header is generated with the number of characters in the response instead of the number of bytes, though there might be other reasons as well.

Just in case, as long as your backend uses HTTP, an easy way to do an independent check of your backend is to use curl to directly connect your backend. It will properly count bytes in the response and will only show the part which is properly announced in the Content-Length header. Further, with -vv verbosity it also prints information about extra data it found during reading. For example, with the following test server returning an incorrect response:

$ printf "HTTP/1.0 200 OK\nContent-Length: 10\n\nthis is a too long body\n" | nc -l 8080

The curl output is as follows:

$ curl -vv http://127.0.0.1:8080/
*   Trying 127.0.0.1:8080...
* Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)
> GET / HTTP/1.1
> Host: 127.0.0.1:8080
> User-Agent: curl/7.75.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
* HTTP 1.0, assume close after body
< HTTP/1.0 200 OK
< Content-Length: 10
< 
* Excess found in a read: excess = 14, size = 10, maxdownload = 10, bytecount = 0
* Closing connection 0
this is a $ 

Note that the output is truncated at 10 characters, as specified in the Content-Length, and the Excess found in a read... message is printed.

comment:3 by breisig@…, 3 years ago

Thank you for the extra information. I was doing some further investigation between Nginx 1.18.0 ad Nginx 1.20.0. You were right that when I enabled warning in the error log, I can see the following in *both* versions.


2021/04/25 11:17:36 [warn] 15295#0: *247 upstream sent more data than specified in "Content-Length" header while reading upstream, client: 127.0.0.1, server: mytestwebsite.com, request: "GET / HTTP/1.1", upstream: "http://unix:/var/run/puma/puma.sock:/", host: "mytestwebsite.com"


However, I just noticed something interesting inconsistency with v1.18.0 with missing data when compressed vs not compressed.


curl -vv http://127.0.0.1:81/

<button name="button" type="button" title="Yes, I accept" class="button_base inverted no_wrap" id="btn_cookie">Yes, I accept</button>
</div>
</div>

</body>

  • Connection #0 to host 127.0.0.1 left intact

</htmlroot@localdev ~#



curl -vv http://127.0.0.1:81/ --compressed

<button name="button" type="button" title="Yes, I accept" class="button_base inverted no_wrap" id="btn_cookie">Yes, I accept</button>
</div>
</div>

</body>
</html>

  • Connection #0 to host 127.0.0.1 left intact

It seems with nginx 1.18.0, If we enabled compression in curl [--compressed], the entire data is sent but when we don't pass compression, it's missing some characters. In nginx 1.20.0, it's consistent when and when not compressed with curl. [missing characters]

comment:4 by Maxim Dounin, 3 years ago

Resolution: invalid
Status: newclosed

You were right that when I enabled warning in the error log, I can see the following in *both* versions.

Thanks for confirming. Closing this, as clearly this is a problem in your backend, and nginx is doing exactly what it is expected to do. To fix things you have to fix your backend.

It seems with nginx 1.18.0, If we enabled compression in curl [--compressed], the entire data is sent but when we don't pass compression, it's missing some characters. In nginx 1.20.0, it's consistent when and when not compressed with curl.

As already explained in comment:2, when gzip is used, nginx removes the Content-Length header from the response, so all the data sent by your backend in a response with incorrect Content-Length were available to the client with extra data included. With gzip disabled nginx used to sent the same data as well, but with the incorrect Content-Length header from as in the backend's response, so extra data are usually discarded by the client. In nginx 1.19.1+, extra data are always discarded by nginx itself.

comment:5 by breisig@…, 3 years ago

Thank you Maxim. I have found the issue and it was our code modifying the content length. Once fixed, it works perfect in nginx 1.18.0 and 1.20.0 :-)

Note: See TracTickets for help on using tickets.