id,summary,reporter,owner,description,type,status,priority,milestone,component,version,resolution,keywords,cc,uname,nginx_version 1904,sendfile with io-threads - nginx mistakenly considers premature client connection close if client sends FIN at response end,Shmulik Biran,,"Hi, The scenario is as follows: 1. Nginx is configured to work with sendfile and io-threads. 2. Client sends a request, and after receiving the entire content it sends a FIN-ACK, closing the connection. 3. Nginx occasionally considers the transaction as prematurely closed by the client even though the FIN-ACK packet acks the entire content. The effect i've seen is that ""$body_bytes_sent"" holds partial data (up to the last ""successful"" sendfile call) and ""$request_completion"" is empty. I guess there are other effects though these are the one i'm using, so they popped up. From what i've managed to understand from the code it looks like the scenario is that the read_event_handler ""ngx_http_test_reading"" is called before the completed task from the io-thread is handled by the main thread, effectively making Nginx think the client connection close happened earlier. I've managed to reproduce it or latest nginx with rather simple config, but it's time sensitive so it doesn't happen on each transaction. I saw that using a bigger file with rate-limit increases the chances. Config: {{{ worker_processes 1; events { worker_connections 1024; } http { keepalive_timeout 120s; keepalive_requests 1000; log_format main ""$status\t$sent_http_content_length\t$body_bytes_sent\t$request_completion""; access_log logs/access.log main; error_log logs/error.log info; aio threads; sendfile on; limit_rate 10m; server { listen 0.0.0.0:1234 reuseport; location = /test-sendfile-close { alias files/10mb; } } } }}} * files/10mb is a file of size 10MB, created with ""dd"" (dd if=/dev/zero of=files/10mb bs=10M count=1) I then tail -F the access log and the error log file, and send these requests from the same machine: {{{ while true; do wget -q ""http://10.1.1.1:1234/test-sendfile-close""; done }}} The output i get in error log and access log (in this order) in case of a good transaction is: {{{ 2019/12/17 14:52:34 [info] 137444#137444: *1 client 10.1.1.1 closed keepalive connection 200 10485760 10485760 OK }}} But every few transactions i get this output instead: {{{ 2019/12/17 14:52:38 [info] 137444#137444: *7 client prematurely closed connection while sending response to client, client: 10.1.1.1, server: , request: ""GET /test-sendfile-close HTTP/1.1"", host: ""10.1.1.1:1234"" 200 10485760 3810520 }}} As you can see, the reported sent bytes is lower than the actual value, and the request_completion is empty. I understand that the closer the client is to Nginx the higher chances this could happen, but it's not just a lab issue - we've seen this in a field trial with clients in a distance of ~30ms RTT, with higher load of course. If there is need for any other information, or anything else - i'll be glad to provide it. I appreciate the help, and in general - this great product you've built! Thank you, Shmulik Biran",defect,accepted,minor,,nginx-core,1.17.x,,sendfile io-threads premature,,Linux rd10.it.qwilt.com 3.10.0-862.3.2.el7.x86_64 #1 SMP Mon May 21 23:36:36 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux,"nginx version: nginx/1.17.6 built by gcc 4.8.5 20150623 (Red Hat 4.8.5-28) (GCC) configure arguments: --prefix=../build-dir --with-threads --with-debug "