diff options
Diffstat (limited to 'doc/internals/notes-pollhup.txt')
| -rw-r--r-- | doc/internals/notes-pollhup.txt | 281 |
1 files changed, 281 insertions, 0 deletions
diff --git a/doc/internals/notes-pollhup.txt b/doc/internals/notes-pollhup.txt new file mode 100644 index 0000000..ced332b --- /dev/null +++ b/doc/internals/notes-pollhup.txt @@ -0,0 +1,281 @@ +tcp mode 8001->8008 + + +Remote test: +============ + +willy@up1:~$ echo bar | ncat -lp8008 +willy@wtap:haproxy$ echo foo | ncat 127.1 8001 + +17:09:53.663154 epoll_wait(3, [{EPOLLIN, {u32=5, u64=5}}], 200, 1000) = 1 +17:09:54.582146 accept4(5, {sa_family=AF_INET, sin_port=htons(33378), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_NONBLOCK) = 8 +17:09:54.582299 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:09:54.582527 accept4(5, 0x7ffc4a8bf330, [128], SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) +17:09:54.582655 recvfrom(8, "foo\n", 15360, 0, NULL, NULL) = 4 +17:09:54.582727 recvfrom(8, "", 15356, 0, NULL, NULL) = 0 +17:09:54.582827 socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 9 +17:09:54.582878 setsockopt(9, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:09:54.582897 connect(9, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("10.0.3.82")}, 16) = -1 EINPROGRESS (Operation now in progress) +17:09:54.582941 sendto(9, "foo\n", 4, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = -1 EAGAIN (Resource temporarily unavailable) +17:09:54.582968 epoll_ctl(3, EPOLL_CTL_ADD, 9, {EPOLLOUT, {u32=9, u64=9}}) = 0 +17:09:54.582997 epoll_wait(3, [{EPOLLOUT, {u32=9, u64=9}}], 200, 1000) = 1 +17:09:54.583686 connect(9, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("10.0.3.82")}, 16) = 0 +17:09:54.583706 sendto(9, "foo\n", 4, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 4 +17:09:54.583733 recvfrom(9, 0x19c2300, 15360, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +17:09:54.583755 shutdown(9, SHUT_WR) = 0 +17:09:54.583775 epoll_ctl(3, EPOLL_CTL_MOD, 9, {EPOLLIN|EPOLLRDHUP, {u32=9, u64=9}}) = 0 +17:09:54.583802 epoll_wait(3, [{EPOLLIN, {u32=9, u64=9}}], 200, 1000) = 1 +17:09:54.584672 recvfrom(9, "bar\n", 16384, 0, NULL, NULL) = 4 +17:09:54.584713 recvfrom(9, "", 16380, 0, NULL, NULL) = 0 +17:09:54.584743 sendto(8, "bar\n", 4, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_MORE, NULL, 0) = 4 +17:09:54.584819 epoll_wait(3, [], 200, 0) = 0 +17:09:54.584901 epoll_wait(3, [], 200, 1000) = 0 + + +Notes: + - we had data available to try the connect() (see first attempt), despite + this during the retry we sent the connect again! + + - why do we wait before sending the shutw to the server if we already know + it's needed ? missing CF_SHUTW_NOW ? Missing request forwarding ? Missing + auto-close ? + + - response didn't feature HUP nor RDHUP + + +Local: + +17:15:43.010786 accept4(5, {sa_family=AF_INET, sin_port=htons(33506), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_NONBLOCK) = 8 +17:15:43.011013 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:15:43.011181 accept4(5, 0x7ffcd9092cd0, [128], SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) +17:15:43.011231 recvfrom(8, "foo\n", 15360, 0, NULL, NULL) = 4 +17:15:43.011296 recvfrom(8, "", 15356, 0, NULL, NULL) = 0 +17:15:43.011318 socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 9 +17:15:43.011340 setsockopt(9, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:15:43.011353 connect(9, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) +17:15:43.011395 sendto(9, "foo\n", 4, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 4 +17:15:43.011425 shutdown(9, SHUT_WR) = 0 +17:15:43.011459 recvfrom(9, "bar\n", 16384, 0, NULL, NULL) = 4 +17:15:43.011491 recvfrom(9, "", 16380, 0, NULL, NULL) = 0 +17:15:43.011525 sendto(8, "bar\n", 4, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_MORE, NULL, 0) = 4 +17:15:43.011584 epoll_wait(3, [], 200, 0) = 0 + +Notes: + - the shutdown() was properly done right after the sendto(), proving that + CF_SHUTW_NOW and auto-close were present. Maybe difference is sync vs async + send. + + +Local with delay before closing client: + +17:18:17.155349 epoll_wait(3, [{EPOLLIN, {u32=5, u64=5}}], 200, 1000) = 1 +17:18:17.727327 accept4(5, {sa_family=AF_INET, sin_port=htons(33568), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_NONBLOCK) = 8 +17:18:17.727553 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:18:17.727661 accept4(5, 0x7fff4eb9a0b0, [128], SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) +17:18:17.727798 recvfrom(8, 0xbda300, 15360, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +17:18:17.727830 socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 9 +17:18:17.727858 setsockopt(9, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:18:17.727877 connect(9, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) +17:18:17.727923 epoll_ctl(3, EPOLL_CTL_ADD, 8, {EPOLLIN|EPOLLRDHUP, {u32=8, u64=8}}) = 0 +17:18:17.727945 epoll_ctl(3, EPOLL_CTL_ADD, 9, {EPOLLOUT, {u32=9, u64=9}}) = 0 +17:18:17.727989 epoll_wait(3, [{EPOLLOUT, {u32=9, u64=9}}], 200, 1000) = 1 +17:18:17.728010 connect(9, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("127.0.0.1")}, 16) = 0 +17:18:17.728027 recvfrom(9, "bar\n", 15360, 0, NULL, NULL) = 4 +17:18:17.728055 recvfrom(9, 0xbd62f4, 15356, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +17:18:17.728073 sendto(8, "bar\n", 4, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 4 +17:18:17.728104 epoll_ctl(3, EPOLL_CTL_MOD, 9, {EPOLLIN|EPOLLRDHUP, {u32=9, u64=9}}) = 0 +17:18:17.728127 epoll_wait(3, [], 200, 1000) = 0 +17:18:18.729411 epoll_wait(3, [], 200, 1000) = 0 +17:18:19.730654 epoll_wait(3, [{EPOLLIN|EPOLLRDHUP, {u32=8, u64=8}}], 200, 1000) = 1 +17:18:20.299268 recvfrom(8, "", 16384, 0, NULL, NULL) = 0 +17:18:20.299336 epoll_ctl(3, EPOLL_CTL_DEL, 8, 0x7ff3a969f7d0) = 0 +17:18:20.299379 epoll_wait(3, [], 200, 0) = 0 +17:18:20.299401 shutdown(9, SHUT_WR) = 0 +17:18:20.299523 epoll_wait(3, [{EPOLLIN|EPOLLHUP|EPOLLRDHUP, {u32=9, u64=9}}], 200, 1000) = 1 +17:18:20.299678 recvfrom(9, "", 16384, 0, NULL, NULL) = 0 +17:18:20.299761 epoll_wait(3, [], 200, 0) = 0 + +Notes: server sent the response in two parts ("bar" then EOF) just due to +netcat's implementation. The second epoll_wait() caught it. + +Here we clearly see that : + - read0 alone returns EPOLLIN|EPOLLRDHUP + - read0 after shutw returns EPOLLIN|EPOLLRDHUP|EPOLLHUP + => difference indeed is "cannot write" + + +Local with a delay before closing the server: + +17:30:32.527157 epoll_wait(3, [{EPOLLIN, {u32=5, u64=5}}], 200, 1000) = 1 +17:30:33.216827 accept4(5, {sa_family=AF_INET, sin_port=htons(33908), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_NONBLOCK) = 8 +17:30:33.216957 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:30:33.216984 accept4(5, 0x7ffc1a1fb0c0, [128], SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) +17:30:33.217071 recvfrom(8, "GET / HTTP/1.0\r\n\r\n\n", 15360, 0, NULL, NULL) = 19 +17:30:33.217115 recvfrom(8, "", 15341, 0, NULL, NULL) = 0 +17:30:33.217135 socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 9 +17:30:33.217176 setsockopt(9, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +17:30:33.217190 connect(9, {sa_family=AF_INET, sin_port=htons(8000), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) +17:30:33.217233 sendto(9, "GET / HTTP/1.0\r\n\r\n\n", 19, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 19 +17:30:33.217272 shutdown(9, SHUT_WR) = 0 +17:30:33.217318 recvfrom(9, 0x109b2f0, 16384, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +17:30:33.217332 epoll_ctl(3, EPOLL_CTL_ADD, 9, {EPOLLIN|EPOLLRDHUP, {u32=9, u64=9}}) = 0 +17:30:33.217355 epoll_wait(3, [{EPOLLIN|EPOLLHUP|EPOLLRDHUP, {u32=9, u64=9}}], 200, 1000) = 1 +17:30:33.217377 recvfrom(9, "HTTP/1.0 200\r\nContent-length: 0\r\nX-req: size=19, time=0 ms\r\nX-rsp: id=dummy, code=200, cache=1, size=0, time=0 ms (0 real)\r\n\r\n", 16384, 0, NULL, NULL) = 126 +17:30:33.217395 close(9) = 0 +17:30:33.217411 sendto(8, "HTTP/1.0 200\r\nContent-length: 0\r\nX-req: size=19, time=0 ms\r\nX-rsp: id=dummy, code=200, cache=1, size=0, time=0 ms (0 real)\r\n\r\n", 126, MSG_DONTWAIT|MSG_NOSIGNAL|MSG_MORE, NULL, 0) = 126 +17:30:33.217464 close(8) = 0 +17:30:33.217496 epoll_wait(3, [], 200, 0) = 0 + + +Notes: + - RDHUP is properly present while some data remain pending. + - HUP is present since RDHUP + shutw + +It could be concluded that HUP indicates RDHUP+shutw and in no way indicates +the ability to avoid reading. + +Below HUP|ERR|OUT are reported on connection failures, thus WITHOUT read: + +accept4(5, {sa_family=AF_INET, sin_port=htons(39080), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_NONBLOCK) = 8 +setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +accept4(5, 0x7ffffba55730, [128], SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable) +recvfrom(8, "foo\n", 15360, 0, NULL, NULL) = 4 +recvfrom(8, 0x7f634dcfeff4, 15356, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 9 +fcntl(9, F_SETFL, O_RDONLY|O_NONBLOCK) = 0 +setsockopt(9, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +connect(9, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("10.0.3.82")}, 16) = -1 EINPROGRESS (Operation now in progress) +sendto(9, "foo\n", 4, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = -1 EAGAIN (Resource temporarily unavailable) +epoll_ctl(3, EPOLL_CTL_ADD, 8, {EPOLLIN|EPOLLRDHUP, {u32=8, u64=8}}) = 0 +epoll_ctl(3, EPOLL_CTL_ADD, 9, {EPOLLOUT, {u32=9, u64=9}}) = 0 +epoll_wait(3, [{EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=9, u64=9}}], 200, 1000) = 1 +getsockopt(9, SOL_SOCKET, SO_ERROR, [111], [4]) = 0 +recvfrom(9, "", 15360, 0, NULL, NULL) = 0 +close(9) = 0 + + +On a failed connect attempt immediately followed by a failed recv (all flags +set), we can see this: + +socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 8 +fcntl(8, F_SETFL, O_RDONLY|O_NONBLOCK) = 0 +setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 +connect(8, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("10.0.3.82")}, 16) = -1 EINPROGRESS (Operation now in progress) +recvfrom(8, 0x1084a20, 16384, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +epoll_ctl(3, EPOLL_CTL_ADD, 8, {EPOLLIN|EPOLLOUT|EPOLLRDHUP, {u32=8, u64=8}}) = 0 +epoll_wait(3, [{EPOLLIN|EPOLLOUT|EPOLLERR|EPOLLHUP|EPOLLRDHUP, {u32=8, u64=8}}], 200, 1000) = 1 +connect(8, {sa_family=AF_INET, sin_port=htons(8008), sin_addr=inet_addr("10.0.3.82")}, 16) = -1 ECONNREFUSED (Connection refused) +close(8) = 0 + +=> all flags are reported in case of error. + +It's also interesting to note that POLLOUT is still reported after a shutw, +and no send error is ever reported after shutw: + + shutdown(4, SHUT_WR) = 0 + poll([{fd=4, events=POLLIN|POLLOUT|POLLRDHUP}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}]) + +and: + shutdown(4, SHUT_WR) = 0 + sendto(5, "foo", 3, MSG_NOSIGNAL, NULL, 0) = 3 + poll([{fd=4, events=POLLIN|POLLOUT|POLLRDHUP}], 1, 0) = 1 ([{fd=4, revents=POLLIN|POLLOUT}]) + +and: + shutdown(4, SHUT_WR) = 0 + sendto(4, "bar", 3, MSG_NOSIGNAL, NULL, 0) = -1 EPIPE (Broken pipe) + poll([{fd=4, events=POLLIN|POLLOUT|POLLRDHUP}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}]) + + +POLLOUT is still reported after a SHUTWR: + +socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3 +setsockopt(3, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 +bind(3, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 +listen(3, 1000) = 0 +getsockname(3, {sa_family=AF_INET, sin_port=htons(34729), sin_addr=inet_addr("0.0.0.0")}, [16]) = 0 +socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 4 +connect(4, {sa_family=AF_INET, sin_port=htons(34729), sin_addr=inet_addr("0.0.0.0")}, 16) = 0 +accept(3, 0x7ffcd6a68300, [0->16]) = 5 +fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 3), ...}) = 0 +brk(NULL) = 0xc4e000 +brk(0xc6f000) = 0xc6f000 +write(1, "\n", 1 +) = 1 +shutdown(4, SHUT_WR) = 0 +poll([{fd=4, events=POLLIN|POLLOUT|POLLRDHUP}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}]) +write(1, "ret=1 ev={fd:4 ev:4}\n", 21ret=1 ev={fd:4 ev:4} +) = 21 +close(5) = 0 +close(4) = 0 +close(3) = 0 + +Performing a write() on it reports a SIGPIPE: + +shutdown(4, SHUT_WR) = 0 +sendto(4, "bar", 3, MSG_NOSIGNAL, NULL, 0) = -1 EPIPE (Broken pipe) +poll([{fd=4, events=POLLIN|POLLOUT|POLLRDHUP}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}]) + + +On SHUT_RD we see POLLIN|POLLOUT|POLLRDHUP (there's no data pending here) : +shutdown(4, SHUT_RD) = 0 +poll([{fd=4, events=POLLIN|POLLOUT|POLLRDHUP}], 1, 0) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLRDHUP}]) + + +What is observed in the end : + - POLLOUT is always reported for anything SHUT_WR even if it would cause a broken pipe, including listeners if they're also SHUT_RD + - POLLHUP is always reported for anything SHUT_WR + having a SHUT_RD pending with or without anything to read, including listeners + - POLLIN is always reported for anything to read or a pending zero + - POLLIN is NOT reported for SHUT_RD listeners, even with pending connections, only OUT+HUP are reported + - POLLIN and POLLRDHUP are always reported after a SHUTR + - POLLERR also enables IN,OUT,HUP,RHUP + + + + + + + +Currently there's a bit of an issue with connect() being too impatient to read: + +16:26:06.818521 connect(9, {sa_family=AF_INET, sin_port=htons(8000), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) +16:26:06.818558 recvfrom(9, 0x1db9400, 16320, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +16:26:06.818571 epoll_ctl(3, EPOLL_CTL_ADD, 9, {EPOLLIN|EPOLLOUT|EPOLLRDHUP, {u32=9, u64=9}}) = 0 +16:26:06.818588 epoll_wait(3, [{EPOLLOUT, {u32=9, u64=9}}], 200, 1000) = 1 +16:26:06.818603 connect(9, {sa_family=AF_INET, sin_port=htons(8000), sin_addr=inet_addr("127.0.0.1")}, 16) = 0 +16:26:06.818617 sendto(9, "GET /?s=10k HTTP/1.1\r\nhost: 127.0.0.1:4445\r\nuser-agent: curl/7.54.1\r\naccept: */*\r\n\r\n", 84, MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 84 +16:26:06.818660 epoll_ctl(3, EPOLL_CTL_MOD, 9, {EPOLLIN|EPOLLRDHUP, {u32=9, u64=9}}) = 0 +16:26:06.818696 epoll_wait(3, [{EPOLLIN, {u32=9, u64=9}}], 200, 1000) = 1 +16:26:06.818711 recvfrom(9, "HTTP/1.1 200\r\nContent-length: 10240\r\nX-req: size=84, time=0 ms\r\nX-rsp: id=dummy, code=200, cache=1, size=10240, time=0 ms (0 real)\r\n\r\n89.123456789.12345678\n.123456789.123456789.123456789.123456789.123"..., 16320, 0, NULL, NULL) = 10374 +16:26:06.818735 recvfrom(9, 0x1dd75f6, 5946, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable) +16:26:06.818790 epoll_ctl(3, EPOLL_CTL_DEL, 9, 0x7ffa818fd7d0) = 0 +16:26:06.818804 epoll_wait(3, [], 200, 0) = 0 + + + + +This one shows that the error is not definitive, it disappears once it's +been signaled, then only shut remains! Also it's a proof that an error +may well be reported after a shutw, so the r/w error may not be merged +with a shutw since it may appear after an deliberate shutw. + +$ ./contrib/debug/poll -v -c snd,shw -s pol,rcv,pol,rcv,pol,snd,lin,clo -c pol,rcv,pol,rcv,pol,rcv,pol +#### BEGIN #### +cmd #1 stp #1: do_snd(4): ret=3 +cmd #1 stp #2: do_shw(4): ret=0 +cmd #2 stp #0: do_acc(3): ret=5 +cmd #2 stp #1: do_pol(5): ret=1 ev=0x2005 (IN OUT RDHUP) +cmd #2 stp #2: do_rcv(5): ret=3 +cmd #2 stp #3: do_pol(5): ret=1 ev=0x2005 (IN OUT RDHUP) +cmd #2 stp #4: do_rcv(5): ret=0 +cmd #2 stp #5: do_pol(5): ret=1 ev=0x2005 (IN OUT RDHUP) +cmd #2 stp #6: do_snd(5): ret=3 +cmd #2 stp #7: do_lin(5): ret=0 +cmd #2 stp #8: do_clo(5): ret=0 +cmd #3 stp #1: do_pol(4): ret=1 ev=0x201d (IN OUT ERR HUP RDHUP) +cmd #3 stp #2: do_rcv(4): ret=3 +cmd #3 stp #3: do_pol(4): ret=1 ev=0x201d (IN OUT ERR HUP RDHUP) +cmd #3 stp #4: do_rcv(4): ret=-1 (Connection reset by peer) +cmd #3 stp #5: do_pol(4): ret=1 ev=0x2015 (IN OUT HUP RDHUP) +cmd #3 stp #6: do_rcv(4): ret=0 +cmd #3 stp #7: do_pol(4): ret=1 ev=0x2015 (IN OUT HUP RDHUP) +#### END #### |