Strange requests stalling inside nginx

[MichaelLogutov]

Hello.
We have some strange issues when requests seems to stall inside nginx - in
nginx log we see that request took 1 second (and was terminated by client
timeout), while excactly the same request (we have special unique headers to
mark them) from the uwsgi logs took only 100ms to complete.

We also saw some very strange pauses in nginx debug log:

2017/01/26 20:17:51 [debug] 2749#0: *75780960 get rr peer, try: 2
2017/01/26 20:17:51 [debug] 2749#0: *75780960 get rr peer, current:
00007F6EC6C3D1F0 -1
2017/01/26 20:17:51 [debug] 2749#0: *75780960 stream socket 500
2017/01/26 20:17:51 [debug] 2749#0: *75780960 epoll add connection: fd:500
ev:80002005
2017/01/26 20:17:51 [debug] 2749#0: *75780960 connect to 10.0.0.176:80,
fd:500 #75780961
2017/01/26 20:17:51 [debug] 2749#0: *75780960 http upstream connect: -2
2017/01/26 20:17:51 [debug] 2749#0: *75780960 posix_memalign:
00007F6EC5213D60:128 @16
2017/01/26 20:17:51 [debug] 2749#0: *75780960 event timer add: 500:
10000:1485451081089
2017/01/26 20:17:51 [debug] 2749#0: *75780960 http finalize request: -4,
"/api/info/account/type/278933/?" a:1, c:2
2017/01/26 20:17:51 [debug] 2749#0: *75780960 http request count:2 blk:0
2017/01/26 20:17:51 [debug] 2749#0: *75780960 http run request:
"/api/info/account/type/278933/?"
2017/01/26 20:17:51 [debug] 2749#0: *75780960 http upstream check client,
write event:1, "/api/info/account/type/278933/"
2017/01/26 20:17:51 [debug] 2749#0: *75780960 http upstream recv(): -1 (11:
Resource temporarily unavailable)
2017/01/26 20:17:54 [debug] 2749#0: *75780960 http upstream request:
"/api/info/account/type/278933/?"
2017/01/26 20:17:54 [debug] 2749#0: *75780960 http upstream send request
handler
2017/01/26 20:17:54 [debug] 2749#0: *75780960 http upstream send request
2017/01/26 20:17:54 [debug] 2749#0: *75780960 http upstream send request
body
2017/01/26 20:17:54 [debug] 2749#0: *75780960 chain writer buf fl:1 s:433
2017/01/26 20:17:54 [debug] 2749#0: *75780960 chain writer in:
00007F6E975088B0
2017/01/26 20:17:54 [debug] 2749#0: *75780960 writev: 433 of 433
2017/01/26 20:17:54 [debug] 2749#0: *75780960 chain writer out:
0000000000000000
2017/01/26 20:17:54 [debug] 2749#0: *75780960 event timer del: 500:
1485451081089
2017/01/26 20:17:54 [debug] 2749#0: *75780960 event timer add: 500:
200000:1485451274089
2017/01/26 20:17:54 [debug] 2749#0: *75780960 http upstream request:
"/api/info/account/type/278933/?"
2017/01/26 20:17:54 [debug] 2749#0: *75780960 http upstream process header
2017/01/26 20:17:54 [debug] 2749#0: *75780960 malloc: 00007F6E97AC0070:4096
2017/01/26 20:17:54 [debug] 2749#0: *75780960 posix_memalign:
00007F6ECACC95D0:4096 @16
2017/01/26 20:17:54 [debug] 2749#0: *75780960 recv: fd:500 408 of 4096
2017/01/26 20:17:54 [debug] 2749#0: *75780960 http proxy status 200 "200
OK"

Any help would be appreciated.

Posted at Nginx Forum: https://forum.nginx.org/read.php?2,272357,272357#msg-272357