<html><head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
</head>
<body>
<p><br>
</p>
<div class="moz-cite-prefix">On 3/5/22 23:05, Maxim Dounin wrote:<br>
</div>
<blockquote type="cite" cite="mid:YiQzGrpNwjYL2B7a@mdounin.ru">
<pre class="moz-quote-pre" wrap="">Hello!
On Thu, Mar 03, 2022 at 02:04:21PM -0500, Marcus Ball wrote:
</pre>
<blockquote type="cite">
<pre class="moz-quote-pre" wrap="">I recently encountered an issue where Nginx would hang for a very long
time, if not indefinitely, on responses which exceeded the FastCGI
buffer size (> ~4000 bytes) from an upstream source which, in this case,
was PHP-FPM. This issue appeared to only be happening on DigitalOcean's
App Platform service; I couldn't reproduce it locally. I did a lot of
testing and digging around, I eventually tracked it back to
DigitalOcean's system not supporting the `EPOLLRDHUP` event. After much
debugging and reading through Nginx's source code, I believe I found the
source to be two conditions which were missing a check for
`ngx_use_epoll_rdhup`. I made the changes and rebuilt nginx and
everything appears to be working fine now.
If anyone needs to reproduce the issue, I've published a basic example
at <a class="moz-txt-link-freetext" href="https://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fmarcusball%2Fnginx-epoll-bug&data=04%7C01%7C%7Cfde67f80c99f4344ac4108d9ff26ba57%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637821364072127312%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=JknoAPGVXqPEaACMneRDZxH%2FkHjA4xBmONgvh%2BLpbqE%3D&reserved=0">https://nam12.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fmarcusball%2Fnginx-epoll-bug&data=04%7C01%7C%7Cfde67f80c99f4344ac4108d9ff26ba57%7C84df9e7fe9f640afb435aaaaaaaaaaaa%7C1%7C0%7C637821364072127312%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=JknoAPGVXqPEaACMneRDZxH%2FkHjA4xBmONgvh%2BLpbqE%3D&reserved=0</a>. There are also
corresponding Docker Hub images which should be able to demonstrate an
example project with the bug and with the fix if they are deployed to
App Platform: `marcusball/nginx-rdhup-bug:without-fix` and
`marcusball/nginx-rdhup-bug:with-fix` respectively.
</pre>
</blockquote>
<pre class="moz-quote-pre" wrap="">
Thanks for the investigation.
The rev->available shouldn't be 0 unless it was set to 0 due to
reading more than (or equal to) the amount of data reported via
ioctl(FIONREAD) during the particular event loop iteration. And
it will be again set to -1 as long as an additional event is
reported on the socket. That is, it shouldn't hang when epoll()
is working properly and reports all data additionally received
after all the data available at the time of the previous
epoll_wait() return were read by nginx.
I suspect this doesn't work due to issues with DigitalOcean's App
Platform's / gVisor's epoll() emulation layer. Most likely, it
fails to report additional events once nginx reads the amount of
data reported by ioctl(FIONREAD). Or ioctl(FIONREAD) simply
reports incorrect amount of data (or just 0).
Debug log might be helpful to further investigate what goes on
here. It would be great if you'll provide one for additional
analysis.
As far as I understand, proper workaround for this would be to
compile nginx with --with-cc-opt="-DNGX_HAVE_FIONREAD=0", that is,
with ioctl(FIONREAD) explicitly disabled. Please test if it works
for you.
</pre>
</blockquote>
<br>
<pre>Hi,
</pre>
<pre>Thank you for the suggestion. I tried using the
--with-cc-opt="-DNGX_HAVE_FIONREAD=0" compilation option, and
that also appeared to fix the issue with the response hanging.
However, I'm not exactly sure that is the best solution.
First, this would be less than ideal for this circumstance,
as needing to compile a custom build would make it a lot more
difficult to use Nginx within off-the-shelf components,
such as Heroku buildpacks (heroku/php), which is how I initially
encountered this problem. As a result t would greatly reduce
the main selling point of a service like DigitalOcean's App Platform
which is being able to simply deploy code without needing to worry
about the configuration or maintenance of the server.
More importantly, while disabling FIONREAD appears to address the
issue of the request hanging, I *think* it may be more of a
workaround. I certainly may be mistaken, but I still believe
the patch I submitted address an actual bug which should be fixed.
Basically, if I'm understanding everything properly, I think
that `rev->available` is working correctly. I'm going to use
`ngx_readv_chain.c` with FIONREAD enabled as an example:
As Nginx reads the last of the response from upstream (PHP-FPM)
`readv` receives the remaining body (line 121), `rev->available`
is >= 0, so `n` is subtracted and `rev->available = 0` (L# 171).
The problem is that once `ngx_readv_chain` is called again,
the condition at line 63 is encountered:
if (rev->available == 0 && !rev->pending_eof) {
return NGX_AGAIN;
}
`rev->available` and `rev->pending_eof` are both `0`, so
`NGX_AGAIN` is returned. This is essentially where the "hang"
occurs: `rev->available` and `rev->pending_eof` always
remain zero, and Nginx keeps attempting to read again.
The reason I'm fairly confident this is a bug is that,
with the exception of one line in `ngx_kqueue_module` which
I think is not applicable here, `rev->pending_eof` is
only set to `1` in exactly one place:
ngx_epoll_module.c:887:
#if (NGX_HAVE_EPOLLRDHUP)
if (revents & EPOLLRDHUP) {
rev->pending_eof = 1;
}
#endif
Obviously, this line will never be hit if EPOLLRDHUP is not
available. This is why `pending_eof` is always zero and Nginx
will continue to try to read from upstream and never complete
the response. This is why I think adding the check for
`ngx_use_epoll_rdhup` to mirror the use of other occurrences of
`rev->pending_eof` (like `ngx_readv_chain:205`) appears
to make sense.
Here are a few different logs, note these are the full logs from
the containerized application so they also include some
Nginx access logs, as well as PHP-FPM logs mixed in, but the
vast majority is the Nginx debug log which can be differentiated
via the full timestamp.
WITH THE ISSUE: <a class="moz-txt-link-freetext" href="https://pastebin.com/SKerUPX8">https://pastebin.com/SKerUPX8</a>
Also note, this contains two requests: the first succeeds,
then the second experiences the issue of the response never
completing; it only "completes" when I killed `curl` and
terminated the client connection.
WITH -DNGX_HAVE_FIONREAD=0: <a class="moz-txt-link-freetext" href="https://pastebin.com/xGvxwbLz">https://pastebin.com/xGvxwbLz</a>
WITH MY PATCH: <a class="moz-txt-link-freetext" href="https://pastebin.com/GtmdLviz">https://pastebin.com/GtmdLviz</a>
Marcus Ball
</pre>
</body>
</html>