Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

runc init blocked opening exec.fifo #2828

Closed
cpuguy83 opened this issue Feb 27, 2021 · 20 comments
Closed

runc init blocked opening exec.fifo #2828

cpuguy83 opened this issue Feb 27, 2021 · 20 comments

Comments

@cpuguy83
Copy link
Contributor

We have a case where runc init is blocked trying to open exec.fifo (specifically /proc/self/fd/5 which points to exec.fifo in the state dir.
This happened on a machine with memory pressure and runc exiting with SIGSEGV.

I'm assuming this is happening here, but all I have to debug this is strace:

fd, err := unix.Open("/proc/self/fd/"+strconv.Itoa(l.fifoFd), unix.O_WRONLY|unix.O_CLOEXEC, 0)
if err != nil {
return newSystemErrorWithCause(err, "open exec fifo")
}

@cpuguy83
Copy link
Contributor Author

/cc @kk-src

@cyphar
Copy link
Member

cyphar commented Feb 28, 2021

I think there was a report of a similar issue some time ago -- the main issue is that we can't add a timeout because it's reasonable for there to be an arbitrarily long split between runc create and runc start (not to mention that there were some crazy use-cases where people only use runc create and runc exec).

@cpuguy83
Copy link
Contributor Author

cpuguy83 commented Mar 1, 2021

Hmm, yes indeed.

I wonder if we can open a pipe to wait for an exit signal, and part of cleaning up runc would be to ensure 0 or something is written on that pipe to force it to exit?
Maybe that's overly paranoid and we can just use pids? Or something else entirely.

@kolyshkin
Copy link
Contributor

@cpuguy83 I am not sure what are you proposing.

We have runc create which leaves this runc init the way you saw it, and we have runc delete which cleans things up.

[kir@kir-rhat runc-tst]$ sudo ../runc/runc.my create xx345
[kir@kir-rhat runc-tst]$ sudo ../runc/runc.my list
ID          PID         STATUS      BUNDLE                                                CREATED                          OWNER
xx345       157215      created     /home/kir/go/src/github.com/opencontainers/runc-tst   2021-03-04T00:39:41.707090433Z   root
[kir@kir-rhat runc-tst]$ sudo strace -p 157215
strace: Process 157215 attached
openat(AT_FDCWD, "/proc/self/fd/5", O_WRONLY|O_CLOEXEC^Cstrace: Process 157732 detached
 <detached ...>

[kir@kir-rhat runc-tst]$ sudo ../runc/runc.my delete xx345
[sudo] password for kir: 
[kir@kir-rhat runc-tst]$ sudo strace -p 157215
strace: attach: ptrace(PTRACE_SEIZE, 157732): No such process

Or do you mean that this runc init is a leftover from a runc run which segfaulted, and it needs to be cleaned somehow? If yes, I see two ways to do it:

  • wrap runc into another binary (or a shell script) which cleans things up if needed;
  • have something like a cron job which garbage collects old/stale runc init processes;

Frankly I do not like either way.

A wrapper is an unnecessary complication for a very rare case.

A cron script needs a definition of "stale"; let's say we define it as "started more than 1 hour ago and still there". In this case the init will still be there for at least an hour, and it still may break some workloads.

Overall it looks like the problem needs to be solved at the upper level -- i.e. whoever calls runc run should call runc delete in case runc run fails.

@cpuguy83
Copy link
Contributor Author

cpuguy83 commented Mar 4, 2021

If this is a problem of "runc delete" not being called indeed that is a simple fix.
I'll check through the containerd runc shim to see if this is happening.

@kolyshkin
Copy link
Contributor

@cpuguy83 can we close it, or do you still see the bug?

@wu0407
Copy link

wu0407 commented Mar 27, 2021

use docker 19.03.15 with containerd 1.4.4-3, runc init stuck. It happen on run 200+ containers and no memory press.

docker version
Client: Docker Engine - Community
 Version:           20.10.5
 API version:       1.40
 Go version:        go1.13.15
 Git commit:        55c4c88
 Built:             Tue Mar  2 20:33:55 2021
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          19.03.15
  API version:      1.40 (minimum version 1.12)
  Go version:       go1.13.15
  Git commit:       99e3ed8919
  Built:            Sat Jan 30 03:16:33 2021
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.4.4
  GitCommit:        05f951a3781f4f2c1911b05e61c160e9c30eaa8e
 runc:
  Version:          1.0.0-rc93
  GitCommit:        12644e614e25b05da6fd08a38ffa0cfe1903fdec
 docker-init:
  Version:          0.18.0
  GitCommit:        fec3683
systemctl status
           │ │ └─555906 runc init
           │ ├─docker-8f98bb94a6345097f91845e90e15827d8656753e1282ad1cd66ebc4b9a3f5009.scope
           │ │ └─345003 runc init
           │ ├─docker-42b905837f766877e6c0df0f72f46c622600e369806a66868a7bd390fd01c517.scope
           │ │ └─49695 runc init
           │ ├─docker-4f87550b15443da4ea91f94c04ffa1985dcd0c936424a61c82c4856a5502f59b.scope
           │ │ └─602496 runc init
           │ ├─docker-8aa0663303af8931992a08074fb5262255af8aee7cdba86ced1aa19de834fb7f.scope
           │ │ └─331297 runc init
           │ ├─docker-4ab3b3da91030f53001d001ce71c562b5882cd11bc395f9b9a3e492cd5cc3bb4.scope
           │ │ └─117462 runc init
           │ ├─docker-a241be44b776fa6d578a205519bfd1d278df95103bfd336788f2e8c2f37fc45a.scope
           │ │ └─352865 runc init
           │ ├─docker-c7b11b4e2f31dac4ced6df323844eb2170e7ee99e979e787495b5dd607c6ae7a.scope
           │ │ └─141761 runc init
           │ ├─docker-6a3ec51bc21ad80c65e83d4a1bb1ddea09ecf359aad6d2f591ce253b8a68042f.scope
           │ │ └─509115 runc init
           │ ├─docker-8851feb8532849f3b9b0316151e9ad751928a5a097df611f7fc657b7a05ebf57.scope
           │ │ └─347996 runc init
           │ ├─docker-9205b1e27dfe328ef8bbdf148d763ea5ae6052eb5e1bc98f0b1724614deb2422.scope
           │ │ └─623971 runc init
           │ ├─docker-976ab517c171c0bec41e0ea3d54960ea8902538247e48a20242039e0d8fd19e1.scope
           │ │ └─187707 runc init
           │ ├─docker-ff828ad0b47098da7f9e3caf6116453bb5d3405bc3d743622b08dd8f512452f0.scope
           │ │ └─301184 runc init
           │ ├─docker-175e79d6964aa2777bec47e0f93eceb3349660dd112795575b892ac60d414699.scope
           │ │ └─494329 runc init
           │ ├─docker-34033d42472f28417c989d8cf405aa4935f9621849e166b743e76ef3a676f0c5.scope
           │ │ └─614849 runc init
[root@sh-saas-k8s1-node-dev-14 ~]# ps aux |grep "runc init" |head
root         985  0.0  0.0 158716 23116 ?        Ssl  Mar26   0:00 runc init
root        1829  0.0  0.0 168320 16708 ?        Ssl  02:37   0:00 runc init
root        2795  0.0  0.0 168320 19084 ?        Ssl  Mar26   0:00 runc init
root        3521  0.0  0.0 232448 16240 ?        Ssl  02:37   0:00 runc init
root        5115  0.0  0.0 168320 18208 ?        Ssl  02:37   0:00 runc init
root        5254  0.0  0.0 158716 19120 ?        Ssl  Mar26   0:00 runc init
root        6823  0.0  0.0 160124 18896 ?        Ssl  Mar26   0:00 runc init
root        7184  0.0  0.0 158716 16400 ?        Ssl  02:38   0:00 runc init
root        8608  0.0  0.0 158716 19016 ?        Ssl  Mar26   0:00 runc init
root        9352  0.0  0.0 160124 21072 ?        Ssl  02:38   0:00 runc init
# cat /proc/6823/stat
6823 (runc:[2:INIT]) S 6806 6823 6823 0 -1 4194624 424 0 0 0 2 4 0 0 20 0 5 0 678265920 163966976 4724 18446744073709551615 93973857521664 93973866689428 140731346266928 0 0 0 0 0 2143420159 0 0 0 17 2 0 0 0 0 0 93973868788800 93973874988408 93973895401472 140731346267829 140731346267839 140731346267839 140731346268136 0
# cat /proc/6823/status 
Name:   runc:[2:INIT]
State:  S (sleeping)
Tgid:   6823
Ngid:   0
Pid:    6823
PPid:   6806
TracerPid:      0
Uid:    0       0       0       0
Gid:    0       0       0       0
FDSize: 64
Groups:
NStgid: 6823    1
NSpid:  6823    1
NSpgid: 6823    1
NSsid:  6823    1
VmPeak:   160124 kB
VmSize:   160124 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:     18960 kB
VmRSS:     18896 kB
VmData:   136504 kB
VmStk:       132 kB
VmExe:      8956 kB
VmLib:      2208 kB
VmPTE:       108 kB
VmPMD:        20 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
Threads:        5
SigQ:   1/515167
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000000000000
SigCgt: ffffffffffc1feff
  pInh: 0000000000000000
CapPrm: 0000003fffffffff
CapEff: 0000003fffffffff
CapBnd: 0000003fffffffff
CapAmb: 0000000000000000
Seccomp:        0
Speculation_Store_Bypass:       vulnerable
Cpus_allowed:   ffffffff
Cpus_allowed_list:      0-31
Mems_allowed:   00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000001
Mems_allowed_list:      0
voluntary_ctxt_switches:        45
nonvoluntary_ctxt_switches:     20
[root@sh-saas-k8s1-node-dev-14 ~]# lsof -p 6823
COMMAND    PID USER   FD      TYPE             DEVICE SIZE/OFF       NODE NAME
runc:[2:I 6823 root  cwd       DIR             0,4741     4096 2378446586 /
runc:[2:I 6823 root  rtd       DIR             0,4741     4096 2378446586 /
runc:[2:I 6823 root  txt       REG              253,1 19719152     278544 /
runc:[2:I 6823 root  mem       REG              253,1  2156160     265623 /usr/lib64/libc-2.17.so
runc:[2:I 6823 root  mem       REG              253,1   266680     273930 /usr/lib64/libseccomp.so.2.3.1
runc:[2:I 6823 root  mem       REG              253,1   142232     265649 /usr/lib64/libpthread-2.17.so
runc:[2:I 6823 root  mem       REG              253,1   163400     265614 /usr/lib64/ld-2.17.so
runc:[2:I 6823 root    0u      CHR                1,3      0t0 2378445574 /dev/null
runc:[2:I 6823 root    1w     FIFO               0,10      0t0 2378435473 pipe
runc:[2:I 6823 root    2w     FIFO               0,10      0t0 2378435474 pipe
runc:[2:I 6823 root    3u     unix 0xffff8810c5ff0c00      0t0 2378426053 socket
runc:[2:I 6823 root    4w     FIFO               0,10      0t0 2378426055 pipe
runc:[2:I 6823 root    5u     FIFO               0,20      0t0 2378426052 /run/docker/runtime-runc/moby/2c3ca7e8e1848756da0d2e6d6721146e6a09b5a86e31b45a047cf63cab1c186b/exec.fifo
runc:[2:I 6823 root    6r     FIFO               0,10      0t0 2378442670 pipe
runc:[2:I 6823 root    7u  a_inode               0,11        0       7487 [eventpoll]
runc:[2:I 6823 root    8w     FIFO               0,10      0t0 2378442670 pipe

@wu0407
Copy link

wu0407 commented Mar 27, 2021

if strace into runc init that process exit

runc init strace
789395 17:26:40 futex(0x557a3edb88f8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789394 17:26:40 futex(0xc000040bc8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789393 17:26:40 futex(0x557a3edb89e0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789392 17:26:40 restart_syscall(<... resuming interrupted futex ...> <unfinished ...>
789391 17:26:40 brk(NULL)               = 0x557a3fc11000 <0.000051>
789391 17:26:40 brk(NULL)               = 0x557a3fc11000 <0.000021>
789391 17:26:40 brk(0x557a3fbea000)     = 0x557a3fbea000 <0.000054>
789391 17:26:40 brk(NULL)               = 0x557a3fbea000 <0.000025>
789391 17:26:40 futex(0x557a3ed9bf50, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
789392 17:26:40 <... restart_syscall resumed> ) = 0 <0.000342>
789391 17:26:40 <... futex resumed> )   = 1 <0.000061>
789392 17:26:40 sched_yield( <unfinished ...>
789391 17:26:40 epoll_ctl(8, EPOLL_CTL_DEL, 7, 0xc0001ecca4 <unfinished ...>
789392 17:26:40 <... sched_yield resumed> ) = 0 <0.000081>
789391 17:26:40 <... epoll_ctl resumed> ) = 0 <0.000030>
789392 17:26:40 futex(0x557a3ed9be50, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
789391 17:26:40 close(7 <unfinished ...>
789392 17:26:40 <... futex resumed> )   = 0 <0.000026>
789391 17:26:40 <... close resumed> )   = 0 <0.000026>
789392 17:26:40 epoll_pwait(8, [{EPOLLIN|EPOLLHUP, {u32=1165180680, u64=140575444778760}}], 128, 0, NULL, 24381963946782) = 1 <0.000032>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 futex(0xc000040bc8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
789391 17:26:40 <... read resumed> " \0\0\0\4\0\0\0", 8) = 8 <0.000023>
789394 17:26:40 <... futex resumed> )   = 0 <0.000703>
789392 17:26:40 <... futex resumed> )   = 1 <0.000050>
789394 17:26:40 futex(0x557a3ed9c888, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
789391 17:26:40 futex(0x557a3ed9c888, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789394 17:26:40 <... futex resumed> )   = 0 <0.000019>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789394 17:26:40 futex(0xc000040bc8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789391 17:26:40 <... futex resumed> )   = -1 EAGAIN (Resource temporarily unavailable) <0.000046>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000076>
789391 17:26:40 <... read resumed> "\25\0\1\0>\0\0\300", 8) = 8 <0.000024>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\5\0\0\0w\2\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 <... read resumed> " \0\0\0\0\0\0\0", 8) = 8 <0.000035>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\243\0\0\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0\242\0\1\0\0\0", 8) = 8 <0.000030>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\241\0\2\0\0\0", 8) = 8 <0.000027>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0\240\0\3\0\0\0", 8) = 8 <0.000036>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\237\0\4\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000050>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\236\0\5\0\0\0", 8) = 8 <0.000027>
789391 17:26:40 read(3, "\25\0\235\0\6\0\0\0", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000112>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\234\0\7\0\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\233\0\10\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000098>
789391 17:26:40 <... read resumed> "\25\0\232\0\t\0\0\0", 8) = 8 <0.000019>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\231\0\n\0\0\0", 8) = 8 <0.000015>
789391 17:26:40 read(3, "\25\0\230\0\v\0\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000110>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\227\0\f\0\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\226\0\r\0\0\0", 8) = 8 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 <... read resumed> "\25\0\225\0\16\0\0\0", 8) = 8 <0.000018>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\224\0\17\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\223\0\20\0\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000098>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\222\0\21\0\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\221\0\22\0\0\0", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000102>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\220\0\23\0\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0\217\0\24\0\0\0", 8) = 8 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000098>
789391 17:26:40 <... read resumed> "\25\0\216\0\25\0\0\0", 8) = 8 <0.000019>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\215\0\26\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000095>
789391 17:26:40 <... read resumed> "\25\0\214\0\27\0\0\0", 8) = 8 <0.000039>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\213\0\30\0\0\0", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0\212\0\31\0\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000096>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\211\0\32\0\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\210\0\33\0\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000064>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\207\0\34\0\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\206\0\35\0\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000119>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\205\0\36\0\0\0", 8) = 8 <0.000060>
789391 17:26:40 read(3, "\25\0\204\0\37\0\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000161>
789391 17:26:40 <... read resumed> "\25\0\203\0 \0\0\0", 8) = 8 <0.000084>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\202\0!\0\0\0", 8) = 8 <0.000033>
789391 17:26:40 read(3, "\25\0\201\0\"\0\0\0", 8) = 8 <0.000015>
789391 17:26:40 read(3, "\25\0\200\0#\0\0\0", 8) = 8 <0.000019>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000154>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\177\0$\0\0\0", 8) = 8 <0.000045>
789391 17:26:40 read(3, "\25\0~\0%\0\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000114>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0}\0&\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0|\0'\0\0\0", 8) = 8 <0.000062>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000118>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0{\0(\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0z\0)\0\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000106>
789391 17:26:40 <... read resumed> "\25\0y\0*\0\0\0", 8) = 8 <0.000026>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0x\0+\0\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0w\0,\0\0\0", 8) = 8 <0.000034>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000111>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0v\0-\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0u\0.\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000111>
789391 17:26:40 <... read resumed> "\25\0t\0/\0\0\0", 8) = 8 <0.000022>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0s\0000\0\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0r\0001\0\0\0", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000128>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0q\0002\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0p\0003\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0o\0004\0\0\0", 8) = 8 <0.000026>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000154>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0n\0005\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0m\0006\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000125>
789391 17:26:40 <... read resumed> "\25\0l\0007\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0k\0009\0\0\0", 8) = 8 <0.000039>
789391 17:26:40 read(3, "\25\0j\0:\0\0\0", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000113>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0i\0;\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0h\0<\0\0\0", 8) = 8 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000107>
789391 17:26:40 <... read resumed> "\25\0g\0=\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0f\0>\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0e\0?\0\0\0", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000105>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0d\0@\0\0\0", 8) = 8 <0.000027>
789391 17:26:40 read(3, "\25\0c\0A\0\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000146>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0b\0B\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0a\0C\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000111>
789391 17:26:40 <... read resumed> "\25\0`\0D\0\0\0", 8) = 8 <0.000022>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0_\0E\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0^\0F\0\0\0", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0]\0G\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\\\0H\0\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000107>
789391 17:26:40 <... read resumed> "\25\0[\0I\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0Z\0J\0\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0Y\0K\0\0\0", 8) = 8 <0.000030>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000117>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0X\0L\0\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0W\0M\0\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000101>
789391 17:26:40 <... read resumed> "\25\0V\0N\0\0\0", 8) = 8 <0.000026>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0U\0O\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0T\0P\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000108>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0S\0Q\0\0\0", 8) = 8 <0.000062>
789391 17:26:40 read(3, "\25\0R\0R\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000115>
789391 17:26:40 <... read resumed> "\25\0Q\0S\0\0\0", 8) = 8 <0.000021>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0P\0T\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0O\0U\0\0\0", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000102>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0N\0V\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0M\0W\0\0\0", 8) = 8 <0.000016>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000111>
789391 17:26:40 <... read resumed> "\25\0L\0X\0\0\0", 8) = 8 <0.000034>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0K\0Y\0\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0J\0Z\0\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000110>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0I\0[\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0H\0\\\0\0\0", 8) = 8 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000118>
789391 17:26:40 <... read resumed> "\25\0G\0]\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0F\0^\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0E\0_\0\0\0", 8) = 8 <0.000037>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0D\0`\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0C\0a\0\0\0", 8) = 8 <0.000038>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0B\0b\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000088>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0A\0c\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0@\0d\0\0\0", 8) = 8 <0.000026>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0?\0f\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000122>
789391 17:26:40 <... read resumed> "\25\0>\0h\0\0\0", 8) = 8 <0.000062>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0=\0i\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0<\0j\0\0\0", 8) = 8 <0.000036>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0;\0k\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000098>
789391 17:26:40 <... read resumed> "\25\0:\0l\0\0\0", 8) = 8 <0.000034>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0009\0m\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000102>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0008\0n\0\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0007\0o\0\0\0", 8) = 8 <0.000028>
789391 17:26:40 read(3, "\25\0006\0p\0\0\0", 8) = 8 <0.000027>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000155>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0005\0q\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0004\0r\0\0\0", 8) = 8 <0.000026>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 40000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0003\0s\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0002\0t\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000117>
789391 17:26:40 <... read resumed> "\25\0001\0u\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 nanosleep({0, 80000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0000\0v\0\0\0", 8) = 8 <0.000027>
789391 17:26:40 read(3, "\25\0/\0w\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000153>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 160000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0.\0x\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0-\0y\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0,\0z\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0+\0{\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000234>
789391 17:26:40 <... read resumed> "\25\0*\0|\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 nanosleep({0, 320000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0)\0}\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0(\0~\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0'\0\177\0\0\0", 8) = 8 <0.000027>
789391 17:26:40 read(3, "\25\0&\0\200\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0%\0\201\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0$\0\202\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000407>
789391 17:26:40 <... read resumed> "\25\0#\0\203\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 nanosleep({0, 640000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\"\0\204\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0!\0\205\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0 \0\211\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\37\0\212\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\36\0\214\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\35\0\215\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\34\0\216\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\33\0\217\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\32\0\220\0\0\0", 8) = 8 <0.000044>
789391 17:26:40 read(3, "\25\0\31\0\221\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\30\0\222\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000721>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 1280000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\27\0\223\0\0\0", 8) = 8 <0.000046>
789391 17:26:40 read(3, "\25\0\26\0\224\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\25\0\225\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\24\0\226\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\23\0\227\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\22\0\230\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\21\0\232\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0\20\0\235\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\17\0\236\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\16\0\237\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\r\0\240\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\f\0\241\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\v\0\242\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\n\0\272\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\t\0\273\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\10\0\274\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\7\0\275\0\0\0", 8) = 8 <0.000038>
789391 17:26:40 read(3, "\25\0\6\0\276\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\5\0\277\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\4\0\300\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\3\0\301\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\2\0\302\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.001366>
789391 17:26:40 <... read resumed> "\25\0\1\0\303\0\0\0", 8) = 8 <0.000030>
789392 17:26:40 epoll_pwait(8,  <unfinished ...>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... epoll_pwait resumed> [], 128, 0, NULL, 24381978099700) = 0 <0.000023>
789391 17:26:40 <... read resumed> "\25\0\0\1\304\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 futex(0xc000040bc8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
789391 17:26:40 futex(0x557a3ed9c888, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789392 17:26:40 <... futex resumed> )   = 1 <0.000024>
789394 17:26:40 <... futex resumed> )   = 0 <0.010810>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789394 17:26:40 futex(0x557a3ed9c888, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000026>
789391 17:26:40 <... futex resumed> )   = 0 <0.000085>
789394 17:26:40 futex(0xc000040bc8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000101>
789391 17:26:40 <... read resumed> "\6\0\0\0\0\0\377\177", 8) = 8 <0.000034>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\377\0\305\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0\376\0\306\0\0\0", 8) = 8 <0.000037>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\375\0\307\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000102>
789391 17:26:40 <... read resumed> "\25\0\374\0\310\0\0\0", 8) = 8 <0.000036>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\373\0\311\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 <... read resumed> "\25\0\372\0\312\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\371\0\313\0\0\0", 8) = 8 <0.000028>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 <... read resumed> "\25\0\370\0\314\0\0\0", 8) = 8 <0.000038>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\367\0\315\0\0\0", 8) = 8 <0.000026>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 <... read resumed> "\25\0\366\0\316\0\0\0", 8) = 8 <0.000035>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\365\0\317\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\364\0\320\0\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000101>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\363\0\321\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000060>
789391 17:26:40 <... read resumed> "\25\0\362\0\322\0\0\0", 8) = 8 <0.000023>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\361\0\323\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\360\0\325\0\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\357\0\326\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\356\0\327\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\355\0\330\0\0\0", 8) = 8 <0.000051>
789391 17:26:40 read(3, "\25\0\354\0\331\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000116>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\353\0\332\0\0\0", 8) = 8 <0.000062>
789391 17:26:40 read(3, "\25\0\352\0\333\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000101>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\351\0\334\0\0\0", 8) = 8 <0.000035>
789391 17:26:40 read(3, "\25\0\350\0\335\0\0\0", 8) = 8 <0.000026>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\347\0\336\0\0\0", 8) = 8 <0.000040>
789391 17:26:40 read(3, "\25\0\346\0\337\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000106>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\345\0\340\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\344\0\341\0\0\0", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000093>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\343\0\342\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\342\0\344\0\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000091>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\341\0\345\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\340\0\346\0\0\0", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000093>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\337\0\347\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\336\0\350\0\0\0", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000092>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\335\0\351\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\334\0\352\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000098>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\333\0\353\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\332\0\360\0\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0\331\0\361\0\0\0", 8) = 8 <0.000019>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\330\0\362\0\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\327\0\363\0\0\0", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\326\0\364\0\0\0", 8) = 8 <0.000028>
789391 17:26:40 read(3, "\25\0\325\0\365\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\324\0\367\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\323\0\373\0\0\0", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\322\0\374\0\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\321\0\375\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000105>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\320\0\376\0\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\317\0\377\0\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\316\0\1\1\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\315\0\2\1\0\0", 8) = 8 <0.000028>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000103>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\314\0\3\1\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\313\0\4\1\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000102>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\312\0\5\1\0\0", 8) = 8 <0.000061>
789391 17:26:40 read(3, "\25\0\311\0\6\1\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000150>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\310\0\7\1\0\0", 8) = 8 <0.000027>
789391 17:26:40 read(3, "\25\0\307\0\10\1\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000098>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\306\0\t\1\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\305\0\n\1\0\0", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000094>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\304\0\v\1\0\0", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\303\0\f\1\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 <... read resumed> "\25\0\302\0\r\1\0\0", 8) = 8 <0.000021>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\301\0\16\1\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\300\0\17\1\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\277\0\21\1\0\0", 8) = 8 <0.000034>
789391 17:26:40 read(3, "\25\0\276\0\22\1\0\0", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000109>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\275\0\23\1\0\0", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\274\0\24\1\0\0", 8) = 8 <0.000029>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000087>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\273\0\25\1\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000060>
789391 17:26:40 <... read resumed> "\25\0\272\0\26\1\0\0", 8) = 8 <0.000033>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\271\0\30\1\0\0", 8) = 8 <0.000028>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000095>
789391 17:26:40 <... read resumed> "\25\0\270\0\31\1\0\0", 8) = 8 <0.000033>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\267\0\32\1\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\266\0\33\1\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000093>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\265\0\34\1\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\264\0\35\1\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000094>
789391 17:26:40 <... read resumed> "\25\0\263\0\36\1\0\0", 8) = 8 <0.000018>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\262\0\37\1\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0\261\0 \1\0\0", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\260\0!\1\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\257\0\"\1\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000093>
789391 17:26:40 <... read resumed> "\25\0\256\0#\1\0\0", 8) = 8 <0.000018>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\255\0$\1\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000096>
789391 17:26:40 <... read resumed> "\25\0\254\0%\1\0\0", 8) = 8 <0.000032>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\253\0&\1\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0\252\0'\1\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000091>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\251\0(\1\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\250\0)\1\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 <... read resumed> "\25\0\247\0+\1\0\0", 8) = 8 <0.000020>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\246\0-\1\0\0", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0\245\0.\1\0\0", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\244\0002\1\0\0", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0\243\0003\1\0\0", 8) = 8 <0.000017>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000095>
789391 17:26:40 <... read resumed> "\25\0\242\0005\1\0\0", 8) = 8 <0.000026>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\241\0:\1\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\240\0;\1\0\0", 8) = 8 <0.000018>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000094>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\237\0<\1\0\0", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\236\0=\1\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000093>
789391 17:26:40 <... read resumed> "\25\0\235\0>\1\0\0", 8) = 8 <0.000021>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\234\0?\1\0\0", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\233\0B\1\0\0", 8) = 8 <0.000018>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000116>
789391 17:26:40 <... read resumed> "\25\0\232\0E\1\0\0", 8) = 8 <0.000020>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\231\0F\1\0\0", 8) = 8 <0.000023>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000110>
789391 17:26:40 <... read resumed> "\25\0\230\0\247\330\377\377", 8) = 8 <0.000053>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\227\0\254\330\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\226\0\256\330\377\377", 8) = 8 <0.000019>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000102>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\225\0\261\330\377\377", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\224\0\262\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000092>
789391 17:26:40 <... read resumed> "\25\0\223\0\264\330\377\377", 8) = 8 <0.000018>
789392 17:26:40 nanosleep({0, 40000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\222\0\266\330\377\377", 8) = 8 <0.000031>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000118>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 80000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\221\0\267\330\377\377", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\220\0\274\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\217\0\275\330\377\377", 8) = 8 <0.000018>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000122>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 160000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\216\0\276\330\377\377", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\215\0\277\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\214\0\300\330\377\377", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\213\0\301\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\212\0\302\330\377\377", 8) = 8 <0.000017>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000234>
789391 17:26:40 <... read resumed> "\25\0\211\0\303\330\377\377", 8) = 8 <0.000029>
789392 17:26:40 nanosleep({0, 320000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\210\0\304\330\377\377", 8) = 8 <0.000016>
789391 17:26:40 read(3, "\25\0\207\0\305\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\206\0\320\330\377\377", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0\205\0\323\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\204\0\324\330\377\377", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0\203\0\326\330\377\377", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0\202\0\327\330\377\377", 8) = 8 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000402>
789391 17:26:40 <... read resumed> "\25\0\201\0\330\330\377\377", 8) = 8 <0.000038>
789392 17:26:40 nanosleep({0, 640000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\200\0\333\330\377\377", 8) = 8 <0.000016>
789391 17:26:40 read(3, "\25\0\177\0\334\330\377\377", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0~\0\335\330\377\377", 8) = 8 <0.000034>
789391 17:26:40 read(3, "\25\0}\0\336\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0|\0\337\330\377\377", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0{\0\340\330\377\377", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0z\0\341\330\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0y\0\342\330\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0x\0\344\330\377\377", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0w\0\345\330\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0v\0\346\330\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0u\0\347\330\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0t\0\350\330\377\377", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000723>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 1280000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0s\0\351\330\377\377", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0r\0\354\330\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0q\0\222\377\377\377", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0p\0\223\377\377\377", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0o\0\0\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0n\0\1\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0m\0\2\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0l\0\3\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0k\0\4\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0j\0\5\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0i\0\6\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0h\0\7\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0g\0\10\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0f\0\t\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0e\0\n\0\0@", 8) = 8 <0.000031>
789391 17:26:40 read(3, "\25\0d\0\v\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0c\0\f\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0b\0\16\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0a\0\21\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0`\0\22\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0_\0\25\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0^\0\26\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0]\0\27\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\\\0\30\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0[\0\31\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0Z\0\32\0\0@", 8) = 8 <0.000029>
789391 17:26:40 read(3, "\25\0Y\0\33\0\0@", 8) = 8 <0.000028>
789391 17:26:40 read(3, "\25\0X\0\34\0\0@", 8) = 8 <0.000019>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.001358>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 epoll_pwait(8,  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0W\0\35\0\0@", 8) = 8 <0.000017>
789392 17:26:40 <... epoll_pwait resumed> [], 128, 0, NULL, 24381991144875) = 0 <0.000020>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 2560000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0V\0\36\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0U\0\37\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0T\0 \0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0S\0!\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0R\0\"\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0Q\0#\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0P\0$\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0O\0%\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0N\0&\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0M\0'\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0L\0(\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0K\0)\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0J\0*\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0I\0+\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0H\0,\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0G\0000\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0F\0001\0\0@", 8) = 8 <0.000041>
789391 17:26:40 read(3, "\25\0E\0002\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0D\0003\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0C\0004\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0B\0005\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0A\0009\0\0@", 8) = 8 <0.000032>
789391 17:26:40 read(3, "\25\0@\0:\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0?\0<\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0>\0=\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0=\0>\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0<\0?\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0;\0@\0\0@", 8) = 8 <0.000032>
789391 17:26:40 read(3, "\25\0:\0A\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0009\0B\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0008\0C\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0007\0D\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0006\0E\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0005\0F\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0004\0G\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0003\0H\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0002\0I\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0001\0J\0\0@", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0000\0K\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0/\0L\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0.\0M\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0-\0N\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0,\0O\0\0@", 8) = 8 <0.000031>
789391 17:26:40 read(3, "\25\0+\0P\0\0@", 8) = 8 <0.000028>
789391 17:26:40 read(3, "\25\0*\0Q\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.002637>
789391 17:26:40 <... read resumed> "\25\0)\0R\0\0@", 8) = 8 <0.000038>
789392 17:26:40 futex(0xc000040bc8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
789391 17:26:40 futex(0x557a3ed9c888, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789392 17:26:40 <... futex resumed> )   = 1 <0.000022>
789394 17:26:40 <... futex resumed> )   = 0 <0.012623>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789394 17:26:40 futex(0x557a3ed9c888, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000029>
789391 17:26:40 <... futex resumed> )   = 0 <0.000091>
789394 17:26:40 futex(0xc000040bc8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000120>
789391 17:26:40 <... read resumed> "\25\0(\0S\0\0@", 8) = 8 <0.000053>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0'\0T\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 <... read resumed> "\25\0&\0U\0\0@", 8) = 8 <0.000035>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0%\0V\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000093>
789391 17:26:40 <... read resumed> "\25\0$\0W\0\0@", 8) = 8 <0.000035>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0#\0X\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\"\0Y\0\0@", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000105>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0!\0Z\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0 \0[\0\0@", 8) = 8 <0.000026>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000107>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\37\0\\\0\0@", 8) = 8 <0.000032>
789391 17:26:40 read(3, "\25\0\36\0]\0\0@", 8) = 8 <0.000026>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000106>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\35\0^\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\34\0_\0\0@", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000101>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\33\0`\0\0@", 8) = 8 <0.000062>
789391 17:26:40 read(3, "\25\0\32\0a\0\0@", 8) = 8 <0.000069>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000149>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\31\0b\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\30\0c\0\0@", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\27\0d\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\26\0f\0\0@", 8) = 8 <0.000023>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000096>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\25\0h\0\0@", 8) = 8 <0.000038>
789391 17:26:40 read(3, "\25\0\24\0i\0\0@", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\23\0j\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000095>
789391 17:26:40 <... read resumed> "\25\0\22\0k\0\0@", 8) = 8 <0.000027>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\21\0l\0\0@", 8) = 8 <0.000029>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000107>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\20\0m\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\17\0n\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000101>
789391 17:26:40 <... read resumed> "\25\0\16\0o\0\0@", 8) = 8 <0.000019>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\r\0p\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0\f\0q\0\0@", 8) = 8 <0.000032>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000107>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\v\0r\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\n\0s\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 <... read resumed> "\25\0\t\0t\0\0@", 8) = 8 <0.000026>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\10\0u\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\7\0v\0\0@", 8) = 8 <0.000019>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000096>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\6\0w\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\5\0x\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000097>
789391 17:26:40 <... read resumed> "\25\0\4\0y\0\0@", 8) = 8 <0.000020>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\3\0z\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\2\0{\0\0@", 8) = 8 <0.000017>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000089>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\1\0|\0\0@", 8) = 8 <0.000029>
789391 17:26:40 read(3, "\25\0\0\1}\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\6\0\0\0\0\0\377\177", 8) = 8 <0.000034>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000134>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\377\0~\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\376\0\202\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000109>
789391 17:26:40 <... read resumed> "\25\0\375\0\204\0\0@", 8) = 8 <0.000022>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\374\0\205\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000103>
789391 17:26:40 <... read resumed> "\25\0\373\0\211\0\0@", 8) = 8 <0.000036>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\372\0\212\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 <... read resumed> "\25\0\371\0\214\0\0@", 8) = 8 <0.000021>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\370\0\215\0\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000112>
789391 17:26:40 <... read resumed> "\25\0\367\0\216\0\0@", 8) = 8 <0.000032>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\366\0\217\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0\365\0\220\0\0@", 8) = 8 <0.000017>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\364\0\221\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\363\0\222\0\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0\362\0\223\0\0@", 8) = 8 <0.000024>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\361\0\224\0\0@", 8) = 8 <0.000036>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000111>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\360\0\225\0\0@", 8) = 8 <0.000026>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000101>
789391 17:26:40 <... read resumed> "\25\0\357\0\226\0\0@", 8) = 8 <0.000039>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\356\0\227\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000104>
789391 17:26:40 <... read resumed> "\25\0\355\0\230\0\0@", 8) = 8 <0.000037>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\354\0\232\0\0@", 8) = 8 <0.000026>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000115>
789391 17:26:40 <... read resumed> "\25\0\353\0\235\0\0@", 8) = 8 <0.000037>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\352\0\236\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 <... read resumed> "\25\0\351\0\237\0\0@", 8) = 8 <0.000036>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\350\0\240\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000100>
789391 17:26:40 <... read resumed> "\25\0\347\0\241\0\0@", 8) = 8 <0.000042>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\346\0\242\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\345\0\272\0\0@", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000129>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\344\0\273\0\0@", 8) = 8 <0.000044>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000076>
789391 17:26:40 <... read resumed> "\25\0\343\0\274\0\0@", 8) = 8 <0.000039>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\342\0\275\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\341\0\276\0\0@", 8) = 8 <0.000027>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000108>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\340\0\277\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\337\0\300\0\0@", 8) = 8 <0.000025>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\336\0\301\0\0@", 8) = 8 <0.000067>
789391 17:26:40 read(3, "\25\0\335\0\302\0\0@", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000119>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\334\0\303\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3, "\25\0\333\0\304\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000102>
789391 17:26:40 <... read resumed> "\25\0\332\0\305\0\0@", 8) = 8 <0.000025>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\331\0\306\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\330\0\307\0\0@", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000099>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\327\0\310\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\326\0\311\0\0@", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000106>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\325\0\312\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\324\0\313\0\0@", 8) = 8 <0.000020>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000110>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\323\0\314\0\0@", 8) = 8 <0.000027>
789391 17:26:40 read(3, "\25\0\322\0\317\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000106>
789391 17:26:40 <... read resumed> "\25\0\321\0\320\0\0@", 8) = 8 <0.000023>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\320\0\322\0\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\317\0\325\0\0@", 8) = 8 <0.000031>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000113>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\316\0\330\0\0@", 8) = 8 <0.000028>
789391 17:26:40 read(3, "\25\0\315\0\331\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000109>
789391 17:26:40 <... read resumed> "\25\0\314\0\332\0\0@", 8) = 8 <0.000028>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\313\0\333\0\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\312\0\334\0\0@", 8) = 8 <0.000017>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000106>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\311\0\335\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\310\0\337\0\0@", 8) = 8 <0.000029>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000110>
789391 17:26:40 <... read resumed> "\25\0\307\0\340\0\0@", 8) = 8 <0.000022>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\306\0\341\0\0@", 8) = 8 <0.000020>
789391 17:26:40 read(3, "\25\0\305\0\342\0\0@", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000109>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\304\0\344\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\303\0\345\0\0@", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000122>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\302\0\346\0\0@", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0\301\0\347\0\0@", 8) = 8 <0.000022>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000116>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\300\0\350\0\0@", 8) = 8 <0.000026>
789391 17:26:40 read(3, "\25\0\277\0\351\0\0@", 8) = 8 <0.000034>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000096>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 20000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\276\0\352\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\275\0\353\0\0@", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000092>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 epoll_pwait(8,  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\274\0\360\0\0@", 8) = 8 <0.000023>
789392 17:26:40 <... epoll_pwait resumed> [], 128, 0, NULL, 24382004206664) = 0 <0.000022>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 40000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\273\0\361\0\0@", 8) = 8 <0.000025>
789391 17:26:40 read(3, "\25\0\272\0\362\0\0@", 8) = 8 <0.000024>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000120>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 80000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\271\0\363\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\270\0\365\0\0@", 8) = 8 <0.000042>
789391 17:26:40 read(3, "\25\0\267\0\373\0\0@", 8) = 8 <0.000021>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000152>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 nanosleep({0, 160000},  <unfinished ...>
789391 17:26:40 <... read resumed> "\25\0\266\0\374\0\0@", 8) = 8 <0.000024>
789391 17:26:40 read(3, "\25\0\265\0\375\0\0@", 8) = 8 <0.000038>
789391 17:26:40 read(3, "\25\0\264\0\376\0\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0\263\0\377\0\0@", 8) = 8 <0.000023>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000242>
789391 17:26:40 <... read resumed> "\25\0\262\0\1\1\0@", 8) = 8 <0.000027>
789392 17:26:40 nanosleep({0, 320000},  <unfinished ...>
789391 17:26:40 read(3, "\25\0\261\0\2\1\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\260\0\3\1\0@", 8) = 8 <0.000022>
789391 17:26:40 read(3, "\25\0\257\0\4\1\0@", 8) = 8 <0.000021>
789391 17:26:40 read(3, "\25\0\256\0\5\1\0@", 8) = 8 <0.000019>
789391 17:26:40 read(3, "\25\0\255\0\6\1\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0\254\0\7\1\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3, "\25\0\253\0\10\1\0@", 8) = 8 <0.000017>
789391 17:26:40 read(3, "\25\0\252\0\t\1\0@", 8) = 8 <0.000018>
789391 17:26:40 read(3,  <unfinished ...>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000412>
789391 17:26:40 <... read resumed> "", 8) = 0 <0.000025>
789392 17:26:40 nanosleep({0, 640000},  <unfinished ...>
789391 17:26:40 epoll_ctl(8, EPOLL_CTL_DEL, 3, 0xc0001ecc7c) = 0 <0.000025>
789391 17:26:40 close(3)                = 0 <0.000048>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.000733>
789392 17:26:40 nanosleep({0, 1280000},  <unfinished ...>
789391 17:26:40 prctl(PR_SET_SECCOMP, SECCOMP_MODE_FILTER, {len=526, filter=0xc0002c2000}) = -1 EINVAL (Invalid argument) <0.000032>
789391 17:26:40 write(4, "{\"type\":\"procError\"}", 20) = 20 <0.000048>
789392 17:26:40 <... nanosleep resumed> NULL) = 0 <0.001398>
789392 17:26:40 nanosleep({0, 2560000},  <unfinished ...>
789391 17:26:40 futex(0xc000040bc8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
789394 17:26:40 <... futex resumed> )   = 0 <0.010610>
789391 17:26:40 <... futex resumed> )   = 1 <0.000039>
789394 17:26:40 futex(0x557a3ed9c888, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000021>
789394 17:26:40 futex(0xc000040bc8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
789391 17:26:40 openat(AT_FDCWD, "/etc//localtime", O_RDONLY) = 3 <0.000061>
789391 17:26:40 read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\4\0\0\0\0\0\0UTC\0\0\0TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0\0\0\0\0\0\0\1\0\0\0\1\0\0\0\4\370\0\0\0\0\0\0\0\0\0\0\0\0\0\0UTC\0\0\0\nUTC0\n", 4096) = 127 <0.000018>
789391 17:26:40 read(3, "", 4096)       = 0 <0.000017>
789391 17:26:40 close(3)                = 0 <0.000018>
789391 17:26:40 write(4, "{\"Timestamp\":\"2021-03-27T09:26:40.867423322Z\",\"ECode\":10,\"Cause\":\"\",\"Message\":\"error loading seccomp filter into kernel: loading seccomp filter: invalid argument\",\"Stack\":{\"Frames\":[{\"File\":\"factory_linux.go\",\"Function\":\"func1\",\"Package\":\"github.com/opencontainers/runc/libcontainer.(*LinuxFactory).StartInitialization\",\"Line\":379},{\"File\":\"factory_linux.go\",\"Function\":\"StartInitialization\",\"Package\":\"github.com/opencontainers/runc/libcontainer.(*LinuxFactory)\",\"Line\":396},{\"File\":\"init.go\",\"Function\":\"func6\",\"Package\":\"main.glob.\",\"Line\":43},{\"File\":\"app.go\",\"Function\":\"HandleAction\",\"Package\":\"github.com/opencontainers/runc/vendor/github.com/urfave/cli\",\"Line\":523},{\"File\":\"command.go\",\"Function\":\"Run\",\"Package\":\"github.com/opencontainers/runc/vendor/github.com/urfave/cli.Command\",\"Line\":174},{\"File\":\"app.go\",\"Function\":\"Run\",\"Package\":\"github.com/opencontainers/runc/vendor/github.com/urfave/cli.(*App)\",\"Line\":276},{\"File\":\"main.go\",\"Function\":\"main\",\"Package\":\"main\",\"Line\":160},{\"File\":\"proc.go\",\"Function\":\"main\",\"Package\":\"runtime\",\"Line\":203},{\"File\":\"asm_amd64.s\",\"Function\":\"goexit\",\"Package\":\"runtime\",\"Line\":1357}]}}", 1139) = 1139 <0.000026>
789391 17:26:40 close(4)                = 0 <0.000891>
789391 17:26:40 exit_group(1)           = ?
789395 17:26:40 +++ exited with 1 +++
789394 17:26:40 +++ exited with 1 +++
789393 17:26:40 +++ exited with 1 +++
789392 17:26:40 +++ exited with 1 +++
789391 17:26:40 +++ exited with 1 +++

@dannylee-
Copy link

dannylee- commented Mar 31, 2021

We saw a similar issue. We upp'd the /proc/sys/fs/pipe-user-pages-soft to 65535 and that seemed to solve it. We haven't figured out why, but we got the idea from these Chinese blogs (will require Google Translating the page) - https://www.igoodtv.com/p/1921069.html
https://www.likakuli.com/posts/docker-hang/

@cpuguy83
Copy link
Contributor Author

@wu0407 This is related to #2865

The issue reported here in 2828 is definitely different.

@cpuguy83
Copy link
Contributor Author

To resolve I'd recommend downgrading to rc92 if you can.

@wu0407
Copy link

wu0407 commented Apr 1, 2021

To resolve I'd recommend downgrading to rc92 if you can.

I try rc92 it work.

@kolyshkin
Copy link
Contributor

This might be fixed by #2871, which was just merged

@dannylee- @wu0407 @cpuguy83 can you please test the runc tip and report back if the bug is fixed?

@cpuguy83
Copy link
Contributor Author

cpuguy83 commented Apr 2, 2021

@kolyshkin I don't think this issue is related. In the case fixed by #2871 runc was blocked writing to the pipe for libseccomp.

In this issue something happens on the system (like OOM?) and runc is blocked on opening the init fifo b/c the main runc is not running.

@wu0407
Copy link

wu0407 commented Apr 3, 2021

commit: 0d49470 fixed
commit: 8c4dca8 fixed

@kolyshkin
Copy link
Contributor

In this issue something happens on the system (like OOM?) and runc is blocked on opening the init fifo b/c the main runc is not running.

Right, sorry I mixed these up.

As I said earlier, a subsequent runc delete should remove the container directory, including the fifo on which runc init waits, which should result in runc init exit.

@cpuguy83
Copy link
Contributor Author

cpuguy83 commented Apr 8, 2021

We can close for now, I haven't received a reliable way to reproduce the issue.

@cpuguy83 cpuguy83 closed this as completed Apr 8, 2021
@dannylee-
Copy link

dannylee- commented Apr 8, 2021

I'm not sure if it's the same issue, but you can reproduce this by doing the following:

  1. Setting /proc/sys/fs/pipe-user-pages-soft to 1. (echo 1 > /proc/sys/fs/pipe-user-pages-soft)
  2. Start a docker container
  3. Run "docker exec <container_id> ls"

If you run this on runc 1.0.0-rc93, the docker exec call will hang and there will be a hanging "runc init" process. Also, if the container has a healthcheck, it will start accumulating hanging "runc init" processes.

If you run this on runc 1.0.0-rc92, everything works fine.

@cpuguy83
Copy link
Contributor Author

cpuguy83 commented Apr 8, 2021

@dannylee- Different issue, and that should be fixed on HEAD. Can you try with that?

@kolyshkin
Copy link
Contributor

@dannylee- this is #2871

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

5 participants