Under the hood of TCP Socket Implementation On Golang
Golang is surely my first to go language to write web application, it hides many details but still gives a lot of flexibility. Recently I did strace
to an http service app, actually did it without a reason but I found something interesting.
Here’s what strace -c
gave me :
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
91.24 0.397615 336 1185 29 futex
4.13 0.018009 3 7115 clock_gettime
2.92 0.012735 19 654 epoll_wait
1.31 0.005701 6 911 write
0.20 0.000878 3 335 epoll_ctl
0.12 0.000525 1 915 457 read
0.02 0.000106 2 59 select
0.01 0.000059 0 170 close
0.01 0.000053 0 791 setsockopt
0.01 0.000035 0 158 getpeername
0.01 0.000034 0 170 socket
0.01 0.000029 0 160 getsockname
0.01 0.000026 0 159 getsockopt
0.00 0.000000 0 7 sched_yield
0.00 0.000000 0 166 166 connect
0.00 0.000000 0 3 1 accept4
------ ----------- ----------- --------- --------- ----------------
100.00 0.435805 12958 653 total
There are a lot of interesting things in that profiling result, but the highlight of this article are the error number of read and the number of futex call
At the first sight I didn’t think about futex
call, which most of them are a wake call. I thought that this app serve hundreds req per second, it should has many go routine; At the other hand it also leverage channel, it should has many under the hood blocking mechanism. So a lot of futex
call should be normal, later I found out that this number was also from other things -will back to it later-.
Why you no read
Who’s like error? Worst when it happens hundreds time in less than a minute, that’s what I thought when looking to that profiling result. What the heck with that read
call?
read(36, "GET /xxx/v3?q=xx%20ch&d"..., 4096) = 520
...
read(36, 0xc422aa4291, 1) = -1 EAGAIN (Resource temporarily unavailable)
After every read
call there is (maybe) always one read to the same file descriptor with EAGAIN
error. Hey I remember this error, it comes when the file descriptor is not ready to certain operation; in this case read
. But Why golang do this way?
I thought there was bug from the epoll_wait
which gave wrong ready event to every fd? every fd? It looks like double ready rather than wrong event, why double?
Honestly my experience with epoll is shallow, basic event loop socket handler [0] is the only one. No multi threading, no synchronization, it’s very plain. After googling I found Marek (clever guy) criticizing epoll [1], and it’s like boom!!!
Important TL;DR from that post : unnecessary wake up is ‘generally’ unavoidable when using epoll
with multi threaded worker, because weneed to notify each worker about waiting ready events.
Hey that also explain about our futex wake numbers. But lets take a look at simplified version on how to use epoll
in event loop socket implementation to further understand it :
- Bind socket listener to file descriptor, lets call it
s_fd
- Create epoll file descriptor using
epoll_create
, lets call ite_fd
- Bind
s_fd
toe_fd
usingepol_ctl
for particular events (usually bothEPOLLIN|EPOLLOUT
) - Create forever loop (event loop) which call
epoll_wait
in every iteration to get incoming ready connections fd from binded events - Handle the ready connection, in multi worker implementation means notifying each worker
Using strace
I found that golang using edge triggered epoll
epoll_ctl(4, EPOLL_CTL_ADD, 3, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=2490298448, u64=140490870550608}}) = 0
Which means this is also valid on golang socket implementation :
- Kernel: Receives a new connection.
- Kernel: Notifies two waiting threads A and B. Due to “thundering herd” behavior with level-triggered notifications kernel must wake up both.
- Thread A: Finishes
epoll_wait()
. - Thread B: Finishes
epoll_wait()
. - Thread A: Performs
accept()
, this succeeds. - Thread B: Performs
accept()
, this fails with EAGAIN.
At this point I am 80% confident this was the case, but let’s do some analysis using this simple web app [2]. Here is what it does on single request.
epoll_wait(4, [{EPOLLIN|EPOLLOUT, {u32=2186919600, u64=140542106779312}}], 128, -1) = 1
futex(0x7c1bd8, FUTEX_WAKE, 1) = 1
futex(0x7c1b10, FUTEX_WAKE, 1) = 1
read(5, "GET / HTTP/1.1\r\nHost: localhost:"..., 4096) = 348
futex(0xc420060110, FUTEX_WAKE, 1) = 1
write(5, "HTTP/1.1 200 OK\r\nDate: Sat, 03 J"..., 116) = 116
futex(0xc420060110, FUTEX_WAKE, 1) = 1
read(5, 0xc4200f6000, 4096) = -1 EAGAIN (Resource temporarily unavailable)
Look how after epoll_wait
there are two futex
wake call which I think is the worker and then there are error read.
How if I set GOMAXPROCS to 1, enforcing single worker behavior.
epoll_wait(4,[{EPOLLIN, {u32=1969377136, u64=140245536493424}}], 128, -1) = 1
futex(0x7c1bd8, FUTEX_WAKE, 1) = 1
accept4(3, {sa_family=AF_INET6, sin6_port=htons(54400), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28], SOCK_CLOEXEC|SOCK_NONBLOCK) = 6
epoll_ctl(4, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=1969376752, u64=140245536493040}}) = 0
getsockname(6, {sa_family=AF_INET6, sin6_port=htons(8080), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
setsockopt(6, SOL_TCP, TCP_NODELAY, [1], 4) = 0
setsockopt(6, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
setsockopt(6, SOL_TCP, TCP_KEEPINTVL, [180], 4) = 0
setsockopt(6, SOL_TCP, TCP_KEEPIDLE, [180], 4) = 0
accept4(3, 0xc42004db78, 0xc42004db6c, SOCK_CLOEXEC|SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable)
read(6, "GET /test?kjhkjhkjh HTTP/1.1\r\nHo"..., 4096) = 92
write(6, "HTTP/1.1 200 OK\r\nDate: Sat, 03 J"..., 139) = 139
read(6, "", 4096) = 0
When using 1 worker, there is only once futex
wake call after epoll_wait
and no read error. However I found this behavior is not consistent, in some trial I still got read error and 2 futex
wake call.
And then what to do?
In the same post [1] Marek talk about EPOLLEXCLUSIVE
which available starting from linux version 4.5. I’m using version 4.8 why it’s still happening on my maching? Turns out that golang is not using that flag yet, I hope at the next next version it will support that flag when available.
I learned a lot from this journey, hope you too.
[0] https://banu.com/blog/2/how-to-use-epoll-a-complete-example-in-c/ [1] https://idea.popcount.org/2017-02-20-epoll-is-fundamentally-broken-12/
[2] https://gist.github.com/wejick/2cef1f8799361318a62a59f6801eade8