Hello, Thanks for your answer Willy !
On Mon, Jan 22, 2018 at 05:47:55PM +0100, Willy Tarreau wrote: > Hi Marc, > > On Mon, Jan 22, 2018 at 03:18:20PM +0100, Marc Fournier wrote: > > Cyril Bonté <cyril.bo...@free.fr> writes: > > > > Hello, > > > > > Im' not sure you saw Samuel Reed's mail. > > > He reported a similar issue some hours ago (High load average under > > > 1.8 with multiple draining processes). It would be interesting to find > > > a common configuration to reproduce the issue, so I add him to the thread. > > > > I've been observing the same error messages Emmanuel reports, using > > 1.8.3 and nbthread. I tried to simplify & anonymize my configuration so > > I could share a version which reproduces the problem, but didn't > > succeed: the problem disappears at some point in the process, and I'm > > unable figure out exactly which change makes the difference :-( > > We've done some work over the week-end to address an issue related to > FDs and threads : in short, it's impossible to let a thread sleep when > there's some activity on another one because they share the same epoll_fd. > > We've sent Samuel a copy of patches to test (I'm attaching them here in > case you're interested to try as well, to add on top of latest 1.8, though > 1.8.3 will be OK). Since you seem to be able to reproduce the bug on a > full config, you may be tempted to try htem. Ok, thanks ! I built 1.8.3 with only this patchset added to it, but the issue still occurred. strace shows similar sequence of actions, slightly differently. Example: 6629 12:34:38.312873 set_robust_list(0x7f4a21c449e0, 24 <unfinished ...> 6434 12:34:38.312900 munmap(0x7f4a22446000, 8003584 <unfinished ...> 6629 12:34:38.312920 <... set_robust_list resumed> ) = 0 6629 12:34:38.312941 gettimeofday( <unfinished ...> 6630 12:34:38.312965 <... epoll_create resumed> ) = 19 6434 12:34:38.312999 <... munmap resumed> ) = 0 6629 12:34:38.313020 <... gettimeofday resumed> {1516707278, 313013}, NULL) = 0 6629 12:34:38.313055 mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0 <unfinished ...> 6630 12:34:38.313095 close(16 <unfinished ...> 6629 12:34:38.313118 <... mmap resumed> ) = 0x7f4a1385e000 6630 12:34:38.313172 <... close resumed> ) = 0 6434 12:34:38.313196 munmap(0x7f4a22be8000, 32006144 <unfinished ...> 6629 12:34:38.313220 munmap(0x7f4a1385e000, 8003584) = 0 6434 12:34:38.313265 <... munmap resumed> ) = 0 6629 12:34:38.313287 munmap(0x7f4a18000000, 59105280 <unfinished ...> 6434 12:34:38.313308 munmap(0x7f4a24a6e000, 112009216 <unfinished ...> 6629 12:34:38.313330 <... munmap resumed> ) = 0 6434 12:34:38.313839 <... munmap resumed> ) = 0 6629 12:34:38.313870 mprotect(0x7f4a14000000, 135168, PROT_READ|PROT_WRITE) = 0 6630 12:34:38.313911 fcntl(15, F_SETFL, O_RDONLY|O_NONBLOCK <unfinished ...> 6629 12:34:38.313959 mmap(NULL, 8003584, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...> 6630 12:34:38.313985 <... fcntl resumed> ) = 0 6630 12:34:38.314010 gettimeofday({1516707278, 314022}, NULL) = 0 6630 12:34:38.314070 socket(PF_INET, SOCK_STREAM, IPPROTO_TCP <unfinished ...> 6629 12:34:38.314096 <... mmap resumed> ) = 0x7f4a1b0bc000 6629 12:34:38.314126 epoll_create(2000128 <unfinished ...> 6630 12:34:38.314158 <... socket resumed> ) = 16 6629 12:34:38.314182 <... epoll_create resumed> ) = 20 6629 12:34:38.314203 close(16 <unfinished ...> 6630 12:34:38.314226 fcntl(16, F_SETFL, O_RDONLY|O_NONBLOCK <unfinished ...> 6629 12:34:38.314256 <... close resumed> ) = 0 6630 12:34:38.314278 <... fcntl resumed> ) = -1 EBADF (Bad file descriptor) 6630 12:34:38.314303 close(16 <unfinished ...> 6629 12:34:38.314324 fcntl(15, F_SETFL, O_RDONLY|O_NONBLOCK <unfinished ...> 6630 12:34:38.314344 <... close resumed> ) = -1 EBADF (Bad file descriptor) 6629 12:34:38.314365 <... fcntl resumed> ) = 0 But HAProxy still isn't able to recover from the mayhem it created, in this case. > > - when exposed to client requests, I only observed high CPU load on one > > instance out of the three I have, which receeded after a restart of > > haproxy. When working in isolation (no client requests), I never > > noticed high CPU load. > > So this could indicate an uncaught error on a specific fd. A "show fd" > on the CLI may give some useful information about this. And the patches > above also add "show activity", to run twice one second apart, and which > will indicate the various causes of wakeups. Attached to this email, you have the output of five sequential "show fd;show activity" with a one second sleep between each. The first one was taken just before sending SIGUSR2 to HAProxy. > > # thread 12166 gets created, and closes an fd it didn't create, which > > # happens to be the socket opened to the DNS server: > > > > strace: Process 12166 attached > > [pid 12167] sendto(16, > > "\316\352\1\0\0\1\0\0\0\0\0\1\nprivate-25\10backends"..., 79, 0, NULL, 0 > > <unfinished ...> > > [pid 12166] set_robust_list(0x7ff9bc9aa9e0, 24 <unfinished ...> > > [pid 12167] <... sendto resumed> ) = 79 > > [pid 12166] <... set_robust_list resumed> ) = 0 > > [pid 12166] gettimeofday({1516289044, 684014}, NULL) = 0 > > [pid 12167] sendto(16, > > "\37\367\1\0\0\1\0\0\0\0\0\1\nprivate-26\10backends"..., 79, 0, NULL, 0 > > <unfinished ...> > > [pid 12166] mmap(NULL, 134217728, PROT_NONE, > > MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0 <unfinished ...> > > [pid 12167] <... sendto resumed> ) = 79 > > [pid 12167] sendto(16, > > "\224\10\1\0\0\1\0\0\0\0\0\1\nprivate-27\10backends"..., 79, 0, NULL, 0) = > > 79 > > [pid 12166] <... mmap resumed> ) = 0x7ff9ac000000 > > [pid 12167] sendto(16, "\25 > > \1\0\0\1\0\0\0\0\0\1\nprivate-28\10backends"..., 79, 0, NULL, 0) = 79 > > [pid 12166] munmap(0x7ff9b0000000, 67108864) = 0 > > [pid 12167] sendto(16, > > "\275\n\1\0\0\1\0\0\0\0\0\1\nprivate-29\10backends"..., 79, 0, NULL, 0 > > <unfinished ...> > > [pid 12166] mprotect(0x7ff9ac000000, 135168, PROT_READ|PROT_WRITE > > <unfinished ...> > > [pid 12167] <... sendto resumed> ) = 79 > > [pid 12166] <... mprotect resumed> ) = 0 > > [pid 12167] sendto(16, > > "\312\360\1\0\0\1\0\0\0\0\0\1\nprivate-30\10backends"..., 79, 0, NULL, 0 > > <unfinished ...> > > [pid 12166] mmap(NULL, 8003584, PROT_READ|PROT_WRITE, > > MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...> > > [pid 12167] <... sendto resumed> ) = 79 > > [pid 12167] sendto(16, > > "\247e\1\0\0\1\0\0\0\0\0\1\nprivate-31\10backends"..., 79, 0, NULL, 0) = 79 > > [pid 12166] <... mmap resumed> ) = 0x7ff9baa65000 > > [pid 12167] sendto(16, "_k\1\0\0\1\0\0\0\0\0\1\tprivate-0\nbackoffic"..., > > 80, 0, NULL, 0 <unfinished ...> > > [pid 12166] close(16 <unfinished ...> > > Wow, that's scary! Are you certain it's not the parent process and that > it's really a thread ? you may see a clone() syscall in 12166 giving birth > to 12167. If they are different processes, that can be fine, but ... Yes, the options to strace I used there doesn't print out the pid of the master process, only those of sub-processes (and threads). This is how things look like when reload occurs after receiving SIGUSR2: kill(48, SIGUSR1) = 0 getrlimit(RLIMIT_NOFILE, {rlim_cur=1024*1024, rlim_max=1024*1024}) = 0 getpid() = 1 write(2, "[WARNING] 017/152404 (1) : [hapr"..., 172) = 172 getpid() = 1 write(-1, "1\n", 2) = -1 EBADF (Bad file descriptor) clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7ff9ca196c50) = 57 strace: Process 12164 attached [pid 12164] set_robust_list(0x7ff9ca196c60, 24 <unfinished ...> [pid 11084] close(4) = 0 [pid 12164] <... set_robust_list resumed> ) = 0 [pid 11084] close(5) = 0 [pid 11084] close(7) = 0 [pid 12164] open("/dev/null", O_RDWR <unfinished ...> [pid 11084] close(8) = 0 [pid 12164] <... open resumed> ) = 17 [pid 11084] close(9) = 0 [pid 12164] getgroups(0, <unfinished ...> > > [pid 12164] getpid() = 57 > > [pid 12164] getpid() = 57 > > Pids are collected for logging. Strange that the libc didn't cache > the getpid()'s result by the way, usually it does. Thinking about it, > getpid()==57 is a bit surprising, maybe it's not really a getpid in > fact. Sorry I didn't mention this in my last email: HAProxy is running in a docker container, but I'm running strace from the host. The pid namespace isolation would be causing this pid number mismatch. I don't have any explanation for the repeated calls to getpid() though. I'll reply to your other email in a moment. Thanks ! Marc
4 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x55e0a118fa80 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=GLOBAL 5 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x55e0a1192780 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=https_redirection 7 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x55e0a1194840 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=entrypoint 8 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x55e0a1198d80 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=app_internal 9 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x55e0a119bb50 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=sorry_internal 10 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x55e0a119c340 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_bypass_varnish 11 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x55e0a11f1db0 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_blue 12 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x55e0a121ab50 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_green 13 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x55e0a1565e80 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=stats 14 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x55e0a1567f50 iocb=0x55e0a0910890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=healthcheck 15 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlc] cache=0 owner=0x55e0a0baca38 iocb=0x55e0a08dfed0(unknown) tmask=0xffffffffffffffff umask=0x0 16 : st=0x22(R:pRa W:pRa) ev=0x00(heopi) [Nlc] cache=0 owner=0x7f0310013130 iocb=0x55e0a0923d40(conn_fd_handler) tmask=0x4 umask=0x8 cflg=0x00241300 fe=GLOBAL 21 : st=0x25(R:PrA W:pRa) ev=0x00(heopi) [nlc] cache=0 owner=0x7f03180124c0 iocb=0x55e0a0923d40(conn_fd_handler) tmask=0x8 umask=0x0 cflg=0x80201306 fe=healthcheck thread_id: 2 date_now: 1516707278.042397 loops: 1879 39538 40174 24107064 wake_cache: 84 164 203 996 wake_tasks: 9 9 10 1767 wake_applets: 2 37569 38160 6 wake_signal: 0 0 0 0 poll_exp: 95 37742 38373 2769 poll_drop: 7 8 8 20 poll_dead: 0 0 0 0 poll_skip: 0 0 0 0 fd_skip: 28 59 85 1705 fd_lock: 0 2 2 13 fd_del: 14 24 23 11 conn_dead: 0 0 0 0 stream: 35 37654 38244 24 empty_rq: 80 130 177 24105239 long_rq: 0 0 0 0 4 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x5587cd0a7ad0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=GLOBAL 5 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0aa7d0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=https_redirection 7 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0ac890 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=entrypoint 8 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b0dd0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=app_internal 9 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b3ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=sorry_internal 10 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b4390 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_bypass_varnish 11 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd109e30 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_blue 12 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd132ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_green 13 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd47ded0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=stats 14 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd47ffa0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=healthcheck 15 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlc] cache=0 owner=0x5587cb83aa38 iocb=0x5587cb56ded0(unknown) tmask=0xffffffffffffffff umask=0x0 16 : st=0x25(R:PrA W:pRa) ev=0x04(heOpi) [nlc] cache=0 owner=0x5587cd4977d0 iocb=0x5587cb5ce2b0(dgram_fd_handler) tmask=0xffffffffffffffff umask=0x0 21 : st=0x22(R:pRa W:pRa) ev=0x00(heopi) [Nlc] cache=0 owner=0x7f4a1c0122f0 iocb=0x5587cb5b1d40(conn_fd_handler) tmask=0x4 umask=0x0 cflg=0x00241300 fe=GLOBAL thread_id: 2 date_now: 1516707279.023984 loops: 33 5526 28 29 wake_cache: 2 1 2 2 wake_tasks: 2 28 0 0 wake_applets: 0 0 0 0 wake_signal: 0 0 0 0 poll_exp: 4 29 2 2 poll_drop: 6 6 6 6 poll_dead: 0 0 0 0 poll_skip: 0 0 0 0 fd_skip: 1 1 0 1 fd_lock: 0 0 0 0 fd_del: 0 0 1 0 conn_dead: 0 0 0 0 stream: 0 0 1 0 empty_rq: 3 5497 0 2 long_rq: 0 0 0 0 4 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x5587cd0a7ad0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=GLOBAL 5 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0aa7d0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=https_redirection 7 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0ac890 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=entrypoint 8 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b0dd0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=app_internal 9 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b3ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=sorry_internal 10 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b4390 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_bypass_varnish 11 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd109e30 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_blue 12 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd132ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_green 13 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd47ded0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=stats 14 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x5587cd47ffa0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=healthcheck 15 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlc] cache=0 owner=0x5587cb83aa38 iocb=0x5587cb56ded0(unknown) tmask=0xffffffffffffffff umask=0x0 16 : st=0x25(R:PrA W:pRa) ev=0x04(heOpi) [nlc] cache=0 owner=0x5587cd4977d0 iocb=0x5587cb5ce2b0(dgram_fd_handler) tmask=0xffffffffffffffff umask=0x0 21 : st=0x25(R:PrA W:pRa) ev=0x00(heopi) [nlc] cache=0 owner=0x7f4a1c0122f0 iocb=0x5587cb5b1d40(conn_fd_handler) tmask=0x8 umask=0x0 cflg=0x00201306 fe=GLOBAL thread_id: 3 date_now: 1516707280.047117 loops: 83 13949 83 83 wake_cache: 7 4 10 9 wake_tasks: 2 69 0 1 wake_applets: 0 0 1 1 wake_signal: 0 0 0 0 poll_exp: 9 73 11 11 poll_drop: 6 6 6 6 poll_dead: 0 0 0 0 poll_skip: 0 0 0 0 fd_skip: 1 3 6 7 fd_lock: 0 0 0 0 fd_del: 2 0 1 1 conn_dead: 0 0 0 0 stream: 4 0 2 1 empty_rq: 7 13878 12 13 long_rq: 0 0 0 0 4 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x5587cd0a7ad0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=GLOBAL 5 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0aa7d0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=https_redirection 7 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0ac890 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=entrypoint 8 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b0dd0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=app_internal 9 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b3ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=sorry_internal 10 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b4390 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_bypass_varnish 11 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd109e30 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_blue 12 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd132ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_green 13 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd47ded0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=stats 14 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x5587cd47ffa0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=healthcheck 15 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlc] cache=0 owner=0x5587cb83aa38 iocb=0x5587cb56ded0(unknown) tmask=0xffffffffffffffff umask=0x0 16 : st=0x25(R:PrA W:pRa) ev=0x04(heOpi) [nlc] cache=0 owner=0x5587cd4977d0 iocb=0x5587cb5ce2b0(dgram_fd_handler) tmask=0xffffffffffffffff umask=0x0 21 : st=0x26(R:PRa W:pRa) ev=0x10(Heopi) [nlc] cache=0 owner=0x7f4a1c0122f0 iocb=0x5587cb5b1d40(conn_fd_handler) tmask=0x8 umask=0x8 cflg=0x00241300 fe=GLOBAL thread_id: 3 date_now: 1516707281.058964 loops: 103 24168 133 137 wake_cache: 11 7 13 14 wake_tasks: 3 113 0 1 wake_applets: 0 0 1 2 wake_signal: 0 0 0 0 poll_exp: 14 120 14 17 poll_drop: 6 6 6 7 poll_dead: 0 0 0 0 poll_skip: 0 0 0 0 fd_skip: 4 3 6 10 fd_lock: 0 0 0 0 fd_del: 2 0 2 2 conn_dead: 0 0 0 0 stream: 4 0 4 3 empty_rq: 12 24051 15 20 long_rq: 0 0 0 0 4 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x5587cd0a7ad0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=GLOBAL 5 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0aa7d0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=https_redirection 7 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0ac890 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=entrypoint 8 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b0dd0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=app_internal 9 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b3ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=sorry_internal 10 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd0b4390 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_bypass_varnish 11 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd109e30 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_blue 12 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd132ba0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=backdoor_green 13 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlC] cache=0 owner=0x5587cd47ded0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=stats 14 : st=0x05(R:PrA W:pra) ev=0x01(heopI) [nlC] cache=0 owner=0x5587cd47ffa0 iocb=0x5587cb59e890(listener_accept) tmask=0xffffffffffffffff umask=0x0 l.st=RDY fe=healthcheck 15 : st=0x05(R:PrA W:pra) ev=0x00(heopi) [nlc] cache=0 owner=0x5587cb83aa38 iocb=0x5587cb56ded0(unknown) tmask=0xffffffffffffffff umask=0x0 16 : st=0x25(R:PrA W:pRa) ev=0x04(heOpi) [nlc] cache=0 owner=0x5587cd4977d0 iocb=0x5587cb5ce2b0(dgram_fd_handler) tmask=0xffffffffffffffff umask=0x0 21 : st=0x26(R:PRa W:pRa) ev=0x10(Heopi) [nlc] cache=0 owner=0x7f4a1c0122f0 iocb=0x5587cb5b1d40(conn_fd_handler) tmask=0x8 umask=0x8 cflg=0x00241300 fe=GLOBAL thread_id: 3 date_now: 1516707282.078082 loops: 117 34766 177 186 wake_cache: 12 7 16 20 wake_tasks: 3 153 0 1 wake_applets: 0 0 1 3 wake_signal: 0 0 0 0 poll_exp: 15 160 17 24 poll_drop: 6 6 6 8 poll_dead: 0 0 0 0 poll_skip: 0 0 0 0 fd_skip: 5 6 8 10 fd_lock: 0 0 0 0 fd_del: 2 0 2 5 conn_dead: 0 0 0 0 stream: 4 0 4 9 empty_rq: 14 34609 20 25 long_rq: 0 0 0 0