I1213 23:09:08.796468 17733 x:0] *************************** I1213 23:09:08.796580 17733 x:0] Args: [/syzkaller/managers/kvm-direct-overlay-host-race/current/image -root /syzkaller/managers/kvm-direct-overlay-host-race/workdir/gvisor_root -watchdog-action=panic -trace-signal=12 -network=none -debug -platform=ptrace -file-access=exclusive -overlay -network=host exec -user=0:0 -cap CAP_CHOWN -cap CAP_DAC_OVERRIDE -cap CAP_DAC_READ_SEARCH -cap CAP_FOWNER -cap CAP_FSETID -cap CAP_KILL -cap CAP_SETGID -cap CAP_SETUID -cap CAP_SETPCAP -cap CAP_LINUX_IMMUTABLE -cap CAP_NET_BIND_SERVICE -cap CAP_NET_BROADCAST -cap CAP_NET_ADMIN -cap CAP_NET_RAW -cap CAP_IPC_LOCK -cap CAP_IPC_OWNER -cap CAP_SYS_MODULE -cap CAP_SYS_RAWIO -cap CAP_SYS_CHROOT -cap CAP_SYS_PTRACE -cap CAP_SYS_PACCT -cap CAP_SYS_ADMIN -cap CAP_SYS_BOOT -cap CAP_SYS_NICE -cap CAP_SYS_RESOURCE -cap CAP_SYS_TIME -cap CAP_SYS_TTY_CONFIG -cap CAP_MKNOD -cap CAP_LEASE -cap CAP_AUDIT_WRITE -cap CAP_AUDIT_CONTROL -cap CAP_SETFCAP -cap CAP_MAC_OVERRIDE -cap CAP_MAC_ADMIN -cap CAP_SYSLOG -cap CAP_WAKE_ALARM -cap CAP_BLOCK_SUSPEND -cap CAP_AUDIT_READ ci-gvisor-kvm-direct-overlay-host-race-3 /syz-fuzzer -executor=/syz-executor -name=vm-3 -arch=amd64 -manager=stdin -sandbox=none -procs=4 -v=0 -cover=false -debug=false -test=false] I1213 23:09:08.796735 17733 x:0] Git Revision: 6253d32cc932e76608be5c57a4870b3d61464487 I1213 23:09:08.796749 17733 x:0] PID: 17733 I1213 23:09:08.796763 17733 x:0] UID: 0, GID: 0 I1213 23:09:08.796789 17733 x:0] Configuration: I1213 23:09:08.796798 17733 x:0] RootDir: /syzkaller/managers/kvm-direct-overlay-host-race/workdir/gvisor_root I1213 23:09:08.796809 17733 x:0] Platform: ptrace I1213 23:09:08.796834 17733 x:0] FileAccess: exclusive, overlay: true I1213 23:09:08.796852 17733 x:0] Network: host, logging: false I1213 23:09:08.796875 17733 x:0] Strace: false, max size: 1024, syscalls: [] I1213 23:09:08.796908 17733 x:0] *************************** D1213 23:09:08.797126 17733 x:0] Load container "/syzkaller/managers/kvm-direct-overlay-host-race/workdir/gvisor_root" "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.799122 17733 x:0] Signal container "ci-gvisor-kvm-direct-overlay-host-race-3": signal 0 D1213 23:09:08.799186 17733 x:0] Signal sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.799215 17733 x:0] Connecting to sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.799530 17733 x:0] urpc: successfully marshalled 120 bytes. D1213 23:09:08.799880 17450 x:0] urpc: unmarshal success. D1213 23:09:08.800123 17450 x:0] containerManager.Signal &{CID:ci-gvisor-kvm-direct-overlay-host-race-3 Signo:0 PID:0 Mode:Process} D1213 23:09:08.800290 17450 x:0] urpc: successfully marshalled 37 bytes. D1213 23:09:08.800394 17733 x:0] urpc: unmarshal success. D1213 23:09:08.800466 17733 x:0] Execute in container "ci-gvisor-kvm-direct-overlay-host-race-3", args: /syz-fuzzer -executor=/syz-executor -name=vm-3 -arch=amd64 -manager=stdin -sandbox=none -procs=4 -v=0 -cover=false -debug=false -test=false D1213 23:09:08.800526 17733 x:0] Executing new process in container "ci-gvisor-kvm-direct-overlay-host-race-3" in sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.800556 17733 x:0] Connecting to sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.801412 17733 x:0] urpc: successfully marshalled 549 bytes. D1213 23:09:08.801660 17450 x:0] urpc: unmarshal success. D1213 23:09:08.802243 17450 x:0] containerManager.ExecuteAsync: /syz-fuzzer -executor=/syz-executor -name=vm-3 -arch=amd64 -manager=stdin -sandbox=none -procs=4 -v=0 -cover=false -debug=false -test=false I1213 23:09:08.802673 17450 x:0] EXEC: [/syz-fuzzer -executor=/syz-executor -name=vm-3 -arch=amd64 -manager=stdin -sandbox=none -procs=4 -v=0 -cover=false -debug=false -test=false] D1213 23:09:08.803144 17450 x:0] send [FD 6] [Tag 000001] Twalkgetattr{FID: 1, NewFID: 4, Names: [syz-fuzzer]} D1213 23:09:08.804200 17450 x:0] recv [FD 6] [Tag 000001] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 18290144, BlockSize: 4096, Blocks: 35728, ATime: {Sec: 1544716303, NanoSec: 827895343}, MTime: {Sec: 1544716303, NanoSec: 827895343}, CTime: {Sec: 1544742548, NanoSec: 767425003}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 9044072}]} D1213 23:09:08.804503 17450 x:0] send [FD 6] [Tag 000001] Twalk{FID: 4, NewFID: 5, Names: []} D1213 23:09:08.805042 17450 x:0] recv [FD 6] [Tag 000001] Rwalk{QIDs: [QID{Type: 0, Version: 0, Path: 9044072}]} D1213 23:09:08.805123 17450 x:0] send [FD 6] [Tag 000001] Tlopen{FID: 5, Flags: ReadOnly} D1213 23:09:08.805650 17450 x:0] recv [FD 6] [Tag 000001] Rlopen{QID: QID{Type: 0, Version: 0, Path: 9044072}, IoUnit: 0, File: &{{29}}} D1213 23:09:08.811718 17450 x:0] Allocating stack with size of 8388608 bytes D1213 23:09:08.812781 17450 x:0] updated processes: map[{ci-gvisor-kvm-direct-overlay-host-race-3 0}:0xc0002ac3c0 {ci-gvisor-kvm-direct-overlay-host-race-3 15}:0xc00031cbf0] D1213 23:09:08.812990 17450 x:0] urpc: successfully marshalled 37 bytes. D1213 23:09:08.813087 17733 x:0] urpc: unmarshal success. D1213 23:09:08.813142 17733 x:0] Wait on PID 15 in container "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.813194 17733 x:0] Waiting for PID 15 in sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.813231 17733 x:0] Connecting to sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:08.813374 17733 x:0] urpc: successfully marshalled 122 bytes. D1213 23:09:08.813673 17450 x:0] urpc: unmarshal success. D1213 23:09:08.813831 17450 x:0] containerManager.Wait D1213 23:09:08.815005 17450 x:0] [ 15] Interrupt queued D1213 23:09:08.950531 17450 x:0] [ 16] Interrupt queued D1213 23:09:08.952248 17450 x:0] [ 17] Interrupt queued D1213 23:09:08.954374 17450 x:0] [ 18] Interrupt queued D1213 23:09:08.959439 17450 x:0] [ 19] Interrupt queued D1213 23:09:08.976811 17450 x:0] [ 20] Interrupt queued D1213 23:09:08.981406 17450 x:0] [ 21] Interrupt queued D1213 23:09:08.993196 17450 x:0] [ 22] Interrupt queued D1213 23:09:09.006730 17450 x:0] [ 23] Interrupt queued D1213 23:09:09.009569 17450 x:0] send [FD 6] [Tag 000001] Twalkgetattr{FID: 1, NewFID: 6, Names: [etc]} D1213 23:09:09.010255 17450 x:0] recv [FD 6] [Tag 000001] Rlerror{Error: 2} 2018/12/13 23:09:09 fuzzer started D1213 23:09:09.045328 17450 x:0] [ 24] Interrupt queued D1213 23:09:09.048880 17450 x:0] [ 25] Interrupt queued D1213 23:09:09.059471 17450 x:0] [ 26] Interrupt queued D1213 23:09:09.067679 17450 x:0] [ 27] Interrupt queued D1213 23:09:09.078526 17450 x:0] [ 28] Interrupt queued D1213 23:09:09.089320 17450 x:0] [ 29] Interrupt queued D1213 23:09:09.107972 17450 x:0] [ 30] Interrupt queued D1213 23:09:09.114501 17450 x:0] [ 31] Interrupt queued D1213 23:09:09.130788 17450 x:0] [ 32] Interrupt queued D1213 23:09:09.142191 17450 x:0] [ 33] Interrupt queued D1213 23:09:09.161443 17450 x:0] [ 34] Interrupt queued D1213 23:09:09.169641 17450 x:0] [ 35] Interrupt queued D1213 23:09:09.187651 17450 x:0] [ 36] Interrupt queued D1213 23:09:09.194705 17450 x:0] [ 37] Interrupt queued D1213 23:09:09.216508 17450 x:0] [ 38] Interrupt queued D1213 23:09:09.225649 17450 x:0] [ 39] Interrupt queued D1213 23:09:09.244287 17450 x:0] [ 40] Interrupt queued D1213 23:09:09.244616 17450 x:0] Time: Adjusting syscall overhead up to 4000 I1213 23:09:09.244732 17450 x:0] CalibratedClock(Monotonic): ready D1213 23:09:09.244799 17450 x:0] Time: Adjusting syscall overhead up to 4000 I1213 23:09:09.244847 17450 x:0] CalibratedClock(Realtime): ready D1213 23:09:09.244884 17450 x:0] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:14633859082089477 monotonicBaseRef:1000386841 monotonicFrequency:2299798474 realtimeReady:1 realtimeBaseCycles:14633859082353639 realtimeBaseRef:1544742549244838179 realtimeFrequency:2299798522} D1213 23:09:09.250664 17450 x:0] [ 41] Interrupt queued D1213 23:09:09.256659 17450 x:0] [ 42] Interrupt queued D1213 23:09:09.263736 17450 x:0] [ 43] Interrupt queued D1213 23:09:09.268859 17450 x:0] [ 44] Interrupt queued D1213 23:09:09.277207 17450 x:0] [ 45] Interrupt queued D1213 23:09:09.287416 17450 x:0] [ 46] Interrupt queued D1213 23:09:09.290437 17450 x:0] [ 47] Interrupt queued D1213 23:09:09.298574 17450 x:0] [ 48] Interrupt queued D1213 23:09:09.306015 17450 x:0] [ 49] Interrupt queued D1213 23:09:09.313879 17450 x:0] [ 50] Interrupt queued D1213 23:09:09.326653 17450 x:0] [ 51] Interrupt queued D1213 23:09:09.341071 17450 x:0] [ 52] Interrupt queued D1213 23:09:09.354393 17450 x:0] [ 53] Interrupt queued D1213 23:09:09.369290 17450 x:0] [ 54] Interrupt queued D1213 23:09:09.382885 17450 x:0] [ 55] Interrupt queued D1213 23:09:09.398420 17450 x:0] [ 56] Interrupt queued D1213 23:09:09.414308 17450 x:0] [ 57] Interrupt queued D1213 23:09:09.427921 17450 x:0] [ 58] Interrupt queued D1213 23:09:09.441248 17450 x:0] [ 59] Interrupt queued D1213 23:09:09.457099 17450 x:0] [ 60] Interrupt queued D1213 23:09:09.469399 17450 x:0] [ 61] Interrupt queued D1213 23:09:09.487449 17450 x:0] [ 62] Interrupt queued D1213 23:09:09.496817 17450 x:0] [ 63] Interrupt queued D1213 23:09:09.512260 17450 x:0] [ 64] Interrupt queued D1213 23:09:09.524701 17450 x:0] [ 65] Interrupt queued D1213 23:09:09.536845 17450 x:0] [ 66] Interrupt queued D1213 23:09:09.549634 17450 x:0] [ 67] Interrupt queued D1213 23:09:09.564821 17450 x:0] [ 68] Interrupt queued D1213 23:09:09.579627 17450 x:0] [ 69] Interrupt queued D1213 23:09:09.592971 17450 x:0] [ 70] Interrupt queued D1213 23:09:09.608495 17450 x:0] [ 71] Interrupt queued D1213 23:09:09.635513 17450 x:0] [ 72] Interrupt queued D1213 23:09:09.648233 17450 x:0] [ 73] Interrupt queued D1213 23:09:09.678477 17450 x:0] [ 74] Interrupt queued D1213 23:09:09.694812 17450 x:0] [ 75] Interrupt queued D1213 23:09:09.709818 17450 x:0] [ 76] Interrupt queued D1213 23:09:09.763151 17450 x:0] [ 77] Interrupt queued D1213 23:09:09.792632 17450 x:0] [ 78] Interrupt queued D1213 23:09:09.902704 17450 x:0] [ 79] Interrupt queued 2018/12/13 23:09:10 dialing manager at stdin D1213 23:09:10.052731 17450 x:0] [ 80] Interrupt queued 2018/12/13 23:09:10 syscalls: 1 2018/12/13 23:09:10 code coverage: debugfs is not enabled or not mounted 2018/12/13 23:09:10 comparison tracing: debugfs is not enabled or not mounted 2018/12/13 23:09:10 setuid sandbox: enabled 2018/12/13 23:09:10 namespace sandbox: enabled 2018/12/13 23:09:10 Android sandbox: /sys/fs/selinux/policy does not exist 2018/12/13 23:09:10 fault injection: CONFIG_FAULT_INJECTION is not enabled 2018/12/13 23:09:10 leak checking: debugfs is not enabled or not mounted 2018/12/13 23:09:10 net packet injection: /dev/net/tun does not exist 2018/12/13 23:09:10 net device setup: ip command is not found D1213 23:09:10.118409 17450 x:0] [ 81] Interrupt queued D1213 23:09:10.166788 17450 x:0] [ 82] Interrupt queued D1213 23:09:10.194394 17450 x:0] [ 83] Interrupt queued D1213 23:09:10.222484 17450 x:0] [ 84] Interrupt queued D1213 23:09:10.244540 17450 x:0] Clock(Monotonic): error: 226 ns, adjusted frequency from 2299798474 Hz to 2299799385 Hz D1213 23:09:10.244736 17450 x:0] Clock(Realtime): error: 251 ns, adjusted frequency from 2299798522 Hz to 2299799451 Hz D1213 23:09:10.244778 17450 x:0] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:14633861381428631 monotonicBaseRef:2000187119 monotonicFrequency:2299799385 realtimeReady:1 realtimeBaseCycles:14633861381908933 realtimeBaseRef:1544742550244732418 realtimeFrequency:2299799451} D1213 23:09:10.259630 17450 x:0] [ 85] Interrupt queued D1213 23:09:10.334746 17450 x:0] [ 86] Interrupt queued D1213 23:09:10.376227 17450 x:0] [ 87] Interrupt queued D1213 23:09:10.508349 17450 x:0] [ 88] Interrupt queued D1213 23:09:10.560114 17450 x:0] [ 89] Interrupt queued D1213 23:09:11.244536 17450 x:0] Clock(Monotonic): error: 93 ns, adjusted frequency from 2299799385 Hz to 2299799156 Hz D1213 23:09:11.244729 17450 x:0] Clock(Realtime): error: 91 ns, adjusted frequency from 2299799451 Hz to 2299799168 Hz D1213 23:09:11.244765 17450 x:0] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:14633863681234102 monotonicBaseRef:3000189765 monotonicFrequency:2299799156 realtimeReady:1 realtimeBaseCycles:14633863681690990 realtimeBaseRef:1544742551244724854 realtimeFrequency:2299799168} D1213 23:09:11.495369 17450 x:0] [ 90] Interrupt queued W1213 23:09:11.625275 17733 x:0] FATAL ERROR: error waiting on pid 15: error waiting on PID 15 in sandbox "ci-gvisor-kvm-direct-overlay-host-race-3": urpc method "containerManager.WaitPID" failed: EOF error waiting on pid 15: error waiting on PID 15 in sandbox "ci-gvisor-kvm-direct-overlay-host-race-3": urpc method "containerManager.WaitPID" failed: EOF W1213 23:09:11.631601 17422 x:0] Wait RPC to container "ci-gvisor-kvm-direct-overlay-host-race-3" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D1213 23:09:11.631862 17422 x:0] Destroy container "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:11.631901 17422 x:0] Destroying container "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:11.631934 17422 x:0] Destroying root container "ci-gvisor-kvm-direct-overlay-host-race-3" by destroying sandbox D1213 23:09:11.631981 17422 x:0] Destroy sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:11.632022 17422 x:0] Killing sandbox "ci-gvisor-kvm-direct-overlay-host-race-3" D1213 23:09:11.632314 17422 x:0] Killing gofer for container "ci-gvisor-kvm-direct-overlay-host-race-3", PID: 17445 I1213 23:09:16.632805 17422 x:0] Exiting with status: 9