Hi Maxim, so I dig into it a bit further and it seems as that I made an error in pairing of tcpdump outputs with nginx error logs. I triple checked it now and the upstream server really killed the connection without sending a response in cases nginx triggers an error.
I am sorry for the noise. Regards Jiri Horky On 10/17/2014 08:01 AM, Jiri Horky wrote: > Hi Max, > > thanks for the explanation, I agree that from the traces, it really > looks like there were no data available in the socket from the upstream, > thus a different situation than I posted the first time. I will try to > reproduce the problem with both, debug log and wireshark traces that > will match and will get back to you. > > Jirka H. > > On 10/17/2014 06:58 AM, Maxim Dounin wrote: >> Hello! >> >> On Fri, Oct 17, 2014 at 12:48:43AM +0200, Jiri Horky wrote: >> >> [...] >> >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 connect to 1.1.1.1:8888, >>> fd:184 #12552 >> Here connection is stablished to an upstream server. >> >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream connect: -2 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 posix_memalign: >>> 0000000000FD3720:128 @16 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 event timer add: 184: >>> 90000:1413499405670 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http finalize request: -4, >>> "/en-us/?" a:1, c:2 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http request count:2 blk:0 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 delete posted event >>> 0000000000D36008 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http run request: "/en-us/?" >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream check client, >>> write event:1, "/en-us/" >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream recv(): -1 >>> (11: Resource temporarily unavailable) >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 post event 0000000000D39818 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 delete posted event >>> 0000000000D39818 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream request: >>> "/en-us/?" >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream send request >>> handler >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream send request >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 chain writer buf fl:1 s:1618 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 chain writer in: >>> 0000000001041398 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 writev: 1618 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 chain writer out: >>> 0000000000000000 >> Request is written into the socket. >> >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 event timer del: 184: >>> 1413499405670 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 event timer add: 184: >>> 90000:1413499405670 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 post event 0000000000D33008 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 post event 0000000000D39818 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 delete posted event >>> 0000000000D33008 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream request: >>> "/en-us/?" >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 http upstream process header >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 malloc: 0000000000FAB620:8192 >>> 2014/10/17 00:41:55 [debug] 27396#0: *12485 recv: fd:184 0 of 8192 >>> 2014/10/17 00:41:55 [error] 27396#0: *12485 upstream prematurely closed >>> connection while reading response header from upstream, client: >>> 68.39.176.125, server: my.upstream.com, request: "GET /en-us/ HTTP/1.1", >>> upstream: "http://1.1.1.1:8888/en-us/";, host: "my.upstream.com", >>> referrer: "https://id.upstream.com/en-us/confirm/registration?token=TOKEN"; >> And reading from the socket indicate that it's closed. >> >> Packet traces you previously posted look unrelated to this debug >> log. In this case, there is either no response from the upstream >> at all, or the response contents are lost due to RST from the >> upstream. >> >> If, as you wrote, your backend "forcibly closes the connection", >> the reason may be that it does so by using close() with SO_LINGER, >> and this in turn results in RST being send to nginx in some cases. >> >> In either case debug log suggests there is nothing wrong on nginx >> side, you should focus on your backend instead. >> _______________________________________________ nginx mailing list [email protected] http://mailman.nginx.org/mailman/listinfo/nginx
