D0228 11:36:59.785389 64421 sampler.go:168] Time: Adjusting syscall overhead up to 8000 I0228 11:36:59.785603 64421 calibrated_clock.go:79] CalibratedClock(Monotonic): ready I0228 11:36:59.785757 64421 calibrated_clock.go:79] CalibratedClock(Realtime): ready D0228 11:36:59.785847 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697201533701170 monotonicBaseRef:1000444384 monotonicFrequency:2299774148 realtimeReady:1 realtimeBaseCycles:8697201534067765 realtimeBaseRef:1582889819785752498 realtimeFrequency:2299774304} D0228 11:37:00.785476 64421 parameters.go:238] Clock(Monotonic): error: -172 ns, adjusted frequency from 2299774148 Hz to 2299774114 Hz D0228 11:37:00.785699 64421 parameters.go:238] Clock(Realtime): error: 181 ns, adjusted frequency from 2299774304 Hz to 2299774909 Hz D0228 11:37:00.786056 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697203833168523 monotonicBaseRef:2000310981 monotonicFrequency:2299774114 realtimeReady:1 realtimeBaseCycles:8697203833701480 realtimeBaseRef:1582889820785691366 realtimeFrequency:2299774909} D0228 11:37:01.785920 64421 parameters.go:238] Clock(Monotonic): error: 416 ns, adjusted frequency from 2299774114 Hz to 2299775526 Hz D0228 11:37:01.786231 64421 parameters.go:238] Clock(Realtime): error: 155 ns, adjusted frequency from 2299774909 Hz to 2299774912 Hz D0228 11:37:01.786388 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697206133151287 monotonicBaseRef:3000401707 monotonicFrequency:2299775526 realtimeReady:1 realtimeBaseCycles:8697206134705897 realtimeBaseRef:1582889821786225987 realtimeFrequency:2299774912} D0228 11:37:02.785623 64421 parameters.go:238] Clock(Monotonic): error: 102 ns, adjusted frequency from 2299775526 Hz to 2299774699 Hz D0228 11:37:02.785853 64421 parameters.go:238] Clock(Realtime): error: 30 ns, adjusted frequency from 2299774912 Hz to 2299774644 Hz D0228 11:37:02.785981 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697208432587722 monotonicBaseRef:4000254261 monotonicFrequency:2299774699 realtimeReady:1 realtimeBaseCycles:8697208433609740 realtimeBaseRef:1582889822785847224 realtimeFrequency:2299774644} D0228 11:37:03.785427 64421 parameters.go:238] Clock(Monotonic): error: -373 ns, adjusted frequency from 2299774699 Hz to 2299773725 Hz D0228 11:37:03.785738 64421 parameters.go:238] Clock(Realtime): error: -55 ns, adjusted frequency from 2299774644 Hz to 2299774446 Hz D0228 11:37:03.785867 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697210732363377 monotonicBaseRef:5000254676 monotonicFrequency:2299773725 realtimeReady:1 realtimeBaseCycles:8697210733109254 realtimeBaseRef:1582889823785727590 realtimeFrequency:2299774446} D0228 11:37:04.785431 64421 parameters.go:238] Clock(Monotonic): error: 350 ns, adjusted frequency from 2299773725 Hz to 2299775283 Hz D0228 11:37:04.785596 64421 parameters.go:238] Clock(Realtime): error: 9 ns, adjusted frequency from 2299774446 Hz to 2299774608 Hz D0228 11:37:04.785719 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697213032167376 monotonicBaseRef:6000267839 monotonicFrequency:2299775283 realtimeReady:1 realtimeBaseCycles:8697213032572774 realtimeBaseRef:1582889824785592391 realtimeFrequency:2299774608} D0228 11:37:05.785458 64421 parameters.go:238] Clock(Monotonic): error: 75 ns, adjusted frequency from 2299775283 Hz to 2299774646 Hz D0228 11:37:05.785667 64421 parameters.go:238] Clock(Realtime): error: 35 ns, adjusted frequency from 2299774608 Hz to 2299774675 Hz D0228 11:37:05.785790 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697215331997805 monotonicBaseRef:7000291817 monotonicFrequency:2299774646 realtimeReady:1 realtimeBaseCycles:8697215332508801 realtimeBaseRef:1582889825785662580 realtimeFrequency:2299774675} D0228 11:37:06.785500 64421 parameters.go:238] Clock(Monotonic): error: 197 ns, adjusted frequency from 2299774646 Hz to 2299774948 Hz D0228 11:37:06.785718 64421 parameters.go:238] Clock(Realtime): error: 28 ns, adjusted frequency from 2299774675 Hz to 2299774668 Hz D0228 11:37:06.785839 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697217631777171 monotonicBaseRef:8000293869 monotonicFrequency:2299774948 realtimeReady:1 realtimeBaseCycles:8697217632396873 realtimeBaseRef:1582889826785711887 realtimeFrequency:2299774668} D0228 11:37:07.785457 64421 parameters.go:238] Clock(Monotonic): error: -58 ns, adjusted frequency from 2299774948 Hz to 2299774407 Hz D0228 11:37:07.785659 64421 parameters.go:238] Clock(Realtime): error: -1 ns, adjusted frequency from 2299774668 Hz to 2299774605 Hz D0228 11:37:07.785739 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697219931553118 monotonicBaseRef:9000294303 monotonicFrequency:2299774407 realtimeReady:1 realtimeBaseCycles:8697219932038812 realtimeBaseRef:1582889827785654173 realtimeFrequency:2299774605} D0228 11:37:08.785486 64421 parameters.go:238] Clock(Monotonic): error: -307 ns, adjusted frequency from 2299774407 Hz to 2299773961 Hz D0228 11:37:08.785748 64421 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0228 11:37:08.785905 64421 parameters.go:238] Clock(Realtime): error: 518 ns, adjusted frequency from 2299774605 Hz to 2299775792 Hz D0228 11:37:08.786080 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697222231388082 monotonicBaseRef:10000320634 monotonicFrequency:2299773961 realtimeReady:1 realtimeBaseCycles:8697222232369053 realtimeBaseRef:1582889828785895777 realtimeFrequency:2299775792} D0228 11:37:09.785481 64421 parameters.go:238] Clock(Monotonic): error: 114 ns, adjusted frequency from 2299773961 Hz to 2299774915 Hz D0228 11:37:09.785715 64421 parameters.go:238] Clock(Realtime): error: -96 ns, adjusted frequency from 2299775792 Hz to 2299774375 Hz D0228 11:37:09.785839 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697224531084104 monotonicBaseRef:11000286744 monotonicFrequency:2299774915 realtimeReady:1 realtimeBaseCycles:8697224531715977 realtimeBaseRef:1582889829785709294 realtimeFrequency:2299774375} D0228 11:37:10.785422 64421 parameters.go:238] Clock(Monotonic): error: 273 ns, adjusted frequency from 2299774915 Hz to 2299775145 Hz D0228 11:37:10.785625 64421 parameters.go:238] Clock(Realtime): error: -18 ns, adjusted frequency from 2299774375 Hz to 2299774528 Hz D0228 11:37:10.785745 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697226830793123 monotonicBaseRef:12000258090 monotonicFrequency:2299775145 realtimeReady:1 realtimeBaseCycles:8697226831283943 realtimeBaseRef:1582889830785619542 realtimeFrequency:2299774528} D0228 11:37:11.785449 64421 parameters.go:238] Clock(Monotonic): error: 268 ns, adjusted frequency from 2299775145 Hz to 2299775247 Hz D0228 11:37:11.785652 64421 parameters.go:238] Clock(Realtime): error: -12 ns, adjusted frequency from 2299774528 Hz to 2299774542 Hz D0228 11:37:11.785733 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697229130627171 monotonicBaseRef:13000283702 monotonicFrequency:2299775247 realtimeReady:1 realtimeBaseCycles:8697229131120834 realtimeBaseRef:1582889831785646659 realtimeFrequency:2299774542} D0228 11:37:12.785427 64421 parameters.go:238] Clock(Monotonic): error: -588 ns, adjusted frequency from 2299775247 Hz to 2299773293 Hz D0228 11:37:12.785667 64421 parameters.go:238] Clock(Realtime): error: 72 ns, adjusted frequency from 2299774542 Hz to 2299774751 Hz D0228 11:37:12.785815 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697231430354531 monotonicBaseRef:14000262879 monotonicFrequency:2299773293 realtimeReady:1 realtimeBaseCycles:8697231430929205 realtimeBaseRef:1582889832785661368 realtimeFrequency:2299774751} D0228 11:37:13.785478 64421 parameters.go:238] Clock(Monotonic): error: 516 ns, adjusted frequency from 2299773293 Hz to 2299775808 Hz D0228 11:37:13.785749 64421 parameters.go:238] Clock(Realtime): error: 349 ns, adjusted frequency from 2299774751 Hz to 2299775414 Hz D0228 11:37:13.787346 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697233730237527 monotonicBaseRef:15000310580 monotonicFrequency:2299775808 realtimeReady:1 realtimeBaseCycles:8697233730890974 realtimeBaseRef:1582889833785742688 realtimeFrequency:2299775414} D0228 11:37:14.785516 64421 parameters.go:238] Clock(Monotonic): error: -476 ns, adjusted frequency from 2299775808 Hz to 2299773647 Hz D0228 11:37:14.785708 64421 parameters.go:238] Clock(Realtime): error: -371 ns, adjusted frequency from 2299775414 Hz to 2299773703 Hz D0228 11:37:14.785810 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697236030066967 monotonicBaseRef:16000333900 monotonicFrequency:2299773647 realtimeReady:1 realtimeBaseCycles:8697236030571961 realtimeBaseRef:1582889834785701628 realtimeFrequency:2299773703} D0228 11:37:15.785475 64421 parameters.go:238] Clock(Monotonic): error: 238 ns, adjusted frequency from 2299773647 Hz to 2299775180 Hz D0228 11:37:15.785661 64421 parameters.go:238] Clock(Realtime): error: -7 ns, adjusted frequency from 2299773703 Hz to 2299774592 Hz D0228 11:37:15.785775 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697238329787372 monotonicBaseRef:17000310749 monotonicFrequency:2299775180 realtimeReady:1 realtimeBaseCycles:8697238330242076 realtimeBaseRef:1582889835785656585 realtimeFrequency:2299774592} D0228 11:37:16.785496 64421 parameters.go:238] Clock(Monotonic): error: 103 ns, adjusted frequency from 2299775180 Hz to 2299774888 Hz D0228 11:37:16.785690 64421 parameters.go:238] Clock(Realtime): error: 373 ns, adjusted frequency from 2299774592 Hz to 2299775476 Hz D0228 11:37:16.785800 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697240629602412 monotonicBaseRef:18000328081 monotonicFrequency:2299774888 realtimeReady:1 realtimeBaseCycles:8697240630078348 realtimeBaseRef:1582889836785683405 realtimeFrequency:2299775476} D0228 11:37:17.785500 64421 parameters.go:238] Clock(Monotonic): error: -396 ns, adjusted frequency from 2299774888 Hz to 2299773740 Hz D0228 11:37:17.785740 64421 parameters.go:238] Clock(Realtime): error: -554 ns, adjusted frequency from 2299775476 Hz to 2299773415 Hz D0228 11:37:17.785848 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697242929348970 monotonicBaseRef:19000315762 monotonicFrequency:2299773740 realtimeReady:1 realtimeBaseCycles:8697242929962845 realtimeBaseRef:1582889837785730810 realtimeFrequency:2299773415} D0228 11:37:18.785556 64421 parameters.go:238] Clock(Monotonic): error: 165 ns, adjusted frequency from 2299773740 Hz to 2299775024 Hz D0228 11:37:18.785806 64421 parameters.go:238] Clock(Realtime): error: 402 ns, adjusted frequency from 2299773415 Hz to 2299775572 Hz D0228 11:37:18.785946 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697245229241789 monotonicBaseRef:20000367540 monotonicFrequency:2299775024 realtimeReady:1 realtimeBaseCycles:8697245229887111 realtimeBaseRef:1582889838785796403 realtimeFrequency:2299775572} D0228 11:37:19.785511 64421 parameters.go:238] Clock(Monotonic): error: 49 ns, adjusted frequency from 2299775024 Hz to 2299774894 Hz D0228 11:37:19.785929 64421 parameters.go:238] Clock(Realtime): error: -127 ns, adjusted frequency from 2299775572 Hz to 2299774371 Hz D0228 11:37:19.786035 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697247528968089 monotonicBaseRef:21000346353 monotonicFrequency:2299774894 realtimeReady:1 realtimeBaseCycles:8697247529943901 realtimeBaseRef:1582889839785918683 realtimeFrequency:2299774371} D0228 11:37:20.785449 64421 parameters.go:238] Clock(Monotonic): error: 31 ns, adjusted frequency from 2299774894 Hz to 2299774700 Hz D0228 11:37:20.785667 64421 parameters.go:238] Clock(Realtime): error: -6 ns, adjusted frequency from 2299774371 Hz to 2299774663 Hz D0228 11:37:20.785808 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697249828597252 monotonicBaseRef:22000282985 monotonicFrequency:2299774700 realtimeReady:1 realtimeBaseCycles:8697249829128592 realtimeBaseRef:1582889840785662275 realtimeFrequency:2299774663} D0228 11:37:21.785470 64421 parameters.go:238] Clock(Monotonic): error: -290 ns, adjusted frequency from 2299774700 Hz to 2299773983 Hz D0228 11:37:21.785691 64421 parameters.go:238] Clock(Realtime): error: -41 ns, adjusted frequency from 2299774663 Hz to 2299774578 Hz D0228 11:37:21.785818 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697252128409052 monotonicBaseRef:23000299117 monotonicFrequency:2299773983 realtimeReady:1 realtimeBaseCycles:8697252128957229 realtimeBaseRef:1582889841785685744 realtimeFrequency:2299774578} D0228 11:37:22.785450 64421 parameters.go:238] Clock(Monotonic): error: 155 ns, adjusted frequency from 2299773983 Hz to 2299775116 Hz D0228 11:37:22.785753 64421 parameters.go:238] Clock(Realtime): error: 16 ns, adjusted frequency from 2299774578 Hz to 2299774698 Hz D0228 11:37:22.785911 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697254428148198 monotonicBaseRef:24000283968 monotonicFrequency:2299775116 realtimeReady:1 realtimeBaseCycles:8697254428869904 realtimeBaseRef:1582889842785745792 realtimeFrequency:2299774698} D0228 11:37:23.785445 64421 parameters.go:238] Clock(Monotonic): error: -188 ns, adjusted frequency from 2299775116 Hz to 2299774226 Hz D0228 11:37:23.785659 64421 parameters.go:238] Clock(Realtime): error: 45 ns, adjusted frequency from 2299774698 Hz to 2299774791 Hz D0228 11:37:23.785749 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697256727888312 monotonicBaseRef:25000268748 monotonicFrequency:2299774226 realtimeReady:1 realtimeBaseCycles:8697256728434674 realtimeBaseRef:1582889843785654510 realtimeFrequency:2299774791} D0228 11:37:24.785526 64421 parameters.go:238] Clock(Monotonic): error: 381 ns, adjusted frequency from 2299774226 Hz to 2299775675 Hz D0228 11:37:24.785839 64421 parameters.go:238] Clock(Realtime): error: 101 ns, adjusted frequency from 2299774791 Hz to 2299774959 Hz D0228 11:37:24.785973 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697259027816578 monotonicBaseRef:26000335728 monotonicFrequency:2299775675 realtimeReady:1 realtimeBaseCycles:8697259028606435 realtimeBaseRef:1582889844785827122 realtimeFrequency:2299774959} D0228 11:37:25.785428 64421 parameters.go:238] Clock(Monotonic): error: -321 ns, adjusted frequency from 2299775675 Hz to 2299773975 Hz D0228 11:37:25.785671 64421 parameters.go:238] Clock(Realtime): error: -240 ns, adjusted frequency from 2299774959 Hz to 2299774081 Hz D0228 11:37:25.785792 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697261327421941 monotonicBaseRef:27000261672 monotonicFrequency:2299773975 realtimeReady:1 realtimeBaseCycles:8697261328010858 realtimeBaseRef:1582889845785666003 realtimeFrequency:2299774081} D0228 11:37:26.785466 64421 parameters.go:238] Clock(Monotonic): error: 90 ns, adjusted frequency from 2299773975 Hz to 2299774809 Hz D0228 11:37:26.785665 64421 parameters.go:238] Clock(Realtime): error: 6 ns, adjusted frequency from 2299774081 Hz to 2299774623 Hz D0228 11:37:26.785763 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697263627293250 monotonicBaseRef:28000303995 monotonicFrequency:2299774809 realtimeReady:1 realtimeBaseCycles:8697263627771516 realtimeBaseRef:1582889846785660166 realtimeFrequency:2299774623} D0228 11:37:27.785431 64421 parameters.go:238] Clock(Monotonic): error: 106 ns, adjusted frequency from 2299774809 Hz to 2299774910 Hz D0228 11:37:27.785669 64421 parameters.go:238] Clock(Realtime): error: 251 ns, adjusted frequency from 2299774623 Hz to 2299775220 Hz D0228 11:37:27.785852 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697265926976916 monotonicBaseRef:29000264363 monotonicFrequency:2299774910 realtimeReady:1 realtimeBaseCycles:8697265927552511 realtimeBaseRef:1582889847785662936 realtimeFrequency:2299775220} D0228 11:37:28.785494 64421 parameters.go:238] Clock(Monotonic): error: -312 ns, adjusted frequency from 2299774910 Hz to 2299773921 Hz D0228 11:37:28.785723 64421 parameters.go:238] Clock(Realtime): error: -197 ns, adjusted frequency from 2299775220 Hz to 2299774210 Hz D0228 11:37:28.785833 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697268226898521 monotonicBaseRef:30000328149 monotonicFrequency:2299773921 realtimeReady:1 realtimeBaseCycles:8697268227453650 realtimeBaseRef:1582889848785717688 realtimeFrequency:2299774210} D0228 11:37:29.785423 64421 parameters.go:238] Clock(Monotonic): error: 646 ns, adjusted frequency from 2299773921 Hz to 2299776171 Hz D0228 11:37:29.785690 64421 parameters.go:238] Clock(Realtime): error: 90 ns, adjusted frequency from 2299774210 Hz to 2299774780 Hz D0228 11:37:29.785829 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697270526510483 monotonicBaseRef:31000257725 monotonicFrequency:2299776171 realtimeReady:1 realtimeBaseCycles:8697270527148300 realtimeBaseRef:1582889849785683093 realtimeFrequency:2299774780} D0228 11:37:30.785499 64421 parameters.go:238] Clock(Monotonic): error: -644 ns, adjusted frequency from 2299776171 Hz to 2299773173 Hz D0228 11:37:30.785777 64421 parameters.go:238] Clock(Realtime): error: 169 ns, adjusted frequency from 2299774780 Hz to 2299775034 Hz D0228 11:37:30.785932 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697272826455116 monotonicBaseRef:32000330976 monotonicFrequency:2299773173 realtimeReady:1 realtimeBaseCycles:8697272827120687 realtimeBaseRef:1582889850785769017 realtimeFrequency:2299775034} D0228 11:37:31.785566 64421 parameters.go:238] Clock(Monotonic): error: -91 ns, adjusted frequency from 2299773173 Hz to 2299774409 Hz D0228 11:37:31.785774 64421 parameters.go:238] Clock(Realtime): error: -484 ns, adjusted frequency from 2299775034 Hz to 2299773561 Hz D0228 11:37:31.785875 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697275126397674 monotonicBaseRef:33000404628 monotonicFrequency:2299774409 realtimeReady:1 realtimeBaseCycles:8697275126886705 realtimeBaseRef:1582889851785765096 realtimeFrequency:2299773561} D0228 11:37:32.555708 64421 urpc.go:577] urpc: unmarshal success. D0228 11:37:32.555955 64421 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0228 11:37:32.556237 64421 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 11:37:32.785371 64421 parameters.go:238] Clock(Monotonic): error: 39 ns, adjusted frequency from 2299774409 Hz to 2299774731 Hz D0228 11:37:32.785550 64421 parameters.go:238] Clock(Realtime): error: 180 ns, adjusted frequency from 2299773561 Hz to 2299775090 Hz D0228 11:37:32.785709 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697277425724006 monotonicBaseRef:34000209792 monotonicFrequency:2299774731 realtimeReady:1 realtimeBaseCycles:8697277426146891 realtimeBaseRef:1582889852785541867 realtimeFrequency:2299775090} D0228 11:37:33.785461 64421 parameters.go:238] Clock(Monotonic): error: 312 ns, adjusted frequency from 2299774731 Hz to 2299775250 Hz D0228 11:37:33.785670 64421 parameters.go:238] Clock(Realtime): error: -9 ns, adjusted frequency from 2299775090 Hz to 2299774548 Hz D0228 11:37:33.785804 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697279725692598 monotonicBaseRef:35000294087 monotonicFrequency:2299775250 realtimeReady:1 realtimeBaseCycles:8697279726197067 realtimeBaseRef:1582889853785661481 realtimeFrequency:2299774548} D0228 11:37:34.785438 64421 parameters.go:238] Clock(Monotonic): error: -235 ns, adjusted frequency from 2299775250 Hz to 2299774108 Hz D0228 11:37:34.785600 64421 parameters.go:238] Clock(Realtime): error: 57 ns, adjusted frequency from 2299774548 Hz to 2299774752 Hz D0228 11:37:34.785703 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697282025374817 monotonicBaseRef:36000253634 monotonicFrequency:2299774108 realtimeReady:1 realtimeBaseCycles:8697282025814780 realtimeBaseRef:1582889854785593285 realtimeFrequency:2299774752} D0228 11:37:35.785442 64421 parameters.go:238] Clock(Monotonic): error: 362 ns, adjusted frequency from 2299774108 Hz to 2299775471 Hz D0228 11:37:35.785611 64421 parameters.go:238] Clock(Realtime): error: 14 ns, adjusted frequency from 2299774752 Hz to 2299774641 Hz D0228 11:37:35.785735 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697284325206543 monotonicBaseRef:37000278687 monotonicFrequency:2299775471 realtimeReady:1 realtimeBaseCycles:8697284325618773 realtimeBaseRef:1582889855785605999 realtimeFrequency:2299774641} D0228 11:37:36.785374 64421 parameters.go:238] Clock(Monotonic): error: 12 ns, adjusted frequency from 2299775471 Hz to 2299774595 Hz D0228 11:37:36.785529 64421 parameters.go:238] Clock(Realtime): error: 228 ns, adjusted frequency from 2299774641 Hz to 2299775198 Hz D0228 11:37:36.785674 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697286624830539 monotonicBaseRef:38000212821 monotonicFrequency:2299774595 realtimeReady:1 realtimeBaseCycles:8697286625202976 realtimeBaseRef:1582889856785523191 realtimeFrequency:2299775198} D0228 11:37:37.785400 64421 parameters.go:238] Clock(Monotonic): error: 18 ns, adjusted frequency from 2299774595 Hz to 2299774651 Hz D0228 11:37:37.785589 64421 parameters.go:238] Clock(Realtime): error: -81 ns, adjusted frequency from 2299775198 Hz to 2299774478 Hz D0228 11:37:37.785685 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697288924655680 monotonicBaseRef:39000234799 monotonicFrequency:2299774651 realtimeReady:1 realtimeBaseCycles:8697288925116950 realtimeBaseRef:1582889857785583534 realtimeFrequency:2299774478} D0228 11:37:38.785456 64421 parameters.go:238] Clock(Monotonic): error: 52 ns, adjusted frequency from 2299774651 Hz to 2299774718 Hz D0228 11:37:38.785668 64421 parameters.go:238] Clock(Realtime): error: -124 ns, adjusted frequency from 2299774478 Hz to 2299774499 Hz D0228 11:37:38.785850 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697291224560391 monotonicBaseRef:40000291352 monotonicFrequency:2299774718 realtimeReady:1 realtimeBaseCycles:8697291225065893 realtimeBaseRef:1582889858785659395 realtimeFrequency:2299774499} D0228 11:37:39.785488 64421 parameters.go:238] Clock(Monotonic): error: -220 ns, adjusted frequency from 2299774718 Hz to 2299774138 Hz D0228 11:37:39.785701 64421 parameters.go:238] Clock(Realtime): error: 236 ns, adjusted frequency from 2299774499 Hz to 2299775168 Hz D0228 11:37:39.785816 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697293524414461 monotonicBaseRef:41000325856 monotonicFrequency:2299774138 realtimeReady:1 realtimeBaseCycles:8697293524919276 realtimeBaseRef:1582889859785693695 realtimeFrequency:2299775168} D0228 11:37:40.785433 64421 parameters.go:238] Clock(Monotonic): error: 165 ns, adjusted frequency from 2299774138 Hz to 2299774988 Hz D0228 11:37:40.785647 64421 parameters.go:238] Clock(Realtime): error: -535 ns, adjusted frequency from 2299775168 Hz to 2299773413 Hz D0228 11:37:40.785743 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697295824065910 monotonicBaseRef:42000272507 monotonicFrequency:2299774988 realtimeReady:1 realtimeBaseCycles:8697295824558519 realtimeBaseRef:1582889860785634591 realtimeFrequency:2299773413} D0228 11:37:41.785484 64421 parameters.go:238] Clock(Monotonic): error: -320 ns, adjusted frequency from 2299774988 Hz to 2299773914 Hz D0228 11:37:41.785684 64421 parameters.go:238] Clock(Realtime): error: 300 ns, adjusted frequency from 2299773413 Hz to 2299775310 Hz D0228 11:37:41.785792 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697298123950130 monotonicBaseRef:43000320003 monotonicFrequency:2299773914 realtimeReady:1 realtimeBaseCycles:8697298124432935 realtimeBaseRef:1582889861785678509 realtimeFrequency:2299775310} D0228 11:37:42.785455 64421 parameters.go:238] Clock(Monotonic): error: 404 ns, adjusted frequency from 2299773914 Hz to 2299775543 Hz D0228 11:37:42.785604 64421 parameters.go:238] Clock(Realtime): error: -61 ns, adjusted frequency from 2299775310 Hz to 2299774543 Hz D0228 11:37:42.785692 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697300423661609 monotonicBaseRef:44000292854 monotonicFrequency:2299775543 realtimeReady:1 realtimeBaseCycles:8697300424027110 realtimeBaseRef:1582889862785599746 realtimeFrequency:2299774543} D0228 11:37:43.785599 64421 parameters.go:238] Clock(Monotonic): error: -77 ns, adjusted frequency from 2299775543 Hz to 2299774416 Hz D0228 11:37:43.785778 64421 parameters.go:238] Clock(Realtime): error: 58 ns, adjusted frequency from 2299774543 Hz to 2299774831 Hz D0228 11:37:43.785907 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697302723768146 monotonicBaseRef:45000436778 monotonicFrequency:2299774416 realtimeReady:1 realtimeBaseCycles:8697302724201541 realtimeBaseRef:1582889863785773627 realtimeFrequency:2299774831} I0228 11:37:43.919834 64421 watchdog.go:277] Watchdog starting loop, tasks: 16, discount: 0s D0228 11:37:44.785545 64421 parameters.go:238] Clock(Monotonic): error: -302 ns, adjusted frequency from 2299774416 Hz to 2299773996 Hz D0228 11:37:44.785739 64421 parameters.go:238] Clock(Realtime): error: 143 ns, adjusted frequency from 2299774831 Hz to 2299775000 Hz D0228 11:37:44.785876 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697305023349866 monotonicBaseRef:46000352988 monotonicFrequency:2299773996 realtimeReady:1 realtimeBaseCycles:8697305023879308 realtimeBaseRef:1582889864785731421 realtimeFrequency:2299775000} D0228 11:37:45.785456 64421 parameters.go:238] Clock(Monotonic): error: -5 ns, adjusted frequency from 2299773996 Hz to 2299774688 Hz D0228 11:37:45.785601 64421 parameters.go:238] Clock(Realtime): error: -240 ns, adjusted frequency from 2299775000 Hz to 2299774053 Hz D0228 11:37:45.785727 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697307322991600 monotonicBaseRef:47000295477 monotonicFrequency:2299774688 realtimeReady:1 realtimeBaseCycles:8697307323341874 realtimeBaseRef:1582889865785595566 realtimeFrequency:2299774053} D0228 11:37:46.785400 64421 parameters.go:238] Clock(Monotonic): error: 581 ns, adjusted frequency from 2299774688 Hz to 2299775997 Hz D0228 11:37:46.785580 64421 parameters.go:238] Clock(Realtime): error: 10 ns, adjusted frequency from 2299774053 Hz to 2299774640 Hz D0228 11:37:46.785679 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697309622624282 monotonicBaseRef:48000233729 monotonicFrequency:2299775997 realtimeReady:1 realtimeBaseCycles:8697309623060333 realtimeBaseRef:1582889866785571392 realtimeFrequency:2299774640} D0228 11:37:47.785390 64421 parameters.go:238] Clock(Monotonic): error: -582 ns, adjusted frequency from 2299775997 Hz to 2299773393 Hz D0228 11:37:47.785578 64421 parameters.go:238] Clock(Realtime): error: 94 ns, adjusted frequency from 2299774640 Hz to 2299774817 Hz D0228 11:37:47.785678 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697311922390317 monotonicBaseRef:49000229397 monotonicFrequency:2299773393 realtimeReady:1 realtimeBaseCycles:8697311922838886 realtimeBaseRef:1582889867785573093 realtimeFrequency:2299774817} D0228 11:37:48.785424 64421 parameters.go:238] Clock(Monotonic): error: 242 ns, adjusted frequency from 2299773393 Hz to 2299775109 Hz D0228 11:37:48.785618 64421 parameters.go:238] Clock(Realtime): error: -36 ns, adjusted frequency from 2299774817 Hz to 2299774572 Hz D0228 11:37:48.785714 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697314222241089 monotonicBaseRef:50000263043 monotonicFrequency:2299775109 realtimeReady:1 realtimeBaseCycles:8697314222706177 realtimeBaseRef:1582889868785613303 realtimeFrequency:2299774572} D0228 11:37:49.785434 64421 parameters.go:238] Clock(Monotonic): error: 32 ns, adjusted frequency from 2299775109 Hz to 2299774803 Hz D0228 11:37:49.785631 64421 parameters.go:238] Clock(Realtime): error: 110 ns, adjusted frequency from 2299774572 Hz to 2299774854 Hz D0228 11:37:49.785786 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697316522031396 monotonicBaseRef:51000269651 monotonicFrequency:2299774803 realtimeReady:1 realtimeBaseCycles:8697316522506745 realtimeBaseRef:1582889869785624606 realtimeFrequency:2299774854} D0228 11:37:50.785461 64421 parameters.go:238] Clock(Monotonic): error: -327 ns, adjusted frequency from 2299774803 Hz to 2299773889 Hz D0228 11:37:50.785648 64421 parameters.go:238] Clock(Realtime): error: -143 ns, adjusted frequency from 2299774854 Hz to 2299774331 Hz D0228 11:37:50.785756 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697318821867263 monotonicBaseRef:52000296203 monotonicFrequency:2299773889 realtimeReady:1 realtimeBaseCycles:8697318822324711 realtimeBaseRef:1582889870785643352 realtimeFrequency:2299774331} D0228 11:37:51.785417 64421 parameters.go:238] Clock(Monotonic): error: -5 ns, adjusted frequency from 2299773889 Hz to 2299774744 Hz D0228 11:37:51.785592 64421 parameters.go:238] Clock(Realtime): error: -187 ns, adjusted frequency from 2299774331 Hz to 2299774220 Hz D0228 11:37:51.785705 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697321121544848 monotonicBaseRef:53000254327 monotonicFrequency:2299774744 realtimeReady:1 realtimeBaseCycles:8697321121952884 realtimeBaseRef:1582889871785579798 realtimeFrequency:2299774220} D0228 11:37:52.786012 64421 parameters.go:238] Clock(Monotonic): error: 301 ns, adjusted frequency from 2299774744 Hz to 2299775430 Hz D0228 11:37:52.786208 64421 parameters.go:238] Clock(Realtime): error: 322 ns, adjusted frequency from 2299774220 Hz to 2299775338 Hz D0228 11:37:52.786343 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697323422678010 monotonicBaseRef:54000845001 monotonicFrequency:2299775430 realtimeReady:1 realtimeBaseCycles:8697323423149631 realtimeBaseRef:1582889872786198348 realtimeFrequency:2299775338} D0228 11:37:53.785445 64421 parameters.go:238] Clock(Monotonic): error: -214 ns, adjusted frequency from 2299775430 Hz to 2299774173 Hz D0228 11:37:53.785644 64421 parameters.go:238] Clock(Realtime): error: 167 ns, adjusted frequency from 2299775338 Hz to 2299775048 Hz D0228 11:37:53.785797 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697325721134838 monotonicBaseRef:55000271639 monotonicFrequency:2299774173 realtimeReady:1 realtimeBaseCycles:8697325721636071 realtimeBaseRef:1582889873785637902 realtimeFrequency:2299775048} D0228 11:37:54.785475 64421 parameters.go:238] Clock(Monotonic): error: -126 ns, adjusted frequency from 2299774173 Hz to 2299774351 Hz D0228 11:37:54.785663 64421 parameters.go:238] Clock(Realtime): error: -300 ns, adjusted frequency from 2299775048 Hz to 2299773977 Hz D0228 11:37:54.785778 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697328020995837 monotonicBaseRef:56000309393 monotonicFrequency:2299774351 realtimeReady:1 realtimeBaseCycles:8697328021454615 realtimeBaseRef:1582889874785656815 realtimeFrequency:2299773977} D0228 11:37:55.785445 64421 parameters.go:238] Clock(Monotonic): error: -56 ns, adjusted frequency from 2299774351 Hz to 2299774540 Hz D0228 11:37:55.785606 64421 parameters.go:238] Clock(Realtime): error: 12 ns, adjusted frequency from 2299773977 Hz to 2299774680 Hz D0228 11:37:55.785734 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697330320710290 monotonicBaseRef:57000283347 monotonicFrequency:2299774540 realtimeReady:1 realtimeBaseCycles:8697330321100748 realtimeBaseRef:1582889875785601225 realtimeFrequency:2299774680} D0228 11:37:56.785521 64421 parameters.go:238] Clock(Monotonic): error: -14 ns, adjusted frequency from 2299774540 Hz to 2299774622 Hz D0228 11:37:56.785698 64421 parameters.go:238] Clock(Realtime): error: -12 ns, adjusted frequency from 2299774680 Hz to 2299774597 Hz D0228 11:37:56.785816 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697332620652343 monotonicBaseRef:58000356185 monotonicFrequency:2299774622 realtimeReady:1 realtimeBaseCycles:8697332621084719 realtimeBaseRef:1582889876785692230 realtimeFrequency:2299774597} D0228 11:37:57.785457 64421 sampler.go:197] Time: Adjusting syscall overhead down to 7000 D0228 11:37:57.785604 64421 parameters.go:238] Clock(Monotonic): error: 1 ns, adjusted frequency from 2299774622 Hz to 2299774741 Hz D0228 11:37:57.785716 64421 parameters.go:238] Clock(Realtime): error: -25 ns, adjusted frequency from 2299774597 Hz to 2299774611 Hz D0228 11:37:57.785811 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697334920293520 monotonicBaseRef:59000298159 monotonicFrequency:2299774741 realtimeReady:1 realtimeBaseCycles:8697334920905599 realtimeBaseRef:1582889877785712355 realtimeFrequency:2299774611} D0228 11:37:58.785501 64421 parameters.go:238] Clock(Monotonic): error: -31 ns, adjusted frequency from 2299774741 Hz to 2299774539 Hz D0228 11:37:58.785742 64421 parameters.go:238] Clock(Realtime): error: 93 ns, adjusted frequency from 2299774611 Hz to 2299774822 Hz D0228 11:37:58.785860 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697337220157532 monotonicBaseRef:60000336976 monotonicFrequency:2299774539 realtimeReady:1 realtimeBaseCycles:8697337220736560 realtimeBaseRef:1582889878785736857 realtimeFrequency:2299774822} D0228 11:37:59.785398 64421 parameters.go:238] Clock(Monotonic): error: 5 ns, adjusted frequency from 2299774539 Hz to 2299774663 Hz D0228 11:37:59.785581 64421 parameters.go:238] Clock(Realtime): error: -16 ns, adjusted frequency from 2299774822 Hz to 2299774598 Hz D0228 11:37:59.785696 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697339519705325 monotonicBaseRef:61000238381 monotonicFrequency:2299774663 realtimeReady:1 realtimeBaseCycles:8697339520141830 realtimeBaseRef:1582889879785576166 realtimeFrequency:2299774598} D0228 11:38:00.785457 64421 parameters.go:238] Clock(Monotonic): error: -3 ns, adjusted frequency from 2299774663 Hz to 2299774644 Hz D0228 11:38:00.785650 64421 parameters.go:238] Clock(Realtime): error: 13 ns, adjusted frequency from 2299774598 Hz to 2299774659 Hz D0228 11:38:00.785745 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697341819609563 monotonicBaseRef:62000294723 monotonicFrequency:2299774644 realtimeReady:1 realtimeBaseCycles:8697341820076353 realtimeBaseRef:1582889880785645705 realtimeFrequency:2299774659} D0228 11:38:01.785481 64421 parameters.go:238] Clock(Monotonic): error: 147 ns, adjusted frequency from 2299774644 Hz to 2299774951 Hz D0228 11:38:01.785672 64421 parameters.go:238] Clock(Realtime): error: 36 ns, adjusted frequency from 2299774659 Hz to 2299774764 Hz D0228 11:38:01.785821 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697344119433308 monotonicBaseRef:63000316073 monotonicFrequency:2299774951 realtimeReady:1 realtimeBaseCycles:8697344119899190 realtimeBaseRef:1582889881785666654 realtimeFrequency:2299774764} D0228 11:38:02.785480 64421 parameters.go:238] Clock(Monotonic): error: -153 ns, adjusted frequency from 2299774951 Hz to 2299774279 Hz D0228 11:38:02.785719 64421 parameters.go:238] Clock(Realtime): error: 137 ns, adjusted frequency from 2299774764 Hz to 2299774964 Hz D0228 11:38:02.785833 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697346419118639 monotonicBaseRef:64000277103 monotonicFrequency:2299774279 realtimeReady:1 realtimeBaseCycles:8697346419781742 realtimeBaseRef:1582889882785713522 realtimeFrequency:2299774964} D0228 11:38:03.785455 64421 parameters.go:238] Clock(Monotonic): error: 54 ns, adjusted frequency from 2299774279 Hz to 2299774768 Hz D0228 11:38:03.785661 64421 parameters.go:238] Clock(Realtime): error: -171 ns, adjusted frequency from 2299774964 Hz to 2299774256 Hz D0228 11:38:03.785756 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697348718929607 monotonicBaseRef:65000293056 monotonicFrequency:2299774768 realtimeReady:1 realtimeBaseCycles:8697348719423334 realtimeBaseRef:1582889883785655528 realtimeFrequency:2299774256} D0228 11:38:04.785460 64421 parameters.go:238] Clock(Monotonic): error: 412 ns, adjusted frequency from 2299774768 Hz to 2299775516 Hz D0228 11:38:04.785660 64421 parameters.go:238] Clock(Realtime): error: 760 ns, adjusted frequency from 2299774256 Hz to 2299776475 Hz D0228 11:38:04.785808 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697351018633969 monotonicBaseRef:66000262441 monotonicFrequency:2299775516 realtimeReady:1 realtimeBaseCycles:8697351019193796 realtimeBaseRef:1582889884785653878 realtimeFrequency:2299776475} D0228 11:38:05.406482 64421 urpc.go:577] urpc: unmarshal success. D0228 11:38:05.406675 64421 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0228 11:38:05.406867 64421 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 11:38:05.785488 64421 parameters.go:238] Clock(Monotonic): error: -422 ns, adjusted frequency from 2299775516 Hz to 2299773671 Hz D0228 11:38:05.785735 64421 parameters.go:238] Clock(Realtime): error: -696 ns, adjusted frequency from 2299776475 Hz to 2299773023 Hz D0228 11:38:05.785835 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697353318545857 monotonicBaseRef:67000321738 monotonicFrequency:2299773671 realtimeReady:1 realtimeBaseCycles:8697353319144482 realtimeBaseRef:1582889885785729629 realtimeFrequency:2299773023} D0228 11:38:06.785564 64421 parameters.go:238] Clock(Monotonic): error: 344 ns, adjusted frequency from 2299773671 Hz to 2299775365 Hz D0228 11:38:06.785783 64421 parameters.go:238] Clock(Realtime): error: 189 ns, adjusted frequency from 2299773023 Hz to 2299775071 Hz D0228 11:38:06.785916 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697355618503495 monotonicBaseRef:68000401731 monotonicFrequency:2299775365 realtimeReady:1 realtimeBaseCycles:8697355619022449 realtimeBaseRef:1582889886785775261 realtimeFrequency:2299775071} D0228 11:38:07.785516 64421 parameters.go:238] Clock(Monotonic): error: -62 ns, adjusted frequency from 2299775365 Hz to 2299774529 Hz D0228 11:38:07.785901 64421 parameters.go:238] Clock(Realtime): error: -371 ns, adjusted frequency from 2299775071 Hz to 2299773844 Hz D0228 11:38:07.786144 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697357918150951 monotonicBaseRef:69000346112 monotonicFrequency:2299774529 realtimeReady:1 realtimeBaseCycles:8697357919057014 realtimeBaseRef:1582889887785888095 realtimeFrequency:2299773844} D0228 11:38:08.785551 64421 parameters.go:238] Clock(Monotonic): error: 118 ns, adjusted frequency from 2299774529 Hz to 2299774825 Hz D0228 11:38:08.785752 64421 parameters.go:238] Clock(Realtime): error: -5 ns, adjusted frequency from 2299773844 Hz to 2299774625 Hz D0228 11:38:08.785841 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697360218018395 monotonicBaseRef:70000386513 monotonicFrequency:2299774825 realtimeReady:1 realtimeBaseCycles:8697360218508405 realtimeBaseRef:1582889888785747884 realtimeFrequency:2299774625} D0228 11:38:09.785542 64421 parameters.go:238] Clock(Monotonic): error: -104 ns, adjusted frequency from 2299774825 Hz to 2299774422 Hz D0228 11:38:09.785807 64421 parameters.go:238] Clock(Realtime): error: 85 ns, adjusted frequency from 2299774625 Hz to 2299774807 Hz D0228 11:38:09.785905 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697362517763989 monotonicBaseRef:71000373802 monotonicFrequency:2299774422 realtimeReady:1 realtimeBaseCycles:8697362518394546 realtimeBaseRef:1582889889785796373 realtimeFrequency:2299774807} D0228 11:38:10.785538 64421 parameters.go:238] Clock(Monotonic): error: -232 ns, adjusted frequency from 2299774422 Hz to 2299774078 Hz D0228 11:38:10.785739 64421 parameters.go:238] Clock(Realtime): error: -68 ns, adjusted frequency from 2299774807 Hz to 2299774477 Hz D0228 11:38:10.785882 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697364817529258 monotonicBaseRef:72000369822 monotonicFrequency:2299774078 realtimeReady:1 realtimeBaseCycles:8697364818026145 realtimeBaseRef:1582889890785734102 realtimeFrequency:2299774477} D0228 11:38:11.785492 64421 parameters.go:238] Clock(Monotonic): error: 331 ns, adjusted frequency from 2299774078 Hz to 2299775299 Hz D0228 11:38:11.785717 64421 parameters.go:238] Clock(Realtime): error: -180 ns, adjusted frequency from 2299774477 Hz to 2299774270 Hz D0228 11:38:11.785839 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697367117212800 monotonicBaseRef:73000330454 monotonicFrequency:2299775299 realtimeReady:1 realtimeBaseCycles:8697367117749443 realtimeBaseRef:1582889891785711848 realtimeFrequency:2299774270} D0228 11:38:12.785558 64421 parameters.go:238] Clock(Monotonic): error: -256 ns, adjusted frequency from 2299775299 Hz to 2299774069 Hz D0228 11:38:12.785750 64421 parameters.go:238] Clock(Realtime): error: 196 ns, adjusted frequency from 2299774270 Hz to 2299775119 Hz D0228 11:38:12.785862 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697369417135051 monotonicBaseRef:74000394352 monotonicFrequency:2299774069 realtimeReady:1 realtimeBaseCycles:8697369417602062 realtimeBaseRef:1582889892785745916 realtimeFrequency:2299775119} D0228 11:38:13.785495 64421 parameters.go:238] Clock(Monotonic): error: 348 ns, adjusted frequency from 2299774069 Hz to 2299775467 Hz D0228 11:38:13.785688 64421 parameters.go:238] Clock(Realtime): error: -3 ns, adjusted frequency from 2299775119 Hz to 2299774555 Hz D0228 11:38:13.785821 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697371716762713 monotonicBaseRef:75000330690 monotonicFrequency:2299775467 realtimeReady:1 realtimeBaseCycles:8697371717232709 realtimeBaseRef:1582889893785683095 realtimeFrequency:2299774555} D0228 11:38:14.785456 64421 parameters.go:238] Clock(Monotonic): error: -328 ns, adjusted frequency from 2299775467 Hz to 2299773898 Hz D0228 11:38:14.785634 64421 parameters.go:238] Clock(Realtime): error: -9 ns, adjusted frequency from 2299774555 Hz to 2299774639 Hz D0228 11:38:14.785783 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697374016444733 monotonicBaseRef:76000290056 monotonicFrequency:2299773898 realtimeReady:1 realtimeBaseCycles:8697374016881326 realtimeBaseRef:1582889894785628333 realtimeFrequency:2299774639} D0228 11:38:15.785579 64421 parameters.go:238] Clock(Monotonic): error: 262 ns, adjusted frequency from 2299773898 Hz to 2299775235 Hz D0228 11:38:15.785808 64421 parameters.go:238] Clock(Realtime): error: 301 ns, adjusted frequency from 2299774639 Hz to 2299775337 Hz D0228 11:38:15.785958 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697376316500879 monotonicBaseRef:77000412784 monotonicFrequency:2299775235 realtimeReady:1 realtimeBaseCycles:8697376317053711 realtimeBaseRef:1582889895785801282 realtimeFrequency:2299775337} D0228 11:38:16.785438 64421 parameters.go:238] Clock(Monotonic): error: -305 ns, adjusted frequency from 2299775235 Hz to 2299773930 Hz D0228 11:38:16.785670 64421 parameters.go:238] Clock(Realtime): error: -200 ns, adjusted frequency from 2299775337 Hz to 2299774123 Hz D0228 11:38:16.785787 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697378615953961 monotonicBaseRef:78000272703 monotonicFrequency:2299773930 realtimeReady:1 realtimeBaseCycles:8697378616515391 realtimeBaseRef:1582889896785664896 realtimeFrequency:2299774123} D0228 11:38:17.785514 64421 parameters.go:238] Clock(Monotonic): error: 59 ns, adjusted frequency from 2299773930 Hz to 2299774846 Hz D0228 11:38:17.785731 64421 parameters.go:238] Clock(Realtime): error: 85 ns, adjusted frequency from 2299774123 Hz to 2299774857 Hz D0228 11:38:17.785854 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697380915897618 monotonicBaseRef:79000346504 monotonicFrequency:2299774846 realtimeReady:1 realtimeBaseCycles:8697380916427103 realtimeBaseRef:1582889897785724723 realtimeFrequency:2299774857} D0228 11:38:18.785425 64421 parameters.go:238] Clock(Monotonic): error: -80 ns, adjusted frequency from 2299774846 Hz to 2299774449 Hz D0228 11:38:18.785640 64421 parameters.go:238] Clock(Realtime): error: 89 ns, adjusted frequency from 2299774857 Hz to 2299774894 Hz D0228 11:38:18.785743 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697383215473167 monotonicBaseRef:80000259844 monotonicFrequency:2299774449 realtimeReady:1 realtimeBaseCycles:8697383215995025 realtimeBaseRef:1582889898785634742 realtimeFrequency:2299774894} D0228 11:38:19.785450 64421 parameters.go:238] Clock(Monotonic): error: 43 ns, adjusted frequency from 2299774449 Hz to 2299774779 Hz D0228 11:38:19.785639 64421 parameters.go:238] Clock(Realtime): error: -258 ns, adjusted frequency from 2299774894 Hz to 2299774071 Hz D0228 11:38:19.785759 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697385515314051 monotonicBaseRef:81000288731 monotonicFrequency:2299774779 realtimeReady:1 realtimeBaseCycles:8697385515767134 realtimeBaseRef:1582889899785633531 realtimeFrequency:2299774071} D0228 11:38:20.785401 64421 parameters.go:238] Clock(Monotonic): error: -36 ns, adjusted frequency from 2299774779 Hz to 2299774679 Hz D0228 11:38:20.785673 64421 parameters.go:238] Clock(Realtime): error: 14 ns, adjusted frequency from 2299774071 Hz to 2299774620 Hz D0228 11:38:20.785800 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697387814967327 monotonicBaseRef:82000235898 monotonicFrequency:2299774679 realtimeReady:1 realtimeBaseCycles:8697387815593545 realtimeBaseRef:1582889900785656289 realtimeFrequency:2299774620} D0228 11:38:21.785518 64421 parameters.go:238] Clock(Monotonic): error: 174 ns, adjusted frequency from 2299774679 Hz to 2299775064 Hz D0228 11:38:21.785831 64421 parameters.go:238] Clock(Realtime): error: 287 ns, adjusted frequency from 2299774620 Hz to 2299775293 Hz D0228 11:38:21.785998 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697390115000010 monotonicBaseRef:83000348084 monotonicFrequency:2299775064 realtimeReady:1 realtimeBaseCycles:8697390115741933 realtimeBaseRef:1582889901785818812 realtimeFrequency:2299775293} D0228 11:38:22.785523 64421 parameters.go:238] Clock(Monotonic): error: 264 ns, adjusted frequency from 2299775064 Hz to 2299775286 Hz D0228 11:38:22.785710 64421 parameters.go:238] Clock(Realtime): error: -200 ns, adjusted frequency from 2299775293 Hz to 2299774190 Hz D0228 11:38:22.785815 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697392414798469 monotonicBaseRef:84000358256 monotonicFrequency:2299775286 realtimeReady:1 realtimeBaseCycles:8697392415255013 realtimeBaseRef:1582889902785704795 realtimeFrequency:2299774190} D0228 11:38:23.785441 64421 parameters.go:238] Clock(Monotonic): error: -114 ns, adjusted frequency from 2299775286 Hz to 2299774327 Hz D0228 11:38:23.785620 64421 parameters.go:238] Clock(Realtime): error: -28 ns, adjusted frequency from 2299774190 Hz to 2299774615 Hz D0228 11:38:23.785766 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697394714375750 monotonicBaseRef:85000272158 monotonicFrequency:2299774327 realtimeReady:1 realtimeBaseCycles:8697394714822943 realtimeBaseRef:1582889903785615107 realtimeFrequency:2299774615} D0228 11:38:24.785567 64421 parameters.go:238] Clock(Monotonic): error: -323 ns, adjusted frequency from 2299774327 Hz to 2299773994 Hz D0228 11:38:24.785863 64421 parameters.go:238] Clock(Realtime): error: 83 ns, adjusted frequency from 2299774615 Hz to 2299774819 Hz D0228 11:38:24.786019 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697397014422442 monotonicBaseRef:86000390589 monotonicFrequency:2299773994 realtimeReady:1 realtimeBaseCycles:8697397015150537 realtimeBaseRef:1582889904785855556 realtimeFrequency:2299774819} D0228 11:38:25.785478 64421 parameters.go:238] Clock(Monotonic): error: -96 ns, adjusted frequency from 2299773994 Hz to 2299774428 Hz D0228 11:38:25.785668 64421 parameters.go:238] Clock(Realtime): error: -97 ns, adjusted frequency from 2299774819 Hz to 2299774435 Hz D0228 11:38:25.785824 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697399314024160 monotonicBaseRef:87000315679 monotonicFrequency:2299774428 realtimeReady:1 realtimeBaseCycles:8697399314482535 realtimeBaseRef:1582889905785663006 realtimeFrequency:2299774435} D0228 11:38:26.785453 64421 parameters.go:238] Clock(Monotonic): error: 16 ns, adjusted frequency from 2299774428 Hz to 2299774711 Hz D0228 11:38:26.785771 64421 parameters.go:238] Clock(Realtime): error: 104 ns, adjusted frequency from 2299774435 Hz to 2299774913 Hz D0228 11:38:26.785899 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697401613734924 monotonicBaseRef:88000287996 monotonicFrequency:2299774711 realtimeReady:1 realtimeBaseCycles:8697401614490987 realtimeBaseRef:1582889906785764762 realtimeFrequency:2299774913} D0228 11:38:27.785417 64421 parameters.go:238] Clock(Monotonic): error: -34 ns, adjusted frequency from 2299774711 Hz to 2299774570 Hz D0228 11:38:27.785619 64421 parameters.go:238] Clock(Realtime): error: -72 ns, adjusted frequency from 2299774913 Hz to 2299774431 Hz D0228 11:38:27.785725 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697403913436947 monotonicBaseRef:89000256389 monotonicFrequency:2299774570 realtimeReady:1 realtimeBaseCycles:8697403913920873 realtimeBaseRef:1582889907785614735 realtimeFrequency:2299774431} D0228 11:38:27.841049 64421 urpc.go:577] urpc: unmarshal success. D0228 11:38:27.841331 64421 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0228 11:38:27.841560 64421 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 11:38:28.785412 64421 parameters.go:238] Clock(Monotonic): error: -4 ns, adjusted frequency from 2299774570 Hz to 2299774632 Hz D0228 11:38:28.785616 64421 parameters.go:238] Clock(Realtime): error: -200 ns, adjusted frequency from 2299774431 Hz to 2299774213 Hz D0228 11:38:28.785734 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697406213184423 monotonicBaseRef:90000244607 monotonicFrequency:2299774632 realtimeReady:1 realtimeBaseCycles:8697406213683418 realtimeBaseRef:1582889908785609566 realtimeFrequency:2299774213} I0228 11:38:28.920785 64421 watchdog.go:277] Watchdog starting loop, tasks: 16, discount: 0s I0228 11:38:29.538141 11388 main.go:296] *************************** I0228 11:38:29.538268 11388 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot 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-ptrace-proxy-sandbox-race-1 /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller992999609] I0228 11:38:29.538687 11388 main.go:298] Version release-20200219.0-63-gc96bb4d2ebc6 I0228 11:38:29.538777 11388 main.go:299] PID: 11388 I0228 11:38:29.538857 11388 main.go:300] UID: 0, GID: 0 I0228 11:38:29.538959 11388 main.go:301] Configuration: I0228 11:38:29.539062 11388 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 11:38:29.539159 11388 main.go:303] Platform: ptrace I0228 11:38:29.539249 11388 main.go:304] FileAccess: shared, overlay: false I0228 11:38:29.539349 11388 main.go:305] Network: sandbox, logging: false I0228 11:38:29.539439 11388 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 11:38:29.539525 11388 main.go:307] *************************** W0228 11:38:29.539613 11388 main.go:312] Block the TERM signal. This is only safe in tests! D0228 11:38:29.540028 11388 container.go:159] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.545790 11388 container.go:592] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-1": signal 0 D0228 11:38:29.545928 11388 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.546019 11388 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.546488 11388 urpc.go:534] urpc: successfully marshalled 117 bytes. D0228 11:38:29.546959 64421 urpc.go:577] urpc: unmarshal success. D0228 11:38:29.547234 64421 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0228 11:38:29.547503 64421 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 11:38:29.547684 11388 urpc.go:577] urpc: unmarshal success. D0228 11:38:29.547833 11388 exec.go:120] Exec arguments: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller992999609 D0228 11:38:29.547981 11388 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0228 11:38:29.548109 11388 container.go:533] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-1", args: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller992999609 D0228 11:38:29.548251 11388 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-1" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.548357 11388 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.549016 11388 urpc.go:534] urpc: successfully marshalled 634 bytes. D0228 11:38:29.549321 64421 urpc.go:577] urpc: unmarshal success. D0228 11:38:29.550643 64421 controller.go:267] containerManager.ExecuteAsync: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller992999609 D0228 11:38:29.550962 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0228 11:38:29.551927 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:29.552110 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 11:38:29.552531 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} I0228 11:38:29.553104 64421 kernel.go:795] EXEC: [/syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller992999609] D0228 11:38:29.553835 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0228 11:38:29.554993 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] 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: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582836029, NanoSec: 349298839}, MTime: {Sec: 1582836029, NanoSec: 349298839}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350291}]} D0228 11:38:29.555184 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0228 11:38:29.555562 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:29.555799 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetattr{FID: 5, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 11:38:29.556558 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350291}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582836029, NanoSec: 349298839}, MTime: {Sec: 1582836029, NanoSec: 349298839}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 11:38:29.556985 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalk{FID: 5, NewFID: 6, Names: []} D0228 11:38:29.557499 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rwalk{QIDs: []} D0228 11:38:29.557612 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tlopen{FID: 6, Flags: ReadOnly} D0228 11:38:29.558548 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350291}, IoUnit: 0, File: &{{33}}} D0228 11:38:29.561890 64421 syscalls.go:266] Allocating stack with size of 8388608 bytes D0228 11:38:29.563411 64421 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-1 0}:0xc00035c860 {ci-gvisor-ptrace-proxy-sandbox-race-1 22}:0xc000192740] D0228 11:38:29.563718 64421 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 11:38:29.563844 11388 urpc.go:577] urpc: unmarshal success. D0228 11:38:29.563991 11388 container.go:580] Wait on PID 22 in container "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.564100 11388 sandbox.go:743] Waiting for PID 22 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.564239 11388 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:29.564499 11388 urpc.go:534] urpc: successfully marshalled 100 bytes. D0228 11:38:29.564831 64421 urpc.go:577] urpc: unmarshal success. D0228 11:38:29.565095 64421 controller.go:443] containerManager.Wait D0228 11:38:29.565872 64421 task_block.go:223] [ 22] Interrupt queued D0228 11:38:29.766818 64421 task_block.go:223] [ 23] Interrupt queued D0228 11:38:29.768905 64421 task_block.go:223] [ 24] Interrupt queued D0228 11:38:29.770272 64421 task_block.go:223] [ 25] Interrupt queued D0228 11:38:29.778024 64421 task_block.go:223] [ 26] Interrupt queued D0228 11:38:29.785419 64421 parameters.go:238] Clock(Monotonic): error: 286 ns, adjusted frequency from 2299774632 Hz to 2299775269 Hz D0228 11:38:29.785718 64421 parameters.go:238] Clock(Realtime): error: 306 ns, adjusted frequency from 2299774213 Hz to 2299775446 Hz D0228 11:38:29.785861 64421 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8697408512977461 monotonicBaseRef:91000252610 monotonicFrequency:2299775269 realtimeReady:1 realtimeBaseCycles:8697408513691008 realtimeBaseRef:1582889909785711044 realtimeFrequency:2299775446} D0228 11:38:29.793581 64421 task_block.go:223] [ 27] Interrupt queued D0228 11:38:29.801335 64421 task_block.go:223] [ 28] Interrupt queued D0228 11:38:29.846648 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0228 11:38:29.847235 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:29.847380 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 11:38:29.847803 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:29.866488 64421 task_block.go:223] [ 29] Interrupt queued D0228 11:38:29.868388 64421 task_block.go:223] [ 30] Interrupt queued D0228 11:38:29.889394 64421 task_block.go:223] [ 31] Interrupt queued D0228 11:38:29.889880 64421 task_block.go:223] [ 32] Interrupt queued D0228 11:38:29.894645 64421 task_block.go:223] [ 33] Interrupt queued D0228 11:38:29.921594 64421 task_block.go:223] [ 34] Interrupt queued D0228 11:38:29.926371 64421 task_block.go:223] [ 35] Interrupt queued D0228 11:38:29.955121 64421 task_block.go:223] [ 36] Interrupt queued D0228 11:38:29.960099 64421 task_block.go:223] [ 37] Interrupt queued D0228 11:38:29.960319 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller992999609]} D0228 11:38:29.961398 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 613, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582889909, NanoSec: 509237265}, MTime: {Sec: 1582889909, NanoSec: 509237265}, CTime: {Sec: 1582889909, NanoSec: 509237265}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350089}]} D0228 11:38:29.961604 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller992999609, Size: 1} D0228 11:38:29.961981 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:29.962276 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetattr{FID: 7, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 11:38:29.962927 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350089}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 613, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582889909, NanoSec: 509237265}, MTime: {Sec: 1582889909, NanoSec: 509237265}, CTime: {Sec: 1582889909, NanoSec: 509237265}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 11:38:29.963051 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalk{FID: 7, NewFID: 8, Names: []} D0228 11:38:29.963511 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rwalk{QIDs: []} D0228 11:38:29.963619 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tlopen{FID: 8, Flags: ReadOnly} D0228 11:38:29.964278 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350089}, IoUnit: 0, File: &{{27}}} D0228 11:38:29.964946 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetattr{FID: 8, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 11:38:29.965569 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350089}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 613, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582889909, NanoSec: 509237265}, MTime: {Sec: 1582889909, NanoSec: 509237265}, CTime: {Sec: 1582889909, NanoSec: 509237265}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 11:38:29 parsed 1 programs D0228 11:38:29.974480 64421 task_stop.go:118] [ 36] Entering internal stop (*kernel.vforkStop)(nil) D0228 11:38:29.975249 64421 task_block.go:223] [ 38] Interrupt queued D0228 11:38:29.979700 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0228 11:38:29.981017 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] 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: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350296}]} D0228 11:38:29.981276 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0228 11:38:29.981694 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:29.981933 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 11:38:29.982803 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350296}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 11:38:29.982951 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalk{FID: 9, NewFID: 10, Names: []} D0228 11:38:29.983654 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rwalk{QIDs: []} D0228 11:38:29.983803 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tlopen{FID: 10, Flags: ReadOnly} D0228 11:38:29.984468 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350296}, IoUnit: 0, File: &{{28}}} D0228 11:38:29.986273 64421 syscalls.go:266] [ 38] Allocating stack with size of 8388608 bytes D0228 11:38:29.987339 64421 task_stop.go:137] [ 36] Leaving internal stop (*kernel.vforkStop)(nil) D0228 11:38:30.010550 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 11:38:30.011206 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.011378 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 11:38:30.011871 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.013691 64421 task_exit.go:221] [ 38] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.015045 64421 task_exit.go:221] [ 38] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.015224 64421 task_signals.go:446] [ 22] Notified of signal 17 D0228 11:38:30.015423 64421 task_block.go:223] [ 22] Interrupt queued D0228 11:38:30.015443 64421 task_block.go:223] [ 22] Interrupt queued D0228 11:38:30.015672 64421 task_signals.go:179] [ 22] Restarting syscall 202 after errno 512: interrupted by signal 17 D0228 11:38:30.015796 64421 task_signals.go:220] [ 22] Signal 17: delivering to handler D0228 11:38:30.017465 64421 task_exit.go:221] [ 38] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.019664 64421 task_block.go:223] [ 39] Interrupt queued D0228 11:38:30.024426 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 11:38:30.025526 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] 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: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350296}]} D0228 11:38:30.025656 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tclunk{FID: 11} D0228 11:38:30.026076 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rclunk{} D0228 11:38:30.026301 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 11:38:30.027028 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350296}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 11:38:30 executed programs: 0 D0228 11:38:30.034211 64421 task_stop.go:118] [ 31] Entering internal stop (*kernel.vforkStop)(nil) D0228 11:38:30.034847 64421 task_block.go:223] [ 40] Interrupt queued D0228 11:38:30.039399 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 11:38:30.040402 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] 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: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350296}]} D0228 11:38:30.040553 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tclunk{FID: 11} D0228 11:38:30.040953 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rclunk{} D0228 11:38:30.041118 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 11:38:30.041799 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350296}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582889819, NanoSec: 816449234}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 11:38:30.042657 64421 syscalls.go:266] [ 40] Allocating stack with size of 8388608 bytes D0228 11:38:30.043464 64421 task_stop.go:137] [ 31] Leaving internal stop (*kernel.vforkStop)(nil) D0228 11:38:30.050650 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 11:38:30.051196 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.051375 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 11:38:30.051800 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.062375 64421 task_block.go:223] [ 41] Interrupt queued D0228 11:38:30.066370 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.067062 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.067249 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.067786 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.068208 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.068688 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.068861 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.069397 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.070026 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.070644 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.070811 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.071236 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.071659 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.072249 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.072353 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.072777 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.073117 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.073539 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.073670 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.074150 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.074805 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.075278 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.075473 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.075906 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.076280 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.076747 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.076916 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.077418 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.077896 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.078583 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.078832 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.079424 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.080112 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.080653 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.080782 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.081237 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.107245 64421 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 11:38:30.107413 64421 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 11:38:30.107516 64421 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 11:38:30.107623 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.107702 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.108353 64421 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 11:38:30.108423 64421 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0228 11:38:30.108538 64421 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0228 11:38:30.108638 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.108724 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.109306 64421 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 11:38:30.109386 64421 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 11:38:30.109486 64421 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 11:38:30.109593 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.109669 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.110214 64421 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 11:38:30.110290 64421 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0228 11:38:30.110369 64421 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0228 11:38:30.110665 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.110743 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.111272 64421 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0228 11:38:30.111387 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0228 11:38:30.112072 64421 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 11:38:30.112152 64421 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 11:38:30.112254 64421 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 11:38:30.112321 64421 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 11:38:30.112397 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.112481 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.113002 64421 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 11:38:30.113084 64421 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0228 11:38:30.113190 64421 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0228 11:38:30.113291 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.113387 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.113943 64421 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 11:38:30.114038 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0228 11:38:30.114650 64421 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 11:38:30.114766 64421 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 11:38:30.114855 64421 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0228 11:38:30.114944 64421 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0228 11:38:30.115010 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.115097 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.115590 64421 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 11:38:30.115671 64421 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0228 11:38:30.115746 64421 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0228 11:38:30.115812 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.115901 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.116390 64421 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 11:38:30.116467 64421 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 11:38:30.116543 64421 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 11:38:30.116641 64421 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 11:38:30.116728 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 11:38:30.118291 64421 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 11:38:30.119402 64421 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0228 11:38:30.120004 64421 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 11:38:30.345356 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.345972 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.346239 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.346649 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.347001 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.347416 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.347554 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.348078 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.348377 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.348770 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.348878 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.349251 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.349619 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.350036 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.350171 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.350730 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.351069 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.351503 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.351634 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.352069 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.352421 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.352855 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.352969 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.353421 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.353714 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.354245 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.354384 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.354871 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.355122 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.355655 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.355810 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.356335 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.356765 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.357292 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.357432 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.357814 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.358133 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.358560 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.358739 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.359195 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.374119 64421 task_block.go:223] [ 42] Interrupt queued D0228 11:38:30.386440 64421 task_block.go:223] [ 43] Interrupt queued D0228 11:38:30.417838 64421 task_block.go:223] [ 44] Interrupt queued D0228 11:38:30.436144 64421 task_block.go:223] [ 43] Interrupt queued D0228 11:38:30.436240 64421 task_block.go:223] [ 43] Interrupt queued D0228 11:38:30.436316 64421 task_block.go:223] [ 44] Interrupt queued D0228 11:38:30.436359 64421 task_block.go:223] [ 44] Interrupt queued D0228 11:38:30.436412 64421 task_exit.go:221] [ 42] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.436564 64421 task_signals.go:189] [ 44] Signal 9: terminating thread group D0228 11:38:30.436588 64421 task_signals.go:189] [ 43] Signal 9: terminating thread group D0228 11:38:30.436780 64421 task_exit.go:221] [ 42] Transitioning from exit state TaskExitInitiated to TaskExitZombie I0228 11:38:30.436680 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 42, TID: 44, fault addr: 0x0 D0228 11:38:30.436963 64421 task_exit.go:221] [ 44] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.437156 64421 task_exit.go:221] [ 44] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.437260 64421 task_exit.go:221] [ 44] Transitioning from exit state TaskExitZombie to TaskExitDead I0228 11:38:30.437054 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 42, TID: 43, fault addr: 0x0 D0228 11:38:30.437499 64421 task_exit.go:221] [ 43] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.438834 64421 task_exit.go:221] [ 43] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.438958 64421 task_exit.go:221] [ 43] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.439100 64421 task_signals.go:419] [ 41] Discarding ignored signal 17 D0228 11:38:30.440495 64421 task_exit.go:221] [ 42] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.444468 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.445104 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.445271 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.445747 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.446949 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.447589 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.447809 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.448431 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.449346 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.449946 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.450072 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.450570 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.458580 64421 task_block.go:223] [ 45] Interrupt queued D0228 11:38:30.469474 64421 task_block.go:223] [ 46] Interrupt queued D0228 11:38:30.496855 64421 task_block.go:223] [ 47] Interrupt queued D0228 11:38:30.516755 64421 task_block.go:223] [ 46] Interrupt queued D0228 11:38:30.516790 64421 task_block.go:223] [ 46] Interrupt queued D0228 11:38:30.516909 64421 task_block.go:223] [ 47] Interrupt queued D0228 11:38:30.517007 64421 task_block.go:223] [ 47] Interrupt queued D0228 11:38:30.517123 64421 task_exit.go:221] [ 45] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.517483 64421 task_signals.go:189] [ 47] Signal 9: terminating thread group D0228 11:38:30.517506 64421 task_signals.go:189] [ 46] Signal 9: terminating thread group D0228 11:38:30.517423 64421 task_exit.go:221] [ 45] Transitioning from exit state TaskExitInitiated to TaskExitZombie I0228 11:38:30.517821 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 45, TID: 47, fault addr: 0x0 D0228 11:38:30.518030 64421 task_exit.go:221] [ 47] Transitioning from exit state TaskExitNone to TaskExitInitiated I0228 11:38:30.518129 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 45, TID: 46, fault addr: 0x0 D0228 11:38:30.518257 64421 task_exit.go:221] [ 47] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.518419 64421 task_exit.go:221] [ 47] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.518744 64421 task_exit.go:221] [ 46] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.520461 64421 task_exit.go:221] [ 46] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.520665 64421 task_exit.go:221] [ 46] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.520852 64421 task_signals.go:419] [ 41] Discarding ignored signal 17 D0228 11:38:30.521106 64421 task_exit.go:221] [ 45] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.525572 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.526591 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.526760 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.527292 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.528604 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.529205 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.529390 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.529932 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.530995 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.531689 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.531913 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.532346 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.540579 64421 task_block.go:223] [ 48] Interrupt queued D0228 11:38:30.548542 64421 task_block.go:223] [ 49] Interrupt queued D0228 11:38:30.565378 64421 task_block.go:223] [ 50] Interrupt queued D0228 11:38:30.570272 64421 task_block.go:223] [ 51] Interrupt queued D0228 11:38:30.577946 64421 task_block.go:223] [ 49] Interrupt queued D0228 11:38:30.577970 64421 task_block.go:223] [ 49] Interrupt queued D0228 11:38:30.578099 64421 task_block.go:223] [ 50] Interrupt queued D0228 11:38:30.578169 64421 task_block.go:223] [ 51] Interrupt queued D0228 11:38:30.578200 64421 task_block.go:223] [ 50] Interrupt queued D0228 11:38:30.578270 64421 task_exit.go:221] [ 48] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.578326 64421 task_block.go:223] [ 51] Interrupt queued D0228 11:38:30.578433 64421 task_signals.go:189] [ 50] Signal 9: terminating thread group D0228 11:38:30.578543 64421 task_exit.go:221] [ 48] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.578617 64421 task_signals.go:189] [ 49] Signal 9: terminating thread group D0228 11:38:30.578565 64421 task_signals.go:189] [ 51] Signal 9: terminating thread group I0228 11:38:30.578759 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 48, TID: 50, fault addr: 0x0 D0228 11:38:30.578959 64421 task_exit.go:221] [ 50] Transitioning from exit state TaskExitNone to TaskExitInitiated I0228 11:38:30.579011 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 48, TID: 49, fault addr: 0x0 D0228 11:38:30.579146 64421 task_exit.go:221] [ 50] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.579276 64421 task_exit.go:221] [ 50] Transitioning from exit state TaskExitZombie to TaskExitDead I0228 11:38:30.579255 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 48, TID: 51, fault addr: 0x0 D0228 11:38:30.579438 64421 task_exit.go:221] [ 51] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.579600 64421 task_exit.go:221] [ 49] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.579833 64421 task_exit.go:221] [ 49] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.579958 64421 task_exit.go:221] [ 49] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.581785 64421 task_exit.go:221] [ 51] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.581934 64421 task_exit.go:221] [ 51] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.582106 64421 task_signals.go:419] [ 41] Discarding ignored signal 17 D0228 11:38:30.582376 64421 task_exit.go:221] [ 48] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.584218 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.584864 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.585015 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.608902 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.610043 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.610773 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.611010 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.611503 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.612521 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.613240 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.613452 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.613861 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.619450 64421 task_block.go:223] [ 52] Interrupt queued D0228 11:38:30.630563 64421 task_block.go:223] [ 53] Interrupt queued D0228 11:38:30.651861 64421 task_block.go:223] [ 54] Interrupt queued D0228 11:38:30.657208 64421 task_block.go:223] [ 55] Interrupt queued D0228 11:38:30.665371 64421 task_block.go:223] [ 53] Interrupt queued D0228 11:38:30.665527 64421 task_block.go:223] [ 54] Interrupt queued D0228 11:38:30.665480 64421 task_block.go:223] [ 53] Interrupt queued D0228 11:38:30.665561 64421 task_block.go:223] [ 54] Interrupt queued D0228 11:38:30.665623 64421 task_block.go:223] [ 55] Interrupt queued D0228 11:38:30.665708 64421 task_block.go:223] [ 55] Interrupt queued D0228 11:38:30.665748 64421 task_exit.go:221] [ 52] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.665896 64421 task_signals.go:189] [ 55] Signal 9: terminating thread group D0228 11:38:30.665941 64421 task_exit.go:221] [ 52] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.665962 64421 task_signals.go:189] [ 54] Signal 9: terminating thread group D0228 11:38:30.666047 64421 task_signals.go:189] [ 53] Signal 9: terminating thread group I0228 11:38:30.666155 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 52, TID: 55, fault addr: 0x0 D0228 11:38:30.666347 64421 task_exit.go:221] [ 55] Transitioning from exit state TaskExitNone to TaskExitInitiated I0228 11:38:30.666374 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 52, TID: 54, fault addr: 0x0 D0228 11:38:30.666513 64421 task_exit.go:221] [ 55] Transitioning from exit state TaskExitInitiated to TaskExitZombie I0228 11:38:30.666562 64421 compat.go:129] Uncaught signal: "killed" (9), PID: 52, TID: 53, fault addr: 0x0 D0228 11:38:30.666615 64421 task_exit.go:221] [ 55] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.666884 64421 task_exit.go:221] [ 54] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.667151 64421 task_exit.go:221] [ 53] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 11:38:30.667554 64421 task_exit.go:221] [ 53] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.667729 64421 task_exit.go:221] [ 53] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.668454 64421 task_exit.go:221] [ 54] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 11:38:30.668577 64421 task_exit.go:221] [ 54] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.668706 64421 task_signals.go:419] [ 41] Discarding ignored signal 17 D0228 11:38:30.669183 64421 task_exit.go:221] [ 52] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 11:38:30.671846 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.672477 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.672640 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.673140 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.673743 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.674327 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.674462 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.674866 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.675438 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 11:38:30.675902 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 2} D0228 11:38:30.676025 64421 transport_flipcall.go:127] send [channel @0xc00039c3c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 11:38:30.676373 64421 transport_flipcall.go:234] recv [channel @0xc00039c3c0] Rlerror{Error: 95} D0228 11:38:30.681355 64421 task_block.go:223] [ 56] Interrupt queued D0228 11:38:30.687615 64421 task_block.go:223] [ 57] Interrupt queued D0228 11:38:30.707933 64421 task_block.go:223] [ 58] Interrupt queued ================== WARNING: DATA RACE Read at 0x00c0008cc250 by goroutine 352: gvisor.dev/gvisor/pkg/tcpip/stack.(*TransportEndpointInfo).AddrNetProto() pkg/tcpip/stack/stack.go:573 +0x79 gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).checkV4Mapped() pkg/tcpip/transport/udp/endpoint.go:931 +0xee gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Connect() pkg/tcpip/transport/udp/endpoint.go:984 +0x6c gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Connect() pkg/sentry/socket/netstack/netstack.go:698 +0x4c5 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Connect() pkg/sentry/syscalls/linux/sys_socket.go:280 +0x251 DIAGNOSIS: I0228 11:38:30.747426 11610 main.go:296] *************************** I0228 11:38:30.747546 11610 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-1] I0228 11:38:30.747696 11610 main.go:298] Version release-20200219.0-63-gc96bb4d2ebc6 I0228 11:38:30.747771 11610 main.go:299] PID: 11610 I0228 11:38:30.747837 11610 main.go:300] UID: 0, GID: 0 I0228 11:38:30.747930 11610 main.go:301] Configuration: I0228 11:38:30.748000 11610 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 11:38:30.748092 11610 main.go:303] Platform: ptrace I0228 11:38:30.748163 11610 main.go:304] FileAccess: shared, overlay: false I0228 11:38:30.748393 11610 main.go:305] Network: sandbox, logging: false I0228 11:38:30.748496 11610 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 11:38:30.748622 11610 main.go:307] *************************** W0228 11:38:30.748691 11610 main.go:312] Block the TERM signal. This is only safe in tests! D0228 11:38:30.748836 11610 container.go:159] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.754895 11610 container.go:592] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-1": signal 0 D0228 11:38:30.755115 11610 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.755240 11610 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.755730 11610 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 11:38:30.830906 11610 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1", PID: 64421 I0228 11:38:30.831044 11610 debug.go:131] Retrieving sandbox stacks D0228 11:38:30.831126 11610 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.831224 11610 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" W0228 11:38:30.831377 11610 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 64421: connection refused retrieving stacks: connecting to control server at PID 64421: connection refused W0228 11:38:30.831630 11610 main.go:329] Failure to execute command, err: 1 Error collecting stacks: failed to run ["/syzkaller/managers/ptrace-proxy-sandbox-race/current/image" "-root" "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "-watchdog-action=panic" "-network=none" "-debug" "-alsologtostderr" "-platform=ptrace" "-file-access=shared" "-network=sandbox" "-TESTONLY-unsafe-nonroot" "debug" "-stacks" "--ps" "ci-gvisor-ptrace-proxy-sandbox-race-1"]: exit status 128 I0228 11:38:30.747426 11610 main.go:296] *************************** I0228 11:38:30.747546 11610 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-1] I0228 11:38:30.747696 11610 main.go:298] Version release-20200219.0-63-gc96bb4d2ebc6 I0228 11:38:30.747771 11610 main.go:299] PID: 11610 I0228 11:38:30.747837 11610 main.go:300] UID: 0, GID: 0 I0228 11:38:30.747930 11610 main.go:301] Configuration: I0228 11:38:30.748000 11610 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 11:38:30.748092 11610 main.go:303] Platform: ptrace I0228 11:38:30.748163 11610 main.go:304] FileAccess: shared, overlay: false I0228 11:38:30.748393 11610 main.go:305] Network: sandbox, logging: false I0228 11:38:30.748496 11610 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 11:38:30.748622 11610 main.go:307] *************************** W0228 11:38:30.748691 11610 main.go:312] Block the TERM signal. This is only safe in tests! D0228 11:38:30.748836 11610 container.go:159] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.754895 11610 container.go:592] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-1": signal 0 D0228 11:38:30.755115 11610 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.755240 11610 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.755730 11610 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 11:38:30.830906 11610 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1", PID: 64421 I0228 11:38:30.831044 11610 debug.go:131] Retrieving sandbox stacks D0228 11:38:30.831126 11610 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.831224 11610 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" W0228 11:38:30.831377 11610 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 64421: connection refused retrieving stacks: connecting to control server at PID 64421: connection refused W0228 11:38:30.831630 11610 main.go:329] Failure to execute command, err: 1 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous write at 0x00c0008cc250 by goroutine 367: gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).bindLocked() pkg/tcpip/transport/udp/endpoint.go:1176 +0x28a gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).prepareForWrite() pkg/tcpip/transport/udp/endpoint.go:323 +0x267 gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).write() pkg/tcpip/transport/udp/endpoint.go:400 +0x12b gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Write() pkg/tcpip/transport/udp/endpoint.go:360 +0x81 gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Write() pkg/sentry/socket/netstack/netstack.go:522 +0x152 gvisor.dev/gvisor/pkg/sentry/fs.(*File).Writev() pkg/sentry/fs/file.go:336 +0x308 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.writev() pkg/sentry/syscalls/linux/sys_write.go:262 +0xe0 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Writev() pkg/sentry/syscalls/linux/sys_write.go:149 +0x2a2 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Goroutine 352 (running) created at: gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Start() pkg/sentry/kernel/task_start.go:315 +0x19d gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Clone() pkg/sentry/kernel/task_clone.go:361 +0x12af gvisor.dev/gvisor/pkg/sentry/syscalls/linux.clone() pkg/sentry/syscalls/linux/sys_thread.go:226 +0x1fe gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Clone() pkg/sentry/syscalls/linux/sys_clone_amd64.go:34 +0x80 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Goroutine 367 (running) created at: gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Start() pkg/sentry/kernel/task_start.go:315 +0x19d gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Clone() pkg/sentry/kernel/task_clone.go:361 +0x12af gvisor.dev/gvisor/pkg/sentry/syscalls/linux.clone() pkg/sentry/syscalls/linux/sys_thread.go:226 +0x1fe gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Clone() pkg/sentry/syscalls/linux/sys_clone_amd64.go:34 +0x80 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 ================== W0228 11:38:30.824219 11388 error.go:48] FATAL ERROR: waiting on pid 22: waiting on PID 22 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 22: waiting on PID 22 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1": urpc method "containerManager.WaitPID" failed: EOF W0228 11:38:30.824525 11388 main.go:329] Failure to execute command, err: 1 W0228 11:38:30.830916 64414 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-1" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0228 11:38:30.831382 64414 container.go:714] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.831577 64414 container.go:801] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.831665 64414 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-1" by destroying sandbox D0228 11:38:30.831800 64414 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0228 11:38:30.831872 64414 container.go:815] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-1", PID: 64420 I0228 11:38:30.933403 64414 main.go:320] Exiting with status: 16896