Hello,
On Fri, Dec 29, 2017 at 2:31 PM, Willy Tarreau <w...@1wt.eu> wrote:
> On Fri, Dec 29, 2017 at 11:45:55AM +0100, Lukas Tribus wrote:
>> The FIN behavior comes from a48c141f4 ("BUG/MAJOR: connection: refine
>> the situations where we don't send shutw()"), which also hit 1.8.2, so
>> that explains the change in behavior between 1.8.1 and 1.8.2.
>
> For me it happens only when I have "option httpclose" in the configuration,
> ie we end up in tunnel mode. I can't reproduce it with either keep-alive,
> http-server-close nor forceclose. At least abortonclose is now safe
> regarding this. Does this match your observations as well ?
No, I'm using the default http-keep-alive mode.
Haproxy calls shutdown() after the HTTP payload was transmitted, nginx
in the default configuration or nc for that matter closes the
connection (we see recvfrom = 0) and then we close():
14:39:57.075589 gettimeofday({1514554797, 75637}, NULL) = 0
14:39:57.075706 gettimeofday({1514554797, 75746}, NULL) = 0
14:39:57.075809 epoll_wait(3, [{EPOLLIN, {u32=4, u64=4}}], 200, 1000) = 1
14:39:57.283293 gettimeofday({1514554797, 283332}, NULL) = 0
14:39:57.283453 accept4(4, {sa_family=AF_INET, sin_port=htons(50192),
sin_addr=inet_addr("127.0.0.1")}, [16], SOCK_NONBLOCK) = 8
14:39:57.283711 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0
14:39:57.283917 accept4(4, 0x7ffd16cfc9f0, 0x7ffd16cfc9e8,
SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable)
14:39:57.284197 read(8, 0x26f9713, 5) = -1 EAGAIN (Resource
temporarily unavailable)
14:39:57.284399 epoll_ctl(3, EPOLL_CTL_ADD, 8, {EPOLLIN|EPOLLRDHUP,
{u32=8, u64=8}}) = 0
14:39:57.284514 gettimeofday({1514554797, 284546}, NULL) = 0
14:39:57.284630 epoll_wait(3, [{EPOLLIN, {u32=8, u64=8}}], 200, 1000) = 1
14:39:57.297577 gettimeofday({1514554797, 297646}, NULL) = 0
14:39:57.297831 read(8, "\26\3\1\0\317", 5) = 5
14:39:57.298051 read(8,
"\1\0\0\313\3\0030\243\205\266H\202.\324\3417\262\33\25Bh\"_M\237\216\0169-\3778\4"...,
207) = 207
14:39:57.298283 gettimeofday({1514554797, 298324}, NULL) = 0
14:39:57.298500 gettimeofday({1514554797, 298539}, NULL) = 0
14:39:57.298893 gettimeofday({1514554797, 298932}, NULL) = 0
14:39:57.299143 gettimeofday({1514554797, 299181}, NULL) = 0
14:39:57.299274 gettimeofday({1514554797, 299318}, NULL) = 0
14:39:57.299394 gettimeofday({1514554797, 299427}, NULL) = 0
14:39:57.302972 write(8,
"\26\3\3\0j\2\0\0f\3\3a\323i\222I\33\21f\361\352\303\257\233\251\211y\315z\3310\254"...,
2938) = 2938
14:39:57.303303 read(8, 0x26fce93, 5) = -1 EAGAIN (Resource
temporarily unavailable)
14:39:57.303549 gettimeofday({1514554797, 303585}, NULL) = 0
14:39:57.303762 epoll_wait(3, [{EPOLLIN, {u32=8, u64=8}}], 200, 1000) = 1
14:39:57.334310 gettimeofday({1514554797, 334383}, NULL) = 0
14:39:57.334572 read(8, "\26\3\3\0F", 5) = 5
14:39:57.334780 read(8,
"\20\0\0BA\4f\315w#\277\37\216\21W\0074\273\227`E\305\16\203\260O\216(\201\270g\305"...,
70) = 70
14:39:57.335413 read(8, "\24\3\3\0\1", 5) = 5
14:39:57.335709 read(8, "\1", 1) = 1
14:39:57.335975 read(8, "\26\3\3\0(", 5) = 5
14:39:57.336186 read(8,
"tQ\325'wD\2370\245\242<\362\247\300j\247b\303\367\24\rb\247\251\236\260GG\265(\22="...,
40) = 40
14:39:57.336395 gettimeofday({1514554797, 336431}, NULL) = 0
14:39:57.336589 write(8,
"\24\3\3\0\1\1\26\3\3\0(0\r\251\371\4X\3249\212Py\330\310\320\r\315h\10\376Oo"...,
51) = 51
14:39:57.336849 read(8, 0x26f50e3, 5) = -1 EAGAIN (Resource
temporarily unavailable)
14:39:57.337071 gettimeofday({1514554797, 337107}, NULL) = 0
14:39:57.337264 epoll_wait(3, [{EPOLLIN, {u32=8, u64=8}}], 200, 1000) = 1
14:39:57.377717 gettimeofday({1514554797, 377794}, NULL) = 0
14:39:57.377942 read(8, "\27\3\3\0000", 5) = 5
14:39:57.378166 read(8,
"tQ\325'wD\2371\307\270^Y\233:\312A\232\355\346\247\35\235C\343\31_gR\272\307\355\362"...,
48) = 48
14:39:57.378439 read(8, "\27\3\3\0003", 5) = 5
14:39:57.378750 read(8,
"tQ\325'wD\2372\331\327\363N1\312\277H*${vDA\24w\346\216\211\273@\265R\344"...,
51) = 51
14:39:57.378972 read(8, "\27\3\3\0%", 5) = 5
14:39:57.379214 read(8,
"tQ\325'wD\2373@\300$\32\267\217@\354\226\224Z\246\253\216(\6\v=\213u\220\3730\237"...,
37) = 37
14:39:57.379431 read(8, "\27\3\3\0o", 5) = 5
14:39:57.379642 read(8,
"tQ\325'wD\2374&\223\263yW\0x\307\344\365\26\305\33q\355\t\314c'\322>\0\276\324"...,
111) = 111
14:39:57.379862 read(8, 0x26f50e3, 5) = -1 EAGAIN (Resource
temporarily unavailable)
14:39:57.380070 setsockopt(8, SOL_TCP, TCP_QUICKACK, [1], 4) = 0
14:39:57.380273 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 9
14:39:57.380482 fcntl(9, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
14:39:57.380693 setsockopt(9, SOL_TCP, TCP_NODELAY, [1], 4) = 0
14:39:57.380911 connect(9, {sa_family=AF_INET, sin_port=htons(81),
sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now
in progress)
14:39:57.381209 gettimeofday({1514554797, 381268}, NULL) = 0
14:39:57.381435 epoll_wait(3, [], 200, 0) = 0
14:39:57.381640 gettimeofday({1514554797, 381680}, NULL) = 0
14:39:57.381865 write(8, "\27\3\3\00000\r\251\371\4X\324:\375v\327o?
\271c\362\216\f\25\3752\320\346&\324\257"..., 53) = 53
14:39:57.382142 sendto(9, "POST /111 HTTP/1.1\r\nuser-agent: "...,
169, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 169
14:39:57.382405 gettimeofday({1514554797, 382442}, NULL) = 0
14:39:57.382590 epoll_wait(3, [], 200, 0) = 0
14:39:57.382769 gettimeofday({1514554797, 382804}, NULL) = 0
14:39:57.382948 recvfrom(9, 0x26cb234, 15360, 0, NULL, NULL) = -1
EAGAIN (Resource temporarily unavailable)
14:39:57.383126 epoll_ctl(3, EPOLL_CTL_ADD, 9, {EPOLLIN|EPOLLRDHUP,
{u32=9, u64=9}}) = 0
14:39:57.383311 gettimeofday({1514554797, 383347}, NULL) = 0
14:39:57.383493 epoll_wait(3, [{EPOLLIN, {u32=8, u64=8}}], 200, 1000) = 1
14:39:57.391886 gettimeofday({1514554797, 391982}, NULL) = 0
14:39:57.392212 read(8, "\27\3\3\0(", 5) = 5
14:39:57.392458 read(8,
"tQ\325'wD\2375\222\202\1\241\277\35\347\213;\221&\211\303g\322\226[\334\10Z\20\332\36s"...,
40) = 40
14:39:57.392671 read(8, 0x2700eb3, 5) = -1 EAGAIN (Resource
temporarily unavailable)
14:39:57.392868 sendto(9, "bla=bla", 7, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 7
14:39:57.393178 shutdown(9, SHUT_WR) = 0
14:39:57.394373 gettimeofday({1514554797, 394456}, NULL) = 0
14:39:57.395673 epoll_wait(3, [{EPOLLIN|EPOLLHUP|EPOLLRDHUP, {u32=9,
u64=9}}], 200, 0) = 1
14:39:57.395897 gettimeofday({1514554797, 395935}, NULL) = 0
14:39:57.396077 write(8,
"\27\3\3\00020\r\251\371\4X\324;\t\302\207\251\375Gn\252Q\215S\370\370\34_w\221\256%"...,
55) = 55
14:39:57.396280 recvfrom(9, "", 15360, 0, NULL, NULL) = 0
14:39:57.396459 close(9) = 0
14:39:57.396634 gettimeofday({1514554797, 396670}, NULL) = 0
14:39:57.396813 epoll_wait(3, [], 200, 0) = 0
14:39:57.396985 gettimeofday({1514554797, 397022}, NULL) = 0
14:39:57.397164 write(8,
"\27\3\3\0\2470\r\251\371\4X\324<:u\210\25\272E\200\253\26\3jq\372\336\350m\275\244\271"...,
172) = 172
14:39:57.397373 sendmsg(5, {msg_name(16)={sa_family=AF_INET,
sin_port=htons(514), sin_addr=inet_addr("10.0.0.4")},
msg_iov(8)=[{"<46>Dec 29 14:39:57 ", 20}, {"haproxy", 7}, {"[", 1},
{"12088", 5}, {"]: ", 3}, {"", 0}, {"127.0.0.1:50192
[29/Dec/2017:14:"..., 135}, {"\n", 1}], msg_controllen=0,
msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 172
14:39:57.397645 gettimeofday({1514554797, 397755}, NULL) = 0
14:39:57.397870 epoll_wait(3, [{EPOLLIN, {u32=8, u64=8}}], 200, 1000) = 1
14:39:57.403815 gettimeofday({1514554797, 403901}, NULL) = 0
14:39:57.404055 read(8, "\27\3\3\0!", 5) = 5
14:39:57.404292 read(8,
"tQ\325'wD\2376\241\235\267\305\370+\370\361\312Nj\32u9\257\202\356rR\375\350|\224\355"...,
33) = 33
14:39:57.404504 read(8, 0x2700eb3, 5) = -1 EAGAIN (Resource
temporarily unavailable)
14:39:57.404692 gettimeofday({1514554797, 404729}, NULL) = 0
14:39:57.404875 epoll_wait(3, [{EPOLLIN, {u32=8, u64=8}}], 200, 1000) = 1
14:39:57.409970 gettimeofday({1514554797, 410006}, NULL) = 0
14:39:57.410075 read(8, "\25\3\3\0\32", 5) = 5
14:39:57.410189 read(8,
"tQ\325'wD\2377e\367\252:\270\353\202\345kYnF\36w=r\300S", 26) = 26
14:39:57.410320 close(8) = 0
14:39:57.410459 gettimeofday({1514554797, 410492}, NULL) = 0
14:39:57.410547 epoll_wait(3, [], 200, 1000) = 0
14:39:58.411989 gettimeofday({1514554798, 412088}, NULL) = 0
14:39:58.412417 gettimeofday({1514554798, 412484}, NULL) = 0
14:39:58.412743 epoll_wait(3, [], 200, 1000) = 0
14:39:59.414155 gettimeofday({1514554799, 414249}, NULL) = 0
14:39:59.414494 gettimeofday({1514554799, 414537}, NULL) = 0
