I0228 08:19:08.565104 44410 calibrated_clock.go:79] CalibratedClock(Monotonic): ready I0228 08:19:08.565328 44410 calibrated_clock.go:79] CalibratedClock(Realtime): ready D0228 08:19:08.565428 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669900401778522 monotonicBaseRef:1000225454 monotonicFrequency:2299774120 realtimeReady:1 realtimeBaseCycles:8669900402318882 realtimeBaseRef:1582877948565323526 realtimeFrequency:2299774104} D0228 08:19:09.565188 44410 parameters.go:238] Clock(Monotonic): error: 347 ns, adjusted frequency from 2299774120 Hz to 2299775211 Hz D0228 08:19:09.565455 44410 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0228 08:19:09.565577 44410 parameters.go:238] Clock(Realtime): error: 648 ns, adjusted frequency from 2299774104 Hz to 2299775806 Hz D0228 08:19:09.565728 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669902701686487 monotonicBaseRef:2000283653 monotonicFrequency:2299775211 realtimeReady:1 realtimeBaseCycles:8669902702660396 realtimeBaseRef:1582877949565570250 realtimeFrequency:2299775806} D0228 08:19:10.565218 44410 parameters.go:238] Clock(Monotonic): error: 9 ns, adjusted frequency from 2299775211 Hz to 2299774456 Hz D0228 08:19:10.565497 44410 parameters.go:238] Clock(Realtime): error: 132 ns, adjusted frequency from 2299775806 Hz to 2299774697 Hz D0228 08:19:10.565605 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669905001510400 monotonicBaseRef:3000304829 monotonicFrequency:2299774456 realtimeReady:1 realtimeBaseCycles:8669905002256829 realtimeBaseRef:1582877950565492254 realtimeFrequency:2299774697} D0228 08:19:11.565197 44410 parameters.go:238] Clock(Monotonic): error: 59 ns, adjusted frequency from 2299774456 Hz to 2299774648 Hz D0228 08:19:11.565405 44410 parameters.go:238] Clock(Realtime): error: 16 ns, adjusted frequency from 2299774697 Hz to 2299774397 Hz D0228 08:19:11.565550 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669907301286248 monotonicBaseRef:4000305434 monotonicFrequency:2299774648 realtimeReady:1 realtimeBaseCycles:8669907301793650 realtimeBaseRef:1582877951565388819 realtimeFrequency:2299774397} D0228 08:19:12.565224 44410 parameters.go:238] Clock(Monotonic): error: 95 ns, adjusted frequency from 2299774648 Hz to 2299774756 Hz D0228 08:19:12.565506 44410 parameters.go:238] Clock(Realtime): error: 152 ns, adjusted frequency from 2299774397 Hz to 2299774830 Hz D0228 08:19:12.565625 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669909601151150 monotonicBaseRef:5000344678 monotonicFrequency:2299774756 realtimeReady:1 realtimeBaseCycles:8669909601824234 realtimeBaseRef:1582877952565500215 realtimeFrequency:2299774830} D0228 08:19:13.565142 44410 parameters.go:238] Clock(Monotonic): error: 7 ns, adjusted frequency from 2299774756 Hz to 2299774564 Hz D0228 08:19:13.565341 44410 parameters.go:238] Clock(Realtime): error: 36 ns, adjusted frequency from 2299774830 Hz to 2299774589 Hz D0228 08:19:13.565435 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669911900744562 monotonicBaseRef:6000265825 monotonicFrequency:2299774564 realtimeReady:1 realtimeBaseCycles:8669911901223777 realtimeBaseRef:1582877953565337030 realtimeFrequency:2299774589} D0228 08:19:14.565989 44410 parameters.go:238] Clock(Monotonic): error: 48 ns, adjusted frequency from 2299774564 Hz to 2299774678 Hz D0228 08:19:14.566202 44410 parameters.go:238] Clock(Realtime): error: 49 ns, adjusted frequency from 2299774589 Hz to 2299774633 Hz D0228 08:19:14.566303 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669914202465301 monotonicBaseRef:7001112070 monotonicFrequency:2299774678 realtimeReady:1 realtimeBaseCycles:8669914202977859 realtimeBaseRef:1582877954566197763 realtimeFrequency:2299774633} D0228 08:19:15.565235 44410 parameters.go:238] Clock(Monotonic): error: 18 ns, adjusted frequency from 2299774678 Hz to 2299774613 Hz D0228 08:19:15.565447 44410 parameters.go:238] Clock(Realtime): error: 64 ns, adjusted frequency from 2299774633 Hz to 2299774642 Hz D0228 08:19:15.565545 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669916500432409 monotonicBaseRef:8000326093 monotonicFrequency:2299774613 realtimeReady:1 realtimeBaseCycles:8669916501012350 realtimeBaseRef:1582877955565441105 realtimeFrequency:2299774642} D0228 08:19:16.565181 44410 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0228 08:19:16.565373 44410 parameters.go:238] Clock(Monotonic): error: 142 ns, adjusted frequency from 2299774613 Hz to 2299774848 Hz D0228 08:19:16.565499 44410 parameters.go:238] Clock(Realtime): error: -55 ns, adjusted frequency from 2299774642 Hz to 2299774448 Hz D0228 08:19:16.565598 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669918800610841 monotonicBaseRef:9000501683 monotonicFrequency:2299774848 realtimeReady:1 realtimeBaseCycles:8669918800910835 realtimeBaseRef:1582877956565494955 realtimeFrequency:2299774448} D0228 08:19:17.565179 44410 parameters.go:238] Clock(Monotonic): error: 671 ns, adjusted frequency from 2299774848 Hz to 2299776122 Hz D0228 08:19:17.565370 44410 parameters.go:238] Clock(Realtime): error: 191 ns, adjusted frequency from 2299774448 Hz to 2299775066 Hz D0228 08:19:17.565478 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669921099921578 monotonicBaseRef:10000299875 monotonicFrequency:2299776122 realtimeReady:1 realtimeBaseCycles:8669921100388550 realtimeBaseRef:1582877957565365927 realtimeFrequency:2299775066} D0228 08:19:18.565140 44410 parameters.go:238] Clock(Monotonic): error: -513 ns, adjusted frequency from 2299776122 Hz to 2299773460 Hz D0228 08:19:18.565459 44410 parameters.go:238] Clock(Realtime): error: -30 ns, adjusted frequency from 2299775066 Hz to 2299774532 Hz D0228 08:19:18.565573 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669923399551190 monotonicBaseRef:11000236168 monotonicFrequency:2299773460 realtimeReady:1 realtimeBaseCycles:8669923400362882 realtimeBaseRef:1582877958565452572 realtimeFrequency:2299774532} D0228 08:19:19.565097 44410 parameters.go:238] Clock(Monotonic): error: 259 ns, adjusted frequency from 2299773460 Hz to 2299775178 Hz D0228 08:19:19.565292 44410 parameters.go:238] Clock(Realtime): error: 24 ns, adjusted frequency from 2299774532 Hz to 2299774649 Hz D0228 08:19:19.565388 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669925699285886 monotonicBaseRef:12000219312 monotonicFrequency:2299775178 realtimeReady:1 realtimeBaseCycles:8669925699756040 realtimeBaseRef:1582877959565286740 realtimeFrequency:2299774649} D0228 08:19:20.565253 44410 parameters.go:238] Clock(Monotonic): error: -401 ns, adjusted frequency from 2299775178 Hz to 2299773720 Hz D0228 08:19:20.565434 44410 parameters.go:238] Clock(Realtime): error: -25 ns, adjusted frequency from 2299774649 Hz to 2299774627 Hz D0228 08:19:20.565566 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669927999419195 monotonicBaseRef:13000375036 monotonicFrequency:2299773720 realtimeReady:1 realtimeBaseCycles:8669927999856759 realtimeBaseRef:1582877960565428523 realtimeFrequency:2299774627} D0228 08:19:21.565177 44410 parameters.go:238] Clock(Monotonic): error: -20 ns, adjusted frequency from 2299773720 Hz to 2299774591 Hz D0228 08:19:21.565365 44410 parameters.go:238] Clock(Realtime): error: -68 ns, adjusted frequency from 2299774627 Hz to 2299774480 Hz D0228 08:19:21.565501 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669930299020669 monotonicBaseRef:14000300139 monotonicFrequency:2299774591 realtimeReady:1 realtimeBaseCycles:8669930299476296 realtimeBaseRef:1582877961565361085 realtimeFrequency:2299774480} D0228 08:19:22.565523 44410 parameters.go:238] Clock(Monotonic): error: 476 ns, adjusted frequency from 2299774591 Hz to 2299775659 Hz D0228 08:19:22.565710 44410 parameters.go:238] Clock(Realtime): error: 4 ns, adjusted frequency from 2299774480 Hz to 2299774651 Hz D0228 08:19:22.565846 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669932599591029 monotonicBaseRef:15000646159 monotonicFrequency:2299775659 realtimeReady:1 realtimeBaseCycles:8669932600041980 realtimeBaseRef:1582877962565705120 realtimeFrequency:2299774651} D0228 08:19:23.565266 44410 parameters.go:238] Clock(Monotonic): error: -211 ns, adjusted frequency from 2299775659 Hz to 2299774153 Hz D0228 08:19:23.565524 44410 parameters.go:238] Clock(Realtime): error: 363 ns, adjusted frequency from 2299774651 Hz to 2299775486 Hz D0228 08:19:23.565645 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669934898692951 monotonicBaseRef:16000353201 monotonicFrequency:2299774153 realtimeReady:1 realtimeBaseCycles:8669934899381209 realtimeBaseRef:1582877963565515787 realtimeFrequency:2299775486} D0228 08:19:24.565163 44410 parameters.go:238] Clock(Monotonic): error: 179 ns, adjusted frequency from 2299774153 Hz to 2299774928 Hz D0228 08:19:24.565377 44410 parameters.go:238] Clock(Realtime): error: -282 ns, adjusted frequency from 2299775486 Hz to 2299773995 Hz D0228 08:19:24.565490 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669937198310837 monotonicBaseRef:17000285252 monotonicFrequency:2299774928 realtimeReady:1 realtimeBaseCycles:8669937198824169 realtimeBaseRef:1582877964565371196 realtimeFrequency:2299773995} D0228 08:19:25.261896 44410 urpc.go:577] urpc: unmarshal success. D0228 08:19:25.262114 44410 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 08:19:25.262394 44410 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:19:25.565207 44410 parameters.go:238] Clock(Monotonic): error: -8 ns, adjusted frequency from 2299774928 Hz to 2299774603 Hz D0228 08:19:25.565416 44410 parameters.go:238] Clock(Realtime): error: -35 ns, adjusted frequency from 2299773995 Hz to 2299774523 Hz D0228 08:19:25.565508 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669939498178703 monotonicBaseRef:18000325663 monotonicFrequency:2299774603 realtimeReady:1 realtimeBaseCycles:8669939498669229 realtimeBaseRef:1582877965565402096 realtimeFrequency:2299774523} D0228 08:19:26.565715 44410 parameters.go:238] Clock(Monotonic): error: -30 ns, adjusted frequency from 2299774603 Hz to 2299774562 Hz D0228 08:19:26.565921 44410 parameters.go:238] Clock(Realtime): error: 255 ns, adjusted frequency from 2299774523 Hz to 2299775204 Hz D0228 08:19:26.566087 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669941799121767 monotonicBaseRef:19000833739 monotonicFrequency:2299774562 realtimeReady:1 realtimeBaseCycles:8669941799623047 realtimeBaseRef:1582877966565914883 realtimeFrequency:2299775204} D0228 08:19:27.565186 44410 parameters.go:238] Clock(Monotonic): error: 9 ns, adjusted frequency from 2299774562 Hz to 2299774539 Hz D0228 08:19:27.565380 44410 parameters.go:238] Clock(Realtime): error: -260 ns, adjusted frequency from 2299775204 Hz to 2299774065 Hz D0228 08:19:27.565489 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669944097689421 monotonicBaseRef:20000308944 monotonicFrequency:2299774539 realtimeReady:1 realtimeBaseCycles:8669944098155823 realtimeBaseRef:1582877967565374644 realtimeFrequency:2299774065} D0228 08:19:28.565178 44410 parameters.go:238] Clock(Monotonic): error: 0 ns, adjusted frequency from 2299774539 Hz to 2299774699 Hz D0228 08:19:28.565411 44410 parameters.go:238] Clock(Realtime): error: 264 ns, adjusted frequency from 2299774065 Hz to 2299775316 Hz D0228 08:19:28.565621 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669946397435423 monotonicBaseRef:21000296535 monotonicFrequency:2299774699 realtimeReady:1 realtimeBaseCycles:8669946397998005 realtimeBaseRef:1582877968565404262 realtimeFrequency:2299775316} D0228 08:19:29.565188 44410 parameters.go:238] Clock(Monotonic): error: -84 ns, adjusted frequency from 2299774699 Hz to 2299774452 Hz D0228 08:19:29.565397 44410 parameters.go:238] Clock(Realtime): error: -312 ns, adjusted frequency from 2299775316 Hz to 2299773905 Hz D0228 08:19:29.565560 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669948697227937 monotonicBaseRef:22000304281 monotonicFrequency:2299774452 realtimeReady:1 realtimeBaseCycles:8669948697745833 realtimeBaseRef:1582877969565392309 realtimeFrequency:2299773905} D0228 08:19:30.566067 44410 parameters.go:238] Clock(Monotonic): error: -95 ns, adjusted frequency from 2299774452 Hz to 2299774433 Hz D0228 08:19:30.566286 44410 parameters.go:238] Clock(Realtime): error: 469 ns, adjusted frequency from 2299773905 Hz to 2299775780 Hz D0228 08:19:30.566416 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669950999019560 monotonicBaseRef:23001181397 monotonicFrequency:2299774433 realtimeReady:1 realtimeBaseCycles:8669950999561886 realtimeBaseRef:1582877970566280286 realtimeFrequency:2299775780} D0228 08:19:31.565188 44410 parameters.go:238] Clock(Monotonic): error: 193 ns, adjusted frequency from 2299774433 Hz to 2299775081 Hz D0228 08:19:31.565386 44410 parameters.go:238] Clock(Realtime): error: -268 ns, adjusted frequency from 2299775780 Hz to 2299774045 Hz D0228 08:19:31.565493 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669953296789113 monotonicBaseRef:24000309624 monotonicFrequency:2299775081 realtimeReady:1 realtimeBaseCycles:8669953297266376 realtimeBaseRef:1582877971565379637 realtimeFrequency:2299774045} D0228 08:19:32.565231 44410 parameters.go:238] Clock(Monotonic): error: -306 ns, adjusted frequency from 2299775081 Hz to 2299773923 Hz D0228 08:19:32.565427 44410 parameters.go:238] Clock(Realtime): error: -473 ns, adjusted frequency from 2299774045 Hz to 2299773580 Hz D0228 08:19:32.565602 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669955596665208 monotonicBaseRef:25000353547 monotonicFrequency:2299773923 realtimeReady:1 realtimeBaseCycles:8669955597136898 realtimeBaseRef:1582877972565421587 realtimeFrequency:2299773580} D0228 08:19:33.565819 44410 parameters.go:238] Clock(Monotonic): error: 340 ns, adjusted frequency from 2299773923 Hz to 2299775424 Hz D0228 08:19:33.566018 44410 parameters.go:238] Clock(Realtime): error: 213 ns, adjusted frequency from 2299773580 Hz to 2299775168 Hz D0228 08:19:33.566154 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669957897729343 monotonicBaseRef:26000914563 monotonicFrequency:2299775424 realtimeReady:1 realtimeBaseCycles:8669957898269583 realtimeBaseRef:1582877973566012560 realtimeFrequency:2299775168} D0228 08:19:34.565174 44410 parameters.go:238] Clock(Monotonic): error: -230 ns, adjusted frequency from 2299775424 Hz to 2299774135 Hz D0228 08:19:34.565398 44410 parameters.go:238] Clock(Realtime): error: 31 ns, adjusted frequency from 2299775168 Hz to 2299774694 Hz D0228 08:19:34.565508 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669960196080646 monotonicBaseRef:27000295319 monotonicFrequency:2299774135 realtimeReady:1 realtimeBaseCycles:8669960196620960 realtimeBaseRef:1582877974565393459 realtimeFrequency:2299774694} D0228 08:19:35.565170 44410 parameters.go:238] Clock(Monotonic): error: 188 ns, adjusted frequency from 2299774135 Hz to 2299775057 Hz D0228 08:19:35.565370 44410 parameters.go:238] Clock(Realtime): error: -240 ns, adjusted frequency from 2299774694 Hz to 2299774133 Hz D0228 08:19:35.565630 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669962495847658 monotonicBaseRef:28000292221 monotonicFrequency:2299775057 realtimeReady:1 realtimeBaseCycles:8669962496328875 realtimeBaseRef:1582877975565364421 realtimeFrequency:2299774133} D0228 08:19:36.565183 44410 parameters.go:238] Clock(Monotonic): error: -253 ns, adjusted frequency from 2299775057 Hz to 2299774160 Hz D0228 08:19:36.565367 44410 parameters.go:238] Clock(Realtime): error: 157 ns, adjusted frequency from 2299774133 Hz to 2299775019 Hz D0228 08:19:36.565489 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669964795652000 monotonicBaseRef:29000304954 monotonicFrequency:2299774160 realtimeReady:1 realtimeBaseCycles:8669964796100928 realtimeBaseRef:1582877976565363516 realtimeFrequency:2299775019} D0228 08:19:37.565173 44410 parameters.go:238] Clock(Monotonic): error: 87 ns, adjusted frequency from 2299774160 Hz to 2299774849 Hz D0228 08:19:37.565457 44410 parameters.go:238] Clock(Realtime): error: 330 ns, adjusted frequency from 2299775019 Hz to 2299775357 Hz D0228 08:19:37.565617 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669967095399924 monotonicBaseRef:30000293545 monotonicFrequency:2299774849 realtimeReady:1 realtimeBaseCycles:8669967096077560 realtimeBaseRef:1582877977565451182 realtimeFrequency:2299775357} D0228 08:19:38.565359 44410 parameters.go:238] Clock(Monotonic): error: -146 ns, adjusted frequency from 2299774849 Hz to 2299774287 Hz D0228 08:19:38.565542 44410 parameters.go:238] Clock(Realtime): error: -180 ns, adjusted frequency from 2299775357 Hz to 2299774252 Hz D0228 08:19:38.565656 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669969395611989 monotonicBaseRef:31000483657 monotonicFrequency:2299774287 realtimeReady:1 realtimeBaseCycles:8669969396050384 realtimeBaseRef:1582877978565537045 realtimeFrequency:2299774252} D0228 08:19:39.565162 44410 parameters.go:238] Clock(Monotonic): error: -45 ns, adjusted frequency from 2299774287 Hz to 2299774521 Hz D0228 08:19:39.565626 44410 parameters.go:238] Clock(Realtime): error: -99 ns, adjusted frequency from 2299774252 Hz to 2299774339 Hz D0228 08:19:39.565771 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669971694926702 monotonicBaseRef:32000283822 monotonicFrequency:2299774521 realtimeReady:1 realtimeBaseCycles:8669971696016073 realtimeBaseRef:1582877979565620286 realtimeFrequency:2299774339} D0228 08:19:40.565173 44410 parameters.go:238] Clock(Monotonic): error: 364 ns, adjusted frequency from 2299774521 Hz to 2299775420 Hz D0228 08:19:40.565376 44410 parameters.go:238] Clock(Realtime): error: 57 ns, adjusted frequency from 2299774339 Hz to 2299774745 Hz D0228 08:19:40.565515 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669973994714148 monotonicBaseRef:33000289442 monotonicFrequency:2299775420 realtimeReady:1 realtimeBaseCycles:8669973995216906 realtimeBaseRef:1582877980565370911 realtimeFrequency:2299774745} D0228 08:19:41.565257 44410 parameters.go:238] Clock(Monotonic): error: -74 ns, adjusted frequency from 2299775420 Hz to 2299774480 Hz D0228 08:19:41.565480 44410 parameters.go:238] Clock(Realtime): error: 222 ns, adjusted frequency from 2299774745 Hz to 2299775087 Hz D0228 08:19:41.565623 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669976294687542 monotonicBaseRef:34000375526 monotonicFrequency:2299774480 realtimeReady:1 realtimeBaseCycles:8669976295226715 realtimeBaseRef:1582877981565473122 realtimeFrequency:2299775087} D0228 08:19:42.565138 44410 parameters.go:238] Clock(Monotonic): error: -245 ns, adjusted frequency from 2299774480 Hz to 2299774185 Hz D0228 08:19:42.565335 44410 parameters.go:238] Clock(Realtime): error: 47 ns, adjusted frequency from 2299775087 Hz to 2299774774 Hz D0228 08:19:42.565478 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669978594197474 monotonicBaseRef:35000260493 monotonicFrequency:2299774185 realtimeReady:1 realtimeBaseCycles:8669978594669633 realtimeBaseRef:1582877982565328686 realtimeFrequency:2299774774} D0228 08:19:43.565293 44410 parameters.go:238] Clock(Monotonic): error: 371 ns, adjusted frequency from 2299774185 Hz to 2299775485 Hz D0228 08:19:43.565531 44410 parameters.go:238] Clock(Realtime): error: -210 ns, adjusted frequency from 2299774774 Hz to 2299774184 Hz D0228 08:19:43.565637 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669980894223601 monotonicBaseRef:36000370043 monotonicFrequency:2299775485 realtimeReady:1 realtimeBaseCycles:8669980894894379 realtimeBaseRef:1582877983565524345 realtimeFrequency:2299774184} D0228 08:19:44.565179 44410 parameters.go:238] Clock(Monotonic): error: 168 ns, adjusted frequency from 2299775485 Hz to 2299775055 Hz D0228 08:19:44.565410 44410 parameters.go:238] Clock(Realtime): error: -87 ns, adjusted frequency from 2299774184 Hz to 2299774396 Hz D0228 08:19:44.565532 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669983193817360 monotonicBaseRef:37000291023 monotonicFrequency:2299775055 realtimeReady:1 realtimeBaseCycles:8669983194394488 realtimeBaseRef:1582877984565405170 realtimeFrequency:2299774396} D0228 08:19:45.565253 44410 parameters.go:238] Clock(Monotonic): error: -387 ns, adjusted frequency from 2299775055 Hz to 2299773750 Hz D0228 08:19:45.565719 44410 parameters.go:238] Clock(Realtime): error: 484 ns, adjusted frequency from 2299774396 Hz to 2299775736 Hz D0228 08:19:45.565865 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669985493779050 monotonicBaseRef:38000372176 monotonicFrequency:2299773750 realtimeReady:1 realtimeBaseCycles:8669985494872851 realtimeBaseRef:1582877985565711272 realtimeFrequency:2299775736} D0228 08:19:46.565178 44410 parameters.go:238] Clock(Monotonic): error: 149 ns, adjusted frequency from 2299773750 Hz to 2299774877 Hz D0228 08:19:46.565388 44410 parameters.go:238] Clock(Realtime): error: -390 ns, adjusted frequency from 2299775736 Hz to 2299773724 Hz D0228 08:19:46.565557 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669987793385393 monotonicBaseRef:39000299383 monotonicFrequency:2299774877 realtimeReady:1 realtimeBaseCycles:8669987793890313 realtimeBaseRef:1582877986565381555 realtimeFrequency:2299773724} D0228 08:19:47.565212 44410 parameters.go:238] Clock(Monotonic): error: -303 ns, adjusted frequency from 2299774877 Hz to 2299773953 Hz D0228 08:19:47.565393 44410 parameters.go:238] Clock(Realtime): error: -74 ns, adjusted frequency from 2299773724 Hz to 2299774455 Hz D0228 08:19:47.565504 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669990093231927 monotonicBaseRef:40000330541 monotonicFrequency:2299773953 realtimeReady:1 realtimeBaseCycles:8669990093678720 realtimeBaseRef:1582877987565387939 realtimeFrequency:2299774455} D0228 08:19:48.565134 44410 parameters.go:238] Clock(Monotonic): error: 397 ns, adjusted frequency from 2299773953 Hz to 2299775414 Hz D0228 08:19:48.565352 44410 parameters.go:238] Clock(Realtime): error: 241 ns, adjusted frequency from 2299774455 Hz to 2299775200 Hz D0228 08:19:48.565513 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669992392838454 monotonicBaseRef:41000257739 monotonicFrequency:2299775414 realtimeReady:1 realtimeBaseCycles:8669992393356273 realtimeBaseRef:1582877988565345803 realtimeFrequency:2299775200} D0228 08:19:49.565162 44410 parameters.go:238] Clock(Monotonic): error: -330 ns, adjusted frequency from 2299775414 Hz to 2299774023 Hz D0228 08:19:49.565359 44410 parameters.go:238] Clock(Realtime): error: -228 ns, adjusted frequency from 2299775200 Hz to 2299774114 Hz D0228 08:19:49.565448 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669994692675563 monotonicBaseRef:42000284565 monotonicFrequency:2299774023 realtimeReady:1 realtimeBaseCycles:8669994693151426 realtimeBaseRef:1582877989565354479 realtimeFrequency:2299774114} D0228 08:19:50.565191 44410 parameters.go:238] Clock(Monotonic): error: -70 ns, adjusted frequency from 2299774023 Hz to 2299774475 Hz D0228 08:19:50.565371 44410 parameters.go:238] Clock(Realtime): error: 54 ns, adjusted frequency from 2299774114 Hz to 2299774792 Hz D0228 08:19:50.565470 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669996992513611 monotonicBaseRef:43000312404 monotonicFrequency:2299774475 realtimeReady:1 realtimeBaseCycles:8669996992954666 realtimeBaseRef:1582877990565367143 realtimeFrequency:2299774792} D0228 08:19:51.565133 44410 parameters.go:238] Clock(Monotonic): error: 293 ns, adjusted frequency from 2299774475 Hz to 2299775246 Hz D0228 08:19:51.565469 44410 parameters.go:238] Clock(Realtime): error: -42 ns, adjusted frequency from 2299774792 Hz to 2299774508 Hz D0228 08:19:51.565564 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8669999292157254 monotonicBaseRef:44000255514 monotonicFrequency:2299775246 realtimeReady:1 realtimeBaseCycles:8669999292952507 realtimeBaseRef:1582877991565464130 realtimeFrequency:2299774508} D0228 08:19:52.565183 44410 parameters.go:238] Clock(Monotonic): error: 201 ns, adjusted frequency from 2299775246 Hz to 2299775090 Hz D0228 08:19:52.565429 44410 parameters.go:238] Clock(Realtime): error: -35 ns, adjusted frequency from 2299774508 Hz to 2299774609 Hz D0228 08:19:52.565591 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670001592040841 monotonicBaseRef:45000302623 monotonicFrequency:2299775090 realtimeReady:1 realtimeBaseCycles:8670001592626307 realtimeBaseRef:1582877992565420339 realtimeFrequency:2299774609} I0228 08:19:52.696659 44410 watchdog.go:277] Watchdog starting loop, tasks: 15, discount: 0s D0228 08:19:53.565196 44410 parameters.go:238] Clock(Monotonic): error: -341 ns, adjusted frequency from 2299775090 Hz to 2299773908 Hz D0228 08:19:53.565451 44410 parameters.go:238] Clock(Realtime): error: 55 ns, adjusted frequency from 2299774609 Hz to 2299774764 Hz D0228 08:19:53.565546 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670003891823945 monotonicBaseRef:46000306107 monotonicFrequency:2299773908 realtimeReady:1 realtimeBaseCycles:8670003892456868 realtimeBaseRef:1582877993565444668 realtimeFrequency:2299774764} D0228 08:19:54.565365 44410 parameters.go:238] Clock(Monotonic): error: -121 ns, adjusted frequency from 2299773908 Hz to 2299774375 Hz D0228 08:19:54.565631 44410 parameters.go:238] Clock(Realtime): error: 371 ns, adjusted frequency from 2299774764 Hz to 2299775523 Hz D0228 08:19:54.565766 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670006192004926 monotonicBaseRef:47000483112 monotonicFrequency:2299774375 realtimeReady:1 realtimeBaseCycles:8670006192644420 realtimeBaseRef:1582877994565624158 realtimeFrequency:2299775523} D0228 08:19:55.565460 44410 parameters.go:238] Clock(Monotonic): error: 67 ns, adjusted frequency from 2299774375 Hz to 2299774897 Hz D0228 08:19:55.565645 44410 parameters.go:238] Clock(Realtime): error: -354 ns, adjusted frequency from 2299775523 Hz to 2299773862 Hz D0228 08:19:55.567891 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670008491976349 monotonicBaseRef:48000568793 monotonicFrequency:2299774897 realtimeReady:1 realtimeBaseCycles:8670008492456280 realtimeBaseRef:1582877995565639958 realtimeFrequency:2299773862} D0228 08:19:56.566773 44410 parameters.go:238] Clock(Monotonic): error: 95 ns, adjusted frequency from 2299774897 Hz to 2299774863 Hz D0228 08:19:56.567043 44410 parameters.go:238] Clock(Realtime): error: 22 ns, adjusted frequency from 2299773862 Hz to 2299774751 Hz D0228 08:19:56.567206 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670010794766560 monotonicBaseRef:49001879927 monotonicFrequency:2299774863 realtimeReady:1 realtimeBaseCycles:8670010795439805 realtimeBaseRef:1582877996567035600 realtimeFrequency:2299774751} D0228 08:19:57.565214 44410 parameters.go:238] Clock(Monotonic): error: 280 ns, adjusted frequency from 2299774863 Hz to 2299775311 Hz D0228 08:19:57.565458 44410 parameters.go:238] Clock(Realtime): error: -273 ns, adjusted frequency from 2299774751 Hz to 2299774064 Hz D0228 08:19:57.565579 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670013090982235 monotonicBaseRef:50000332302 monotonicFrequency:2299775311 realtimeReady:1 realtimeBaseCycles:8670013091572994 realtimeBaseRef:1582877997565452157 realtimeFrequency:2299774064} D0228 08:19:58.565134 44410 parameters.go:238] Clock(Monotonic): error: -314 ns, adjusted frequency from 2299775311 Hz to 2299773821 Hz D0228 08:19:58.565375 44410 parameters.go:238] Clock(Realtime): error: 125 ns, adjusted frequency from 2299774064 Hz to 2299774904 Hz D0228 08:19:58.565508 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670015390585661 monotonicBaseRef:51000257562 monotonicFrequency:2299773821 realtimeReady:1 realtimeBaseCycles:8670015391157537 realtimeBaseRef:1582877998565369748 realtimeFrequency:2299774904} D0228 08:19:59.565180 44410 parameters.go:238] Clock(Monotonic): error: 56 ns, adjusted frequency from 2299773821 Hz to 2299774787 Hz D0228 08:19:59.565434 44410 parameters.go:238] Clock(Realtime): error: 365 ns, adjusted frequency from 2299774904 Hz to 2299775425 Hz D0228 08:19:59.565705 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670017690453217 monotonicBaseRef:52000298320 monotonicFrequency:2299774787 realtimeReady:1 realtimeBaseCycles:8670017691064865 realtimeBaseRef:1582877999565427329 realtimeFrequency:2299775425} D0228 08:20:00.565248 44410 parameters.go:238] Clock(Monotonic): error: -123 ns, adjusted frequency from 2299774787 Hz to 2299774449 Hz D0228 08:20:00.565489 44410 parameters.go:238] Clock(Realtime): error: -218 ns, adjusted frequency from 2299775425 Hz to 2299774121 Hz D0228 08:20:00.565622 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670019990376904 monotonicBaseRef:53000363065 monotonicFrequency:2299774449 realtimeReady:1 realtimeBaseCycles:8670019990967300 realtimeBaseRef:1582878000565482556 realtimeFrequency:2299774121} D0228 08:20:00.758683 44410 urpc.go:577] urpc: unmarshal success. D0228 08:20:00.758987 44410 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 08:20:00.759248 44410 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:20:01.565160 44410 parameters.go:238] Clock(Monotonic): error: 225 ns, adjusted frequency from 2299774449 Hz to 2299775119 Hz D0228 08:20:01.565378 44410 parameters.go:238] Clock(Realtime): error: -281 ns, adjusted frequency from 2299774121 Hz to 2299773976 Hz D0228 08:20:01.565506 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670022289972413 monotonicBaseRef:54000285257 monotonicFrequency:2299775119 realtimeReady:1 realtimeBaseCycles:8670022290486054 realtimeBaseRef:1582878001565371515 realtimeFrequency:2299773976} D0228 08:20:02.565144 44410 parameters.go:238] Clock(Monotonic): error: -383 ns, adjusted frequency from 2299775119 Hz to 2299773747 Hz D0228 08:20:02.565380 44410 parameters.go:238] Clock(Realtime): error: 308 ns, adjusted frequency from 2299773976 Hz to 2299775371 Hz D0228 08:20:02.565490 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670024589701568 monotonicBaseRef:55000265270 monotonicFrequency:2299773747 realtimeReady:1 realtimeBaseCycles:8670024590266354 realtimeBaseRef:1582878002565374264 realtimeFrequency:2299775371} D0228 08:20:03.565170 44410 parameters.go:238] Clock(Monotonic): error: 603 ns, adjusted frequency from 2299773747 Hz to 2299775949 Hz D0228 08:20:03.565431 44410 parameters.go:238] Clock(Realtime): error: 5 ns, adjusted frequency from 2299775371 Hz to 2299774622 Hz D0228 08:20:03.565583 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670026889515661 monotonicBaseRef:56000282813 monotonicFrequency:2299775949 realtimeReady:1 realtimeBaseCycles:8670026890154389 realtimeBaseRef:1582878003565423253 realtimeFrequency:2299774622} D0228 08:20:04.565177 44410 parameters.go:238] Clock(Monotonic): error: -207 ns, adjusted frequency from 2299775949 Hz to 2299774104 Hz D0228 08:20:04.565378 44410 parameters.go:238] Clock(Realtime): error: -82 ns, adjusted frequency from 2299774622 Hz to 2299774451 Hz D0228 08:20:04.565586 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670029189322903 monotonicBaseRef:57000296419 monotonicFrequency:2299774104 realtimeReady:1 realtimeBaseCycles:8670029189814667 realtimeBaseRef:1582878004565373533 realtimeFrequency:2299774451} D0228 08:20:05.565200 44410 parameters.go:238] Clock(Monotonic): error: -38 ns, adjusted frequency from 2299774104 Hz to 2299774562 Hz D0228 08:20:05.565405 44410 parameters.go:238] Clock(Realtime): error: 23 ns, adjusted frequency from 2299774451 Hz to 2299774633 Hz D0228 08:20:05.565507 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670031489144652 monotonicBaseRef:58000317136 monotonicFrequency:2299774562 realtimeReady:1 realtimeBaseCycles:8670031489650803 realtimeBaseRef:1582878005565400355 realtimeFrequency:2299774633} D0228 08:20:06.565145 44410 parameters.go:238] Clock(Monotonic): error: -294 ns, adjusted frequency from 2299774562 Hz to 2299774079 Hz D0228 08:20:06.565339 44410 parameters.go:238] Clock(Realtime): error: 159 ns, adjusted frequency from 2299774633 Hz to 2299774964 Hz D0228 08:20:06.565488 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670033788804304 monotonicBaseRef:59000267170 monotonicFrequency:2299774079 realtimeReady:1 realtimeBaseCycles:8670033789256934 realtimeBaseRef:1582878006565327086 realtimeFrequency:2299774964} D0228 08:20:07.565158 44410 parameters.go:238] Clock(Monotonic): error: -23 ns, adjusted frequency from 2299774079 Hz to 2299774680 Hz D0228 08:20:07.565331 44410 parameters.go:238] Clock(Realtime): error: -238 ns, adjusted frequency from 2299774964 Hz to 2299774133 Hz D0228 08:20:07.565489 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670036088614140 monotonicBaseRef:60000282718 monotonicFrequency:2299774680 realtimeReady:1 realtimeBaseCycles:8670036089031784 realtimeBaseRef:1582878007565327036 realtimeFrequency:2299774133} D0228 08:20:08.565119 44410 parameters.go:238] Clock(Monotonic): error: -71 ns, adjusted frequency from 2299774680 Hz to 2299774459 Hz D0228 08:20:08.565305 44410 parameters.go:238] Clock(Realtime): error: 20 ns, adjusted frequency from 2299774133 Hz to 2299774734 Hz D0228 08:20:08.565435 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670038388293623 monotonicBaseRef:61000241323 monotonicFrequency:2299774459 realtimeReady:1 realtimeBaseCycles:8670038388743841 realtimeBaseRef:1582878008565300043 realtimeFrequency:2299774734} D0228 08:20:09.565126 44410 sampler.go:197] Time: Adjusting syscall overhead down to 7000 D0228 08:20:09.565294 44410 parameters.go:238] Clock(Monotonic): error: 24 ns, adjusted frequency from 2299774459 Hz to 2299774683 Hz D0228 08:20:09.565407 44410 parameters.go:238] Clock(Realtime): error: -25 ns, adjusted frequency from 2299774734 Hz to 2299774589 Hz D0228 08:20:09.565510 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670040688093104 monotonicBaseRef:62000252203 monotonicFrequency:2299774683 realtimeReady:1 realtimeBaseCycles:8670040688756168 realtimeBaseRef:1582878009565403354 realtimeFrequency:2299774589} D0228 08:20:10.565387 44410 parameters.go:238] Clock(Monotonic): error: 383 ns, adjusted frequency from 2299774683 Hz to 2299775562 Hz D0228 08:20:10.565578 44410 parameters.go:238] Clock(Realtime): error: 29 ns, adjusted frequency from 2299774589 Hz to 2299774682 Hz D0228 08:20:10.565693 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670042988465131 monotonicBaseRef:63000511943 monotonicFrequency:2299775562 realtimeReady:1 realtimeBaseCycles:8670042988919226 realtimeBaseRef:1582878010565572270 realtimeFrequency:2299774682} D0228 08:20:11.565189 44410 parameters.go:238] Clock(Monotonic): error: -133 ns, adjusted frequency from 2299775562 Hz to 2299774281 Hz D0228 08:20:11.565389 44410 parameters.go:238] Clock(Realtime): error: -36 ns, adjusted frequency from 2299774682 Hz to 2299774558 Hz D0228 08:20:11.565494 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670045287781601 monotonicBaseRef:64000312318 monotonicFrequency:2299774281 realtimeReady:1 realtimeBaseCycles:8670045288262877 realtimeBaseRef:1582878011565384846 realtimeFrequency:2299774558} D0228 08:20:12.565186 44410 parameters.go:238] Clock(Monotonic): error: -239 ns, adjusted frequency from 2299774281 Hz to 2299774164 Hz D0228 08:20:12.565368 44410 parameters.go:238] Clock(Realtime): error: 26 ns, adjusted frequency from 2299774558 Hz to 2299774685 Hz D0228 08:20:12.565477 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670047587552381 monotonicBaseRef:65000310795 monotonicFrequency:2299774164 realtimeReady:1 realtimeBaseCycles:8670047587989209 realtimeBaseRef:1582878012565363876 realtimeFrequency:2299774685} D0228 08:20:13.565295 44410 parameters.go:238] Clock(Monotonic): error: 490 ns, adjusted frequency from 2299774164 Hz to 2299775791 Hz D0228 08:20:13.565526 44410 parameters.go:238] Clock(Realtime): error: 120 ns, adjusted frequency from 2299774685 Hz to 2299774887 Hz D0228 08:20:13.565686 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670049887524813 monotonicBaseRef:66000397006 monotonicFrequency:2299775791 realtimeReady:1 realtimeBaseCycles:8670049888121973 realtimeBaseRef:1582878013565519577 realtimeFrequency:2299774887} D0228 08:20:14.565144 44410 parameters.go:238] Clock(Monotonic): error: -167 ns, adjusted frequency from 2299775791 Hz to 2299774194 Hz D0228 08:20:14.565348 44410 parameters.go:238] Clock(Realtime): error: -106 ns, adjusted frequency from 2299774887 Hz to 2299774378 Hz D0228 08:20:14.565456 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670052186982738 monotonicBaseRef:67000258789 monotonicFrequency:2299774194 realtimeReady:1 realtimeBaseCycles:8670052187491913 realtimeBaseRef:1582878014565343495 realtimeFrequency:2299774378} D0228 08:20:15.565351 44410 parameters.go:238] Clock(Monotonic): error: -163 ns, adjusted frequency from 2299774194 Hz to 2299774274 Hz D0228 08:20:15.565571 44410 parameters.go:238] Clock(Realtime): error: 25 ns, adjusted frequency from 2299774378 Hz to 2299774691 Hz D0228 08:20:15.565727 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670054487252106 monotonicBaseRef:68000474103 monotonicFrequency:2299774274 realtimeReady:1 realtimeBaseCycles:8670054487768502 realtimeBaseRef:1582878015565561869 realtimeFrequency:2299774691} D0228 08:20:16.565133 44410 parameters.go:238] Clock(Monotonic): error: -121 ns, adjusted frequency from 2299774274 Hz to 2299774367 Hz D0228 08:20:16.565341 44410 parameters.go:238] Clock(Realtime): error: 12 ns, adjusted frequency from 2299774691 Hz to 2299774599 Hz D0228 08:20:16.565437 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670056786519407 monotonicBaseRef:69000253658 monotonicFrequency:2299774367 realtimeReady:1 realtimeBaseCycles:8670056787023366 realtimeBaseRef:1582878016565335835 realtimeFrequency:2299774599} D0228 08:20:17.565183 44410 parameters.go:238] Clock(Monotonic): error: -90 ns, adjusted frequency from 2299774367 Hz to 2299774433 Hz D0228 08:20:17.565497 44410 parameters.go:238] Clock(Realtime): error: 74 ns, adjusted frequency from 2299774599 Hz to 2299774734 Hz D0228 08:20:17.565630 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670059086407826 monotonicBaseRef:70000303250 monotonicFrequency:2299774433 realtimeReady:1 realtimeBaseCycles:8670059087154066 realtimeBaseRef:1582878017565490676 realtimeFrequency:2299774734} D0228 08:20:18.565296 44410 parameters.go:238] Clock(Monotonic): error: -1 ns, adjusted frequency from 2299774433 Hz to 2299774629 Hz D0228 08:20:18.565488 44410 parameters.go:238] Clock(Realtime): error: -283 ns, adjusted frequency from 2299774734 Hz to 2299774037 Hz D0228 08:20:18.565612 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670061386452865 monotonicBaseRef:71000420916 monotonicFrequency:2299774629 realtimeReady:1 realtimeBaseCycles:8670061386911535 realtimeBaseRef:1582878018565483168 realtimeFrequency:2299774037} D0228 08:20:19.565167 44410 parameters.go:238] Clock(Monotonic): error: 201 ns, adjusted frequency from 2299774629 Hz to 2299775177 Hz D0228 08:20:19.565612 44410 parameters.go:238] Clock(Realtime): error: 242 ns, adjusted frequency from 2299774037 Hz to 2299775238 Hz D0228 08:20:19.565772 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670063685918375 monotonicBaseRef:72000286503 monotonicFrequency:2299775177 realtimeReady:1 realtimeBaseCycles:8670063686949410 realtimeBaseRef:1582878019565597891 realtimeFrequency:2299775238} D0228 08:20:20.565240 44410 parameters.go:238] Clock(Monotonic): error: -181 ns, adjusted frequency from 2299775177 Hz to 2299774288 Hz D0228 08:20:20.565442 44410 parameters.go:238] Clock(Realtime): error: 8 ns, adjusted frequency from 2299775238 Hz to 2299774624 Hz D0228 08:20:20.565545 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670065985700961 monotonicBaseRef:73000289724 monotonicFrequency:2299774288 realtimeReady:1 realtimeBaseCycles:8670065986355191 realtimeBaseRef:1582878020565437241 realtimeFrequency:2299774624} D0228 08:20:21.565650 44410 parameters.go:238] Clock(Monotonic): error: -10 ns, adjusted frequency from 2299774288 Hz to 2299774617 Hz D0228 08:20:21.565856 44410 parameters.go:238] Clock(Realtime): error: 70 ns, adjusted frequency from 2299774624 Hz to 2299774817 Hz D0228 08:20:21.565980 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670068286583830 monotonicBaseRef:74000771763 monotonicFrequency:2299774617 realtimeReady:1 realtimeBaseCycles:8670068287078392 realtimeBaseRef:1582878021565849706 realtimeFrequency:2299774817} D0228 08:20:22.565153 44410 parameters.go:238] Clock(Monotonic): error: 112 ns, adjusted frequency from 2299774617 Hz to 2299774937 Hz D0228 08:20:22.565447 44410 parameters.go:238] Clock(Realtime): error: 75 ns, adjusted frequency from 2299774817 Hz to 2299774851 Hz D0228 08:20:22.565572 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670070585209563 monotonicBaseRef:75000272199 monotonicFrequency:2299774937 realtimeReady:1 realtimeBaseCycles:8670070585912598 realtimeBaseRef:1582878022565440704 realtimeFrequency:2299774851} D0228 08:20:23.565165 44410 parameters.go:238] Clock(Monotonic): error: 271 ns, adjusted frequency from 2299774937 Hz to 2299775274 Hz D0228 08:20:23.565424 44410 parameters.go:238] Clock(Realtime): error: -376 ns, adjusted frequency from 2299774851 Hz to 2299773805 Hz D0228 08:20:23.565566 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670072884963062 monotonicBaseRef:76000262877 monotonicFrequency:2299775274 realtimeReady:1 realtimeBaseCycles:8670072885631310 realtimeBaseRef:1582878023565416293 realtimeFrequency:2299773805} D0228 08:20:24.565162 44410 parameters.go:238] Clock(Monotonic): error: -457 ns, adjusted frequency from 2299775274 Hz to 2299773570 Hz D0228 08:20:24.565397 44410 parameters.go:238] Clock(Realtime): error: -79 ns, adjusted frequency from 2299773805 Hz to 2299774493 Hz D0228 08:20:24.565496 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670075184783889 monotonicBaseRef:77000282684 monotonicFrequency:2299773570 realtimeReady:1 realtimeBaseCycles:8670075185347764 realtimeBaseRef:1582878024565391355 realtimeFrequency:2299774493} D0228 08:20:25.565169 44410 parameters.go:238] Clock(Monotonic): error: 311 ns, adjusted frequency from 2299773570 Hz to 2299775285 Hz D0228 08:20:25.565368 44410 parameters.go:238] Clock(Realtime): error: 255 ns, adjusted frequency from 2299774493 Hz to 2299775280 Hz D0228 08:20:25.565470 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670077484568805 monotonicBaseRef:78000287617 monotonicFrequency:2299775285 realtimeReady:1 realtimeBaseCycles:8670077485058206 realtimeBaseRef:1582878025565363504 realtimeFrequency:2299775280} D0228 08:20:26.565124 44410 parameters.go:238] Clock(Monotonic): error: -284 ns, adjusted frequency from 2299775285 Hz to 2299773985 Hz D0228 08:20:26.565348 44410 parameters.go:238] Clock(Realtime): error: 96 ns, adjusted frequency from 2299775280 Hz to 2299774862 Hz D0228 08:20:26.565488 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670079784252777 monotonicBaseRef:79000247911 monotonicFrequency:2299773985 realtimeReady:1 realtimeBaseCycles:8670079784778698 realtimeBaseRef:1582878026565339680 realtimeFrequency:2299774862} D0228 08:20:27.565114 44410 parameters.go:238] Clock(Monotonic): error: 434 ns, adjusted frequency from 2299773985 Hz to 2299775580 Hz D0228 08:20:27.565336 44410 parameters.go:238] Clock(Realtime): error: 543 ns, adjusted frequency from 2299774862 Hz to 2299775943 Hz D0228 08:20:27.565442 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670082084006866 monotonicBaseRef:80000239259 monotonicFrequency:2299775580 realtimeReady:1 realtimeBaseCycles:8670082084532328 realtimeBaseRef:1582878027565330447 realtimeFrequency:2299775943} D0228 08:20:28.565156 44410 parameters.go:238] Clock(Monotonic): error: -398 ns, adjusted frequency from 2299775580 Hz to 2299773711 Hz D0228 08:20:28.565389 44410 parameters.go:238] Clock(Realtime): error: -454 ns, adjusted frequency from 2299775943 Hz to 2299773483 Hz D0228 08:20:28.565525 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670084383874940 monotonicBaseRef:81000279477 monotonicFrequency:2299773711 realtimeReady:1 realtimeBaseCycles:8670084384422735 realtimeBaseRef:1582878028565380218 realtimeFrequency:2299773483} D0228 08:20:29.565138 44410 parameters.go:238] Clock(Monotonic): error: 283 ns, adjusted frequency from 2299773711 Hz to 2299775308 Hz D0228 08:20:29.565404 44410 parameters.go:238] Clock(Realtime): error: 17 ns, adjusted frequency from 2299773483 Hz to 2299774669 Hz D0228 08:20:29.565545 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670086683599716 monotonicBaseRef:82000258198 monotonicFrequency:2299775308 realtimeReady:1 realtimeBaseCycles:8670086684231396 realtimeBaseRef:1582878029565395514 realtimeFrequency:2299774669} D0228 08:20:30.565190 44410 parameters.go:238] Clock(Monotonic): error: -291 ns, adjusted frequency from 2299775308 Hz to 2299773961 Hz D0228 08:20:30.565376 44410 parameters.go:238] Clock(Realtime): error: -201 ns, adjusted frequency from 2299774669 Hz to 2299774153 Hz D0228 08:20:30.565484 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670088983494711 monotonicBaseRef:83000310240 monotonicFrequency:2299773961 realtimeReady:1 realtimeBaseCycles:8670088983948942 realtimeBaseRef:1582878030565370675 realtimeFrequency:2299774153} D0228 08:20:31.565120 44410 parameters.go:238] Clock(Monotonic): error: 467 ns, adjusted frequency from 2299773961 Hz to 2299775645 Hz D0228 08:20:31.565332 44410 parameters.go:238] Clock(Realtime): error: -168 ns, adjusted frequency from 2299774153 Hz to 2299774262 Hz D0228 08:20:31.565429 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670091283111444 monotonicBaseRef:84000241873 monotonicFrequency:2299775645 realtimeReady:1 realtimeBaseCycles:8670091283622056 realtimeBaseRef:1582878031565326740 realtimeFrequency:2299774262} D0228 08:20:32.565170 44410 parameters.go:238] Clock(Monotonic): error: -93 ns, adjusted frequency from 2299775645 Hz to 2299774395 Hz D0228 08:20:32.565432 44410 parameters.go:238] Clock(Realtime): error: 226 ns, adjusted frequency from 2299774262 Hz to 2299775103 Hz D0228 08:20:32.565532 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670093583003417 monotonicBaseRef:85000292455 monotonicFrequency:2299774395 realtimeReady:1 realtimeBaseCycles:8670093583623883 realtimeBaseRef:1582878032565425691 realtimeFrequency:2299775103} D0228 08:20:33.565220 44410 parameters.go:238] Clock(Monotonic): error: -339 ns, adjusted frequency from 2299774395 Hz to 2299773859 Hz D0228 08:20:33.565450 44410 parameters.go:238] Clock(Realtime): error: -40 ns, adjusted frequency from 2299775103 Hz to 2299774485 Hz D0228 08:20:33.565576 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670095882847490 monotonicBaseRef:86000322752 monotonicFrequency:2299773859 realtimeReady:1 realtimeBaseCycles:8670095883438843 realtimeBaseRef:1582878033565443021 realtimeFrequency:2299774485} D0228 08:20:33.747710 44410 urpc.go:577] urpc: unmarshal success. D0228 08:20:33.748146 44410 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 08:20:33.748582 44410 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:20:34.565209 44410 parameters.go:238] Clock(Monotonic): error: 242 ns, adjusted frequency from 2299773859 Hz to 2299775272 Hz D0228 08:20:34.565579 44410 parameters.go:238] Clock(Realtime): error: 54 ns, adjusted frequency from 2299774485 Hz to 2299774761 Hz D0228 08:20:34.565681 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670098182608302 monotonicBaseRef:87000317078 monotonicFrequency:2299775272 realtimeReady:1 realtimeBaseCycles:8670098183515372 realtimeBaseRef:1582878034565574357 realtimeFrequency:2299774761} I0228 08:20:35.436898 56573 main.go:296] *************************** I0228 08:20:35.437033 56573 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-2 /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller972449026] I0228 08:20:35.437472 56573 main.go:298] Version release-20200219.0-52-gabf7ebcd38e8 I0228 08:20:35.437551 56573 main.go:299] PID: 56573 I0228 08:20:35.437651 56573 main.go:300] UID: 0, GID: 0 I0228 08:20:35.437755 56573 main.go:301] Configuration: I0228 08:20:35.437855 56573 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 08:20:35.437958 56573 main.go:303] Platform: ptrace I0228 08:20:35.438038 56573 main.go:304] FileAccess: shared, overlay: false I0228 08:20:35.438153 56573 main.go:305] Network: sandbox, logging: false I0228 08:20:35.438285 56573 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 08:20:35.438388 56573 main.go:307] *************************** W0228 08:20:35.438501 56573 main.go:312] Block the TERM signal. This is only safe in tests! D0228 08:20:35.438858 56573 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.444491 56573 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0228 08:20:35.444623 56573 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.444729 56573 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.445173 56573 urpc.go:534] urpc: successfully marshalled 117 bytes. D0228 08:20:35.445743 44410 urpc.go:577] urpc: unmarshal success. D0228 08:20:35.446030 44410 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 08:20:35.446426 44410 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:20:35.446603 56573 urpc.go:577] urpc: unmarshal success. D0228 08:20:35.446734 56573 exec.go:120] Exec arguments: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller972449026 D0228 08:20:35.446829 56573 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0228 08:20:35.446943 56573 container.go:532] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-2", args: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller972449026 D0228 08:20:35.447109 56573 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-2" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.447205 56573 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.447868 56573 urpc.go:534] urpc: successfully marshalled 635 bytes. D0228 08:20:35.448343 44410 urpc.go:577] urpc: unmarshal success. D0228 08:20:35.449569 44410 controller.go:267] containerManager.ExecuteAsync: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller972449026 D0228 08:20:35.449892 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0228 08:20:35.450773 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.450922 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:20:35.451582 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} I0228 08:20:35.452097 44410 kernel.go:795] EXEC: [/syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller972449026] D0228 08:20:35.452756 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0228 08:20:35.453963 44410 transport_flipcall.go:234] recv [channel @0xc000478300] 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: 1582877948, NanoSec: 597301134}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350296}]} D0228 08:20:35.454253 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0228 08:20:35.454737 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.454990 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetattr{FID: 5, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:20:35.455783 44410 transport_flipcall.go:234] recv [channel @0xc000478300] 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: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582836029, NanoSec: 349298839}, MTime: {Sec: 1582836029, NanoSec: 349298839}, CTime: {Sec: 1582877948, NanoSec: 597301134}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:20:35.455987 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalk{FID: 5, NewFID: 6, Names: []} D0228 08:20:35.456595 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rwalk{QIDs: []} D0228 08:20:35.456732 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tlopen{FID: 6, Flags: ReadOnly} D0228 08:20:35.457418 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350296}, IoUnit: 0, File: &{{33}}} D0228 08:20:35.462643 44410 syscalls.go:266] Allocating stack with size of 8388608 bytes D0228 08:20:35.463778 44410 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-2 0}:0xc00030aa20 {ci-gvisor-ptrace-proxy-sandbox-race-2 21}:0xc00068a300] D0228 08:20:35.464123 44410 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:20:35.464274 56573 urpc.go:577] urpc: unmarshal success. D0228 08:20:35.464426 56573 container.go:579] Wait on PID 21 in container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.464556 56573 sandbox.go:743] Waiting for PID 21 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.464651 56573 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:35.464919 56573 urpc.go:534] urpc: successfully marshalled 100 bytes. D0228 08:20:35.465465 44410 urpc.go:577] urpc: unmarshal success. D0228 08:20:35.465727 44410 controller.go:443] containerManager.Wait D0228 08:20:35.467044 44410 task_block.go:223] [ 21] Interrupt queued D0228 08:20:35.565152 44410 parameters.go:238] Clock(Monotonic): error: 95 ns, adjusted frequency from 2299775272 Hz to 2299774806 Hz D0228 08:20:35.565330 44410 parameters.go:238] Clock(Realtime): error: 323 ns, adjusted frequency from 2299774761 Hz to 2299775471 Hz D0228 08:20:35.565470 44410 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8670100482289112 monotonicBaseRef:88000276003 monotonicFrequency:2299774806 realtimeReady:1 realtimeBaseCycles:8670100482714584 realtimeBaseRef:1582878035565324093 realtimeFrequency:2299775471} D0228 08:20:35.662092 44410 task_block.go:223] [ 22] Interrupt queued D0228 08:20:35.662945 44410 task_block.go:223] [ 23] Interrupt queued D0228 08:20:35.664098 44410 task_block.go:223] [ 24] Interrupt queued D0228 08:20:35.669859 44410 task_block.go:223] [ 25] Interrupt queued D0228 08:20:35.682166 44410 task_block.go:223] [ 26] Interrupt queued D0228 08:20:35.688811 44410 task_block.go:223] [ 27] Interrupt queued D0228 08:20:35.715005 44410 task_block.go:223] [ 28] Interrupt queued D0228 08:20:35.736626 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0228 08:20:35.737301 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.737457 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:20:35.737860 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.758703 44410 task_block.go:223] [ 29] Interrupt queued D0228 08:20:35.780723 44410 task_block.go:223] [ 30] Interrupt queued D0228 08:20:35.786393 44410 task_block.go:223] [ 31] Interrupt queued D0228 08:20:35.793634 44410 task_block.go:223] [ 32] Interrupt queued D0228 08:20:35.827716 44410 task_block.go:223] [ 33] Interrupt queued D0228 08:20:35.835650 44410 task_block.go:223] [ 34] Interrupt queued D0228 08:20:35.864824 44410 task_block.go:223] [ 35] Interrupt queued D0228 08:20:35.870424 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller972449026]} D0228 08:20:35.870609 44410 task_block.go:223] [ 36] Interrupt queued D0228 08:20:35.871716 44410 transport_flipcall.go:234] recv [channel @0xc000478300] 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: 199, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582878035, NanoSec: 405806847}, MTime: {Sec: 1582878035, NanoSec: 405806847}, CTime: {Sec: 1582878035, NanoSec: 405806847}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350236}]} D0228 08:20:35.872024 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller972449026, Size: 1} D0228 08:20:35.872548 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.872856 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetattr{FID: 7, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:20:35.873735 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350236}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 199, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582878035, NanoSec: 405806847}, MTime: {Sec: 1582878035, NanoSec: 405806847}, CTime: {Sec: 1582878035, NanoSec: 405806847}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:20:35.873978 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalk{FID: 7, NewFID: 8, Names: []} D0228 08:20:35.874591 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rwalk{QIDs: []} D0228 08:20:35.874785 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tlopen{FID: 8, Flags: ReadOnly} D0228 08:20:35.875657 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350236}, IoUnit: 0, File: &{{27}}} D0228 08:20:35.877315 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetattr{FID: 8, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:20:35.878199 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350236}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 199, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582878035, NanoSec: 405806847}, MTime: {Sec: 1582878035, NanoSec: 405806847}, CTime: {Sec: 1582878035, NanoSec: 405806847}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 08:20:35 parsed 1 programs D0228 08:20:35.892209 44410 task_stop.go:118] [ 35] Entering internal stop (*kernel.vforkStop)(nil) D0228 08:20:35.892828 44410 task_block.go:223] [ 37] Interrupt queued D0228 08:20:35.899447 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0228 08:20:35.900941 44410 transport_flipcall.go:234] recv [channel @0xc000478300] 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: 1582877948, NanoSec: 601301526}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350302}]} D0228 08:20:35.901221 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0228 08:20:35.901667 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.901919 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:20:35.902649 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350302}, 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: 1582877948, NanoSec: 601301526}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:20:35.902769 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalk{FID: 9, NewFID: 10, Names: []} D0228 08:20:35.903351 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rwalk{QIDs: []} D0228 08:20:35.903535 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tlopen{FID: 10, Flags: ReadOnly} D0228 08:20:35.904446 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350302}, IoUnit: 0, File: &{{28}}} D0228 08:20:35.905505 44410 syscalls.go:266] [ 37] Allocating stack with size of 8388608 bytes D0228 08:20:35.906233 44410 task_stop.go:137] [ 35] Leaving internal stop (*kernel.vforkStop)(nil) D0228 08:20:35.927307 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 08:20:35.927922 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.928162 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:20:35.928523 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.930564 44410 task_exit.go:221] [ 37] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 08:20:35.932028 44410 task_exit.go:221] [ 37] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 08:20:35.932166 44410 task_signals.go:446] [ 21] Notified of signal 17 D0228 08:20:35.932286 44410 task_block.go:223] [ 21] Interrupt queued D0228 08:20:35.932335 44410 task_block.go:223] [ 21] Interrupt queued D0228 08:20:35.932575 44410 task_signals.go:176] [ 21] Not restarting syscall 202 after errno 516: interrupted by signal 17 D0228 08:20:35.932795 44410 task_signals.go:220] [ 21] Signal 17: delivering to handler D0228 08:20:35.933193 44410 task_exit.go:221] [ 37] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 08:20:35.934910 44410 task_block.go:223] [ 38] Interrupt queued D0228 08:20:35.937952 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 08:20:35.939213 44410 transport_flipcall.go:234] recv [channel @0xc000478300] 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: 1582877948, NanoSec: 601301526}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350302}]} D0228 08:20:35.939372 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tclunk{FID: 11} D0228 08:20:35.939894 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rclunk{} D0228 08:20:35.940107 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:20:35.940973 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350302}, 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: 1582877948, NanoSec: 601301526}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 08:20:35 executed programs: 0 D0228 08:20:35.949189 44410 task_stop.go:118] [ 24] Entering internal stop (*kernel.vforkStop)(nil) D0228 08:20:35.949931 44410 task_block.go:223] [ 39] Interrupt queued D0228 08:20:35.955367 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 08:20:35.956850 44410 transport_flipcall.go:234] recv [channel @0xc000478300] 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: 1582877948, NanoSec: 601301526}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350302}]} D0228 08:20:35.957057 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tclunk{FID: 11} D0228 08:20:35.958146 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rclunk{} D0228 08:20:35.958366 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:20:35.959121 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350302}, 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: 1582877948, NanoSec: 601301526}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:20:35.960140 44410 syscalls.go:266] [ 39] Allocating stack with size of 8388608 bytes D0228 08:20:35.960769 44410 task_stop.go:137] [ 24] Leaving internal stop (*kernel.vforkStop)(nil) D0228 08:20:35.966578 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 08:20:35.967191 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.967330 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:20:35.967753 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.979189 44410 task_block.go:223] [ 40] Interrupt queued D0228 08:20:35.982772 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.983327 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.983491 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.983978 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.984370 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.984829 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.985031 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.985543 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.986170 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.986711 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.986862 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.987373 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.987722 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.988326 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.988481 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.989055 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.989389 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.989956 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.990107 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.990558 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.991022 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.991585 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.991767 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.992319 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.992597 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.993104 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.993249 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.993783 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.994086 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.994537 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.994666 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.995053 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:35.995559 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:35.996110 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:35.996247 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:35.996628 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.022530 44410 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 08:20:36.022654 44410 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0228 08:20:36.022728 44410 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0228 08:20:36.022789 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.022872 44410 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 08:20:36.023378 44410 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 08:20:36.023436 44410 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0228 08:20:36.023505 44410 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0228 08:20:36.023561 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.023615 44410 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 08:20:36.024081 44410 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 08:20:36.024141 44410 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 08:20:36.024219 44410 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 08:20:36.024284 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.024368 44410 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 08:20:36.024787 44410 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 08:20:36.024880 44410 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 08:20:36.025358 44410 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 08:20:36.025434 44410 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 08:20:36.025506 44410 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 08:20:36.025586 44410 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 08:20:36.025657 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.025722 44410 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 08:20:36.026113 44410 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 08:20:36.026186 44410 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0228 08:20:36.026241 44410 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0228 08:20:36.026301 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.026367 44410 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 08:20:36.026760 44410 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 08:20:36.026818 44410 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 08:20:36.026908 44410 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 08:20:36.026963 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.027050 44410 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 08:20:36.027460 44410 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 08:20:36.027542 44410 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0228 08:20:36.027614 44410 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0228 08:20:36.027693 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.027751 44410 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 08:20:36.028205 44410 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0228 08:20:36.028269 44410 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 08:20:36.028731 44410 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 08:20:36.028786 44410 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 08:20:36.028861 44410 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 08:20:36.028916 44410 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 08:20:36.028982 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.029060 44410 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 08:20:36.029473 44410 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 08:20:36.029674 44410 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0228 08:20:36.029726 44410 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0228 08:20:36.029816 44410 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:20:36.029895 44410 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 08:20:36.030335 44410 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 08:20:36.030431 44410 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 08:20:36.030905 44410 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 08:20:36.225552 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.226307 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.226499 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.226994 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.227485 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.227954 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.228100 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.228574 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.228831 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.229446 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.229602 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.230329 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.230573 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.231075 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.231198 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.231677 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.232020 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.232584 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.232740 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.233162 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.233456 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.233987 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.234138 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.234654 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.234932 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.235570 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.235873 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.236517 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.236966 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.237473 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.237618 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.238067 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.238347 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.238831 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.239036 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.239575 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.239874 44410 transport_flipcall.go:127] send [channel @0xc000478300] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:20:36.240376 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 2} D0228 08:20:36.240524 44410 transport_flipcall.go:127] send [channel @0xc000478300] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:20:36.241067 44410 transport_flipcall.go:234] recv [channel @0xc000478300] Rlerror{Error: 95} D0228 08:20:36.254512 44410 task_block.go:223] [ 41] Interrupt queued D0228 08:20:36.264924 44410 task_block.go:223] [ 42] Interrupt queued D0228 08:20:36.318182 44410 task_block.go:223] [ 43] Interrupt queued ================== WARNING: DATA RACE Read at 0x00c0006e4470 by goroutine 367: gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).windowCrossedACKThreshold() pkg/tcpip/transport/tcp/endpoint.go:1312 +0x9e gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).SetSockOptInt() pkg/tcpip/transport/tcp/endpoint.go:1394 +0x408 gvisor.dev/gvisor/pkg/sentry/socket/netstack.setSockOptSocket() pkg/sentry/socket/netstack/netstack.go:1575 +0x84c gvisor.dev/gvisor/pkg/sentry/socket/netstack.SetSockOpt() pkg/sentry/socket/netstack/netstack.go:1535 +0x1ad gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).SetSockOpt() pkg/sentry/socket/netstack/netstack.go:1527 +0x69d gvisor.dev/gvisor/pkg/sentry/syscalls/linux.SetSockOpt() pkg/sentry/syscalls/linux/sys_socket.go:541 +0x303 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 DIAGNOSIS: I0228 08:20:36.350933 56812 main.go:296] *************************** I0228 08:20:36.351100 56812 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-2] I0228 08:20:36.351281 56812 main.go:298] Version release-20200219.0-52-gabf7ebcd38e8 I0228 08:20:36.351363 56812 main.go:299] PID: 56812 I0228 08:20:36.351439 56812 main.go:300] UID: 0, GID: 0 I0228 08:20:36.351528 56812 main.go:301] Configuration: I0228 08:20:36.351621 56812 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 08:20:36.351719 56812 main.go:303] Platform: ptrace I0228 08:20:36.351811 56812 main.go:304] FileAccess: shared, overlay: false I0228 08:20:36.351920 56812 main.go:305] Network: sandbox, logging: false I0228 08:20:36.352035 56812 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 08:20:36.352141 56812 main.go:307] *************************** W0228 08:20:36.352219 56812 main.go:312] Block the TERM signal. This is only safe in tests! D0228 08:20:36.352392 56812 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.358817 56812 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0228 08:20:36.359011 56812 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.359116 56812 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.359576 56812 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 08:20:36.437244 56812 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2", PID: 44410 I0228 08:20:36.437397 56812 debug.go:131] Retrieving sandbox stacks D0228 08:20:36.437510 56812 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.437628 56812 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" W0228 08:20:36.437900 56812 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 44410: connection refused retrieving stacks: connecting to control server at PID 44410: connection refused W0228 08:20:36.438288 56812 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-2"]: exit status 128 I0228 08:20:36.350933 56812 main.go:296] *************************** I0228 08:20:36.351100 56812 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-2] I0228 08:20:36.351281 56812 main.go:298] Version release-20200219.0-52-gabf7ebcd38e8 I0228 08:20:36.351363 56812 main.go:299] PID: 56812 I0228 08:20:36.351439 56812 main.go:300] UID: 0, GID: 0 I0228 08:20:36.351528 56812 main.go:301] Configuration: I0228 08:20:36.351621 56812 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 08:20:36.351719 56812 main.go:303] Platform: ptrace I0228 08:20:36.351811 56812 main.go:304] FileAccess: shared, overlay: false I0228 08:20:36.351920 56812 main.go:305] Network: sandbox, logging: false I0228 08:20:36.352035 56812 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 08:20:36.352141 56812 main.go:307] *************************** W0228 08:20:36.352219 56812 main.go:312] Block the TERM signal. This is only safe in tests! D0228 08:20:36.352392 56812 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.358817 56812 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0228 08:20:36.359011 56812 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.359116 56812 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.359576 56812 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 08:20:36.437244 56812 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2", PID: 44410 I0228 08:20:36.437397 56812 debug.go:131] Retrieving sandbox stacks D0228 08:20:36.437510 56812 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.437628 56812 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" W0228 08:20:36.437900 56812 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 44410: connection refused retrieving stacks: connecting to control server at PID 44410: connection refused W0228 08:20:36.438288 56812 main.go:329] Failure to execute command, err: 1 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous write at 0x00c0006e4470 by goroutine 342: gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*handshake).execute() pkg/tcpip/transport/tcp/connect.go:533 +0x631 gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).protocolMainLoop() pkg/tcpip/transport/tcp/connect.go:1280 +0xfc6 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 Goroutine 342 (running) created at: gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).connect() pkg/tcpip/transport/tcp/endpoint.go:2044 +0xf2d gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).Connect() pkg/tcpip/transport/tcp/endpoint.go:1873 +0x8c 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 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 08:20:36.428328 56573 error.go:48] FATAL ERROR: waiting on pid 21: waiting on PID 21 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 21: waiting on PID 21 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2": urpc method "containerManager.WaitPID" failed: EOF W0228 08:20:36.428628 56573 main.go:329] Failure to execute command, err: 1 W0228 08:20:36.437180 44402 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-2" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0228 08:20:36.437919 44402 container.go:713] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.438107 44402 container.go:800] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.438225 44402 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-2" by destroying sandbox D0228 08:20:36.438351 44402 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 08:20:36.438442 44402 container.go:814] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-2", PID: 44409 I0228 08:20:36.540044 44402 main.go:320] Exiting with status: 16896