I0228 08:00:40.080941 5497 calibrated_clock.go:79] CalibratedClock(Monotonic): ready I0228 08:00:40.081228 5497 calibrated_clock.go:79] CalibratedClock(Realtime): ready D0228 08:00:40.081304 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667351137954314 monotonicBaseRef:1000281746 monotonicFrequency:2299774214 realtimeReady:1 realtimeBaseCycles:8667351138718462 realtimeBaseRef:1582876840081222542 realtimeFrequency:2299774223} D0228 08:00:41.080994 5497 parameters.go:238] Clock(Monotonic): error: 115 ns, adjusted frequency from 2299774214 Hz to 2299774668 Hz D0228 08:00:41.081202 5497 parameters.go:238] Clock(Realtime): error: 115 ns, adjusted frequency from 2299774223 Hz to 2299774663 Hz D0228 08:00:41.081324 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667353437904972 monotonicBaseRef:2000358468 monotonicFrequency:2299774668 realtimeReady:1 realtimeBaseCycles:8667353438430209 realtimeBaseRef:1582876841081195375 realtimeFrequency:2299774663} D0228 08:00:42.080916 5497 parameters.go:238] Clock(Monotonic): error: 131 ns, adjusted frequency from 2299774668 Hz to 2299774788 Hz D0228 08:00:42.081080 5497 parameters.go:238] Clock(Realtime): error: 107 ns, adjusted frequency from 2299774663 Hz to 2299774724 Hz D0228 08:00:42.081168 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667355737536261 monotonicBaseRef:3000296123 monotonicFrequency:2299774788 realtimeReady:1 realtimeBaseCycles:8667355737933080 realtimeBaseRef:1582876842081077192 realtimeFrequency:2299774724} D0228 08:00:43.080940 5497 parameters.go:238] Clock(Monotonic): error: -7 ns, adjusted frequency from 2299774788 Hz to 2299774478 Hz D0228 08:00:43.081160 5497 parameters.go:238] Clock(Realtime): error: 173 ns, adjusted frequency from 2299774724 Hz to 2299774913 Hz D0228 08:00:43.081272 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667358037317361 monotonicBaseRef:4000298867 monotonicFrequency:2299774478 realtimeReady:1 realtimeBaseCycles:8667358037887322 realtimeBaseRef:1582876843081155250 realtimeFrequency:2299774913} D0228 08:00:44.080874 5497 parameters.go:238] Clock(Monotonic): error: 62 ns, adjusted frequency from 2299774478 Hz to 2299774666 Hz D0228 08:00:44.081068 5497 parameters.go:238] Clock(Realtime): error: -99 ns, adjusted frequency from 2299774913 Hz to 2299774296 Hz D0228 08:00:44.081173 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667360336983591 monotonicBaseRef:5000251798 monotonicFrequency:2299774666 realtimeReady:1 realtimeBaseCycles:8667360337454775 realtimeBaseRef:1582876844081065041 realtimeFrequency:2299774296} D0228 08:00:45.081648 5497 parameters.go:238] Clock(Monotonic): error: 21 ns, adjusted frequency from 2299774666 Hz to 2299774566 Hz D0228 08:00:45.081845 5497 parameters.go:238] Clock(Realtime): error: 172 ns, adjusted frequency from 2299774296 Hz to 2299774946 Hz D0228 08:00:45.081960 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667362638486551 monotonicBaseRef:6001003303 monotonicFrequency:2299774566 realtimeReady:1 realtimeBaseCycles:8667362639007618 realtimeBaseRef:1582876845081838398 realtimeFrequency:2299774946} D0228 08:00:46.080987 5497 parameters.go:238] Clock(Monotonic): error: 76 ns, adjusted frequency from 2299774566 Hz to 2299774720 Hz D0228 08:00:46.081226 5497 parameters.go:238] Clock(Realtime): error: -131 ns, adjusted frequency from 2299774946 Hz to 2299774220 Hz D0228 08:00:46.081355 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667364936782105 monotonicBaseRef:7000360191 monotonicFrequency:2299774720 realtimeReady:1 realtimeBaseCycles:8667364937364479 realtimeBaseRef:1582876846081221778 realtimeFrequency:2299774220} D0228 08:00:47.080951 5497 parameters.go:238] Clock(Monotonic): error: 69 ns, adjusted frequency from 2299774720 Hz to 2299774716 Hz D0228 08:00:47.081181 5497 parameters.go:238] Clock(Realtime): error: 146 ns, adjusted frequency from 2299774220 Hz to 2299774897 Hz D0228 08:00:47.081291 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667367236378883 monotonicBaseRef:8000282817 monotonicFrequency:2299774716 realtimeReady:1 realtimeBaseCycles:8667367237032682 realtimeBaseRef:1582876847081175679 realtimeFrequency:2299774897} D0228 08:00:48.080966 5497 parameters.go:238] Clock(Monotonic): error: -39 ns, adjusted frequency from 2299774716 Hz to 2299774470 Hz D0228 08:00:48.081134 5497 parameters.go:238] Clock(Realtime): error: -88 ns, adjusted frequency from 2299774897 Hz to 2299774354 Hz D0228 08:00:48.081221 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667369536291071 monotonicBaseRef:9000342593 monotonicFrequency:2299774470 realtimeReady:1 realtimeBaseCycles:8667369536703329 realtimeBaseRef:1582876848081130348 realtimeFrequency:2299774354} D0228 08:00:49.080935 5497 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0228 08:00:49.081155 5497 parameters.go:238] Clock(Monotonic): error: 634 ns, adjusted frequency from 2299774470 Hz to 2299776058 Hz D0228 08:00:49.081349 5497 parameters.go:238] Clock(Realtime): error: 178 ns, adjusted frequency from 2299774354 Hz to 2299775018 Hz D0228 08:00:49.081469 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667371836454668 monotonicBaseRef:10000511795 monotonicFrequency:2299776058 realtimeReady:1 realtimeBaseCycles:8667371836968936 realtimeBaseRef:1582876849081343957 realtimeFrequency:2299775018} D0228 08:00:50.080893 5497 parameters.go:238] Clock(Monotonic): error: -68 ns, adjusted frequency from 2299776058 Hz to 2299774346 Hz D0228 08:00:50.081114 5497 parameters.go:238] Clock(Realtime): error: -101 ns, adjusted frequency from 2299775018 Hz to 2299774360 Hz D0228 08:00:50.081217 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667374135620717 monotonicBaseRef:11000246547 monotonicFrequency:2299774346 realtimeReady:1 realtimeBaseCycles:8667374136204795 realtimeBaseRef:1582876850081109517 realtimeFrequency:2299774360} D0228 08:00:51.081485 5497 parameters.go:238] Clock(Monotonic): error: -471 ns, adjusted frequency from 2299774346 Hz to 2299773515 Hz D0228 08:00:51.081685 5497 parameters.go:238] Clock(Realtime): error: -47 ns, adjusted frequency from 2299774360 Hz to 2299774488 Hz D0228 08:00:51.081802 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667376436788710 monotonicBaseRef:12000852539 monotonicFrequency:2299773515 realtimeReady:1 realtimeBaseCycles:8667376437282331 realtimeBaseRef:1582876851081676170 realtimeFrequency:2299774488} D0228 08:00:52.080917 5497 parameters.go:238] Clock(Monotonic): error: -25 ns, adjusted frequency from 2299773515 Hz to 2299774549 Hz D0228 08:00:52.081130 5497 parameters.go:238] Clock(Realtime): error: 53 ns, adjusted frequency from 2299774488 Hz to 2299774722 Hz D0228 08:00:52.081218 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667378735267887 monotonicBaseRef:13000289727 monotonicFrequency:2299774549 realtimeReady:1 realtimeBaseCycles:8667378735788809 realtimeBaseRef:1582876852081124807 realtimeFrequency:2299774722} D0228 08:00:53.081007 5497 parameters.go:238] Clock(Monotonic): error: -7 ns, adjusted frequency from 2299774549 Hz to 2299774574 Hz D0228 08:00:53.081227 5497 parameters.go:238] Clock(Realtime): error: -34 ns, adjusted frequency from 2299774722 Hz to 2299774524 Hz D0228 08:00:53.081377 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667381035247852 monotonicBaseRef:14000379047 monotonicFrequency:2299774574 realtimeReady:1 realtimeBaseCycles:8667381035784835 realtimeBaseRef:1582876853081221035 realtimeFrequency:2299774524} D0228 08:00:54.080974 5497 parameters.go:238] Clock(Monotonic): error: 276 ns, adjusted frequency from 2299774574 Hz to 2299775252 Hz D0228 08:00:54.081183 5497 parameters.go:238] Clock(Realtime): error: -16 ns, adjusted frequency from 2299774524 Hz to 2299774551 Hz D0228 08:00:54.081315 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667383334947409 monotonicBaseRef:15000346427 monotonicFrequency:2299775252 realtimeReady:1 realtimeBaseCycles:8667383335460517 realtimeBaseRef:1582876854081178056 realtimeFrequency:2299774551} D0228 08:00:55.081090 5497 parameters.go:238] Clock(Monotonic): error: -57 ns, adjusted frequency from 2299775252 Hz to 2299774480 Hz D0228 08:00:55.081335 5497 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0228 08:00:55.081530 5497 parameters.go:238] Clock(Realtime): error: 480 ns, adjusted frequency from 2299774551 Hz to 2299775666 Hz D0228 08:00:55.081671 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667385634894848 monotonicBaseRef:16000421298 monotonicFrequency:2299774480 realtimeReady:1 realtimeBaseCycles:8667385636014270 realtimeBaseRef:1582876855081516872 realtimeFrequency:2299775666} D0228 08:00:56.080898 5497 parameters.go:238] Clock(Monotonic): error: -238 ns, adjusted frequency from 2299774480 Hz to 2299774048 Hz D0228 08:00:56.081123 5497 parameters.go:238] Clock(Realtime): error: -166 ns, adjusted frequency from 2299775666 Hz to 2299774152 Hz D0228 08:00:56.081468 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667387934322721 monotonicBaseRef:17000270584 monotonicFrequency:2299774048 realtimeReady:1 realtimeBaseCycles:8667387934862214 realtimeBaseRef:1582876856081113475 realtimeFrequency:2299774152} D0228 08:00:56.781191 5497 urpc.go:577] urpc: unmarshal success. D0228 08:00:56.781472 5497 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0228 08:00:56.781722 5497 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:00:57.081511 5497 parameters.go:238] Clock(Monotonic): error: 17 ns, adjusted frequency from 2299774048 Hz to 2299774636 Hz D0228 08:00:57.081720 5497 parameters.go:238] Clock(Realtime): error: 905 ns, adjusted frequency from 2299774152 Hz to 2299776748 Hz D0228 08:00:57.081808 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667390235509867 monotonicBaseRef:18000885034 monotonicFrequency:2299774636 realtimeReady:1 realtimeBaseCycles:8667390236016855 realtimeBaseRef:1582876857081713746 realtimeFrequency:2299776748} D0228 08:00:58.080843 5497 parameters.go:238] Clock(Monotonic): error: 462 ns, adjusted frequency from 2299774636 Hz to 2299775614 Hz D0228 08:00:58.081026 5497 parameters.go:238] Clock(Realtime): error: -922 ns, adjusted frequency from 2299776748 Hz to 2299772450 Hz D0228 08:00:58.081138 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667392533755015 monotonicBaseRef:19000219974 monotonicFrequency:2299775614 realtimeReady:1 realtimeBaseCycles:8667392534200525 realtimeBaseRef:1582876858081021036 realtimeFrequency:2299772450} D0228 08:00:59.080997 5497 parameters.go:238] Clock(Monotonic): error: -338 ns, adjusted frequency from 2299775614 Hz to 2299773872 Hz D0228 08:00:59.081182 5497 parameters.go:238] Clock(Realtime): error: -52 ns, adjusted frequency from 2299772450 Hz to 2299774392 Hz D0228 08:00:59.081305 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667394833874562 monotonicBaseRef:20000369524 monotonicFrequency:2299773872 realtimeReady:1 realtimeBaseCycles:8667394834332735 realtimeBaseRef:1582876859081177468 realtimeFrequency:2299774392} D0228 08:01:00.080841 5497 parameters.go:238] Clock(Monotonic): error: 225 ns, adjusted frequency from 2299773872 Hz to 2299775055 Hz D0228 08:01:00.081058 5497 parameters.go:238] Clock(Realtime): error: 579 ns, adjusted frequency from 2299774392 Hz to 2299775939 Hz D0228 08:01:00.081210 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667397133288543 monotonicBaseRef:21000213034 monotonicFrequency:2299775055 realtimeReady:1 realtimeBaseCycles:8667397133817263 realtimeBaseRef:1582876860081051427 realtimeFrequency:2299775939} D0228 08:01:01.080962 5497 parameters.go:238] Clock(Monotonic): error: 176 ns, adjusted frequency from 2299775055 Hz to 2299774925 Hz D0228 08:01:01.081264 5497 parameters.go:238] Clock(Realtime): error: -515 ns, adjusted frequency from 2299775939 Hz to 2299773420 Hz D0228 08:01:01.081419 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667399433338059 monotonicBaseRef:22000332376 monotonicFrequency:2299774925 realtimeReady:1 realtimeBaseCycles:8667399434054186 realtimeBaseRef:1582876861081251874 realtimeFrequency:2299773420} D0228 08:01:02.080920 5497 parameters.go:238] Clock(Monotonic): error: -84 ns, adjusted frequency from 2299774925 Hz to 2299774278 Hz D0228 08:01:02.081135 5497 parameters.go:238] Clock(Realtime): error: 304 ns, adjusted frequency from 2299773420 Hz to 2299775294 Hz D0228 08:01:02.081284 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667401733027314 monotonicBaseRef:23000295124 monotonicFrequency:2299774278 realtimeReady:1 realtimeBaseCycles:8667401733544142 realtimeBaseRef:1582876862081128616 realtimeFrequency:2299775294} D0228 08:01:03.080945 5497 parameters.go:238] Clock(Monotonic): error: -6 ns, adjusted frequency from 2299774278 Hz to 2299774469 Hz D0228 08:01:03.081141 5497 parameters.go:238] Clock(Realtime): error: -256 ns, adjusted frequency from 2299775294 Hz to 2299773939 Hz D0228 08:01:03.081279 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667404032860177 monotonicBaseRef:24000320598 monotonicFrequency:2299774469 realtimeReady:1 realtimeBaseCycles:8667404033334745 realtimeBaseRef:1582876863081135272 realtimeFrequency:2299773939} D0228 08:01:04.080922 5497 parameters.go:238] Clock(Monotonic): error: -288 ns, adjusted frequency from 2299774469 Hz to 2299773925 Hz D0228 08:01:04.081149 5497 parameters.go:238] Clock(Realtime): error: 37 ns, adjusted frequency from 2299773939 Hz to 2299774709 Hz D0228 08:01:04.081302 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667406332577701 monotonicBaseRef:25000295836 monotonicFrequency:2299773925 realtimeReady:1 realtimeBaseCycles:8667406333120625 realtimeBaseRef:1582876864081140464 realtimeFrequency:2299774709} D0228 08:01:05.081057 5497 parameters.go:238] Clock(Monotonic): error: 240 ns, adjusted frequency from 2299773925 Hz to 2299775151 Hz D0228 08:01:05.081241 5497 parameters.go:238] Clock(Realtime): error: -293 ns, adjusted frequency from 2299774709 Hz to 2299773985 Hz D0228 08:01:05.081355 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667408632580711 monotonicBaseRef:26000395447 monotonicFrequency:2299775151 realtimeReady:1 realtimeBaseCycles:8667408633111679 realtimeBaseRef:1582876865081234536 realtimeFrequency:2299773985} D0228 08:01:06.080918 5497 parameters.go:238] Clock(Monotonic): error: 468 ns, adjusted frequency from 2299775151 Hz to 2299775609 Hz D0228 08:01:06.081150 5497 parameters.go:238] Clock(Realtime): error: 229 ns, adjusted frequency from 2299773985 Hz to 2299774975 Hz D0228 08:01:06.081251 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667410932118514 monotonicBaseRef:27000292242 monotonicFrequency:2299775609 realtimeReady:1 realtimeBaseCycles:8667410932679613 realtimeBaseRef:1582876866081144939 realtimeFrequency:2299774975} D0228 08:01:07.080939 5497 parameters.go:238] Clock(Monotonic): error: -355 ns, adjusted frequency from 2299775609 Hz to 2299773698 Hz D0228 08:01:07.081162 5497 parameters.go:238] Clock(Realtime): error: 53 ns, adjusted frequency from 2299774975 Hz to 2299774732 Hz D0228 08:01:07.081299 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667413231928934 monotonicBaseRef:28000307378 monotonicFrequency:2299773698 realtimeReady:1 realtimeBaseCycles:8667413232474393 realtimeBaseRef:1582876867081153550 realtimeFrequency:2299774732} D0228 08:01:08.080888 5497 parameters.go:238] Clock(Monotonic): error: -237 ns, adjusted frequency from 2299773698 Hz to 2299774090 Hz D0228 08:01:08.081114 5497 parameters.go:238] Clock(Realtime): error: 104 ns, adjusted frequency from 2299774732 Hz to 2299774904 Hz D0228 08:01:08.081322 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667415531602852 monotonicBaseRef:29000263991 monotonicFrequency:2299774090 realtimeReady:1 realtimeBaseCycles:8667415532145762 realtimeBaseRef:1582876868081108605 realtimeFrequency:2299774904} D0228 08:01:09.080986 5497 parameters.go:238] Clock(Monotonic): error: -53 ns, adjusted frequency from 2299774090 Hz to 2299774528 Hz D0228 08:01:09.081157 5497 parameters.go:238] Clock(Realtime): error: -199 ns, adjusted frequency from 2299774904 Hz to 2299774101 Hz D0228 08:01:09.081271 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667417831604517 monotonicBaseRef:30000362946 monotonicFrequency:2299774528 realtimeReady:1 realtimeBaseCycles:8667417832022763 realtimeBaseRef:1582876869081152999 realtimeFrequency:2299774101} D0228 08:01:10.080877 5497 parameters.go:238] Clock(Monotonic): error: 692 ns, adjusted frequency from 2299774528 Hz to 2299776202 Hz D0228 08:01:10.081071 5497 parameters.go:238] Clock(Realtime): error: 189 ns, adjusted frequency from 2299774101 Hz to 2299774989 Hz D0228 08:01:10.081282 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667420131128031 monotonicBaseRef:31000253798 monotonicFrequency:2299776202 realtimeReady:1 realtimeBaseCycles:8667420131597417 realtimeBaseRef:1582876870081066274 realtimeFrequency:2299774989} D0228 08:01:11.081003 5497 parameters.go:238] Clock(Monotonic): error: -686 ns, adjusted frequency from 2299776202 Hz to 2299773164 Hz D0228 08:01:11.081202 5497 parameters.go:238] Clock(Realtime): error: -117 ns, adjusted frequency from 2299774989 Hz to 2299774289 Hz D0228 08:01:11.081323 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667422431192087 monotonicBaseRef:32000378964 monotonicFrequency:2299773164 realtimeReady:1 realtimeBaseCycles:8667422431673820 realtimeBaseRef:1582876871081197336 realtimeFrequency:2299774289} D0228 08:01:12.080901 5497 parameters.go:238] Clock(Monotonic): error: 91 ns, adjusted frequency from 2299773164 Hz to 2299774930 Hz D0228 08:01:12.081138 5497 parameters.go:238] Clock(Realtime): error: 336 ns, adjusted frequency from 2299774289 Hz to 2299775433 Hz D0228 08:01:12.081316 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667424730710670 monotonicBaseRef:33000268265 monotonicFrequency:2299774930 realtimeReady:1 realtimeBaseCycles:8667424731296574 realtimeBaseRef:1582876872081131444 realtimeFrequency:2299775433} D0228 08:01:13.080988 5497 parameters.go:238] Clock(Monotonic): error: 124 ns, adjusted frequency from 2299774930 Hz to 2299774908 Hz D0228 08:01:13.081240 5497 parameters.go:238] Clock(Realtime): error: -21 ns, adjusted frequency from 2299775433 Hz to 2299774549 Hz D0228 08:01:13.081393 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667427030701965 monotonicBaseRef:34000362345 monotonicFrequency:2299774908 realtimeReady:1 realtimeBaseCycles:8667427031305640 realtimeBaseRef:1582876873081233033 realtimeFrequency:2299774549} D0228 08:01:14.081068 5497 parameters.go:238] Clock(Monotonic): error: 32 ns, adjusted frequency from 2299774908 Hz to 2299774614 Hz D0228 08:01:14.081272 5497 parameters.go:238] Clock(Realtime): error: -436 ns, adjusted frequency from 2299774549 Hz to 2299773557 Hz D0228 08:01:14.081438 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667429330658647 monotonicBaseRef:35000441384 monotonicFrequency:2299774614 realtimeReady:1 realtimeBaseCycles:8667429331157227 realtimeBaseRef:1582876874081266531 realtimeFrequency:2299773557} D0228 08:01:15.080987 5497 parameters.go:238] Clock(Monotonic): error: -41 ns, adjusted frequency from 2299774614 Hz to 2299774453 Hz D0228 08:01:15.081189 5497 parameters.go:238] Clock(Realtime): error: 15 ns, adjusted frequency from 2299773557 Hz to 2299774670 Hz D0228 08:01:15.081298 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667431630234226 monotonicBaseRef:36000354838 monotonicFrequency:2299774453 realtimeReady:1 realtimeBaseCycles:8667431630732196 realtimeBaseRef:1582876875081180179 realtimeFrequency:2299774670} D0228 08:01:16.080997 5497 parameters.go:238] Clock(Monotonic): error: 41 ns, adjusted frequency from 2299774453 Hz to 2299774847 Hz D0228 08:01:16.081277 5497 parameters.go:238] Clock(Realtime): error: -19 ns, adjusted frequency from 2299774670 Hz to 2299774563 Hz D0228 08:01:16.081391 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667433930033108 monotonicBaseRef:37000365460 monotonicFrequency:2299774847 realtimeReady:1 realtimeBaseCycles:8667433930713920 realtimeBaseRef:1582876876081270211 realtimeFrequency:2299774563} D0228 08:01:17.080969 5497 parameters.go:238] Clock(Monotonic): error: -30 ns, adjusted frequency from 2299774847 Hz to 2299774478 Hz D0228 08:01:17.081288 5497 parameters.go:238] Clock(Realtime): error: 395 ns, adjusted frequency from 2299774563 Hz to 2299775467 Hz D0228 08:01:17.081406 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667436229760819 monotonicBaseRef:38000344964 monotonicFrequency:2299774478 realtimeReady:1 realtimeBaseCycles:8667436230511218 realtimeBaseRef:1582876877081280096 realtimeFrequency:2299775467} D0228 08:01:18.080929 5497 parameters.go:238] Clock(Monotonic): error: -23 ns, adjusted frequency from 2299774478 Hz to 2299774487 Hz D0228 08:01:18.081203 5497 parameters.go:238] Clock(Realtime): error: -464 ns, adjusted frequency from 2299775467 Hz to 2299773572 Hz D0228 08:01:18.081339 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667438529446068 monotonicBaseRef:39000306164 monotonicFrequency:2299774487 realtimeReady:1 realtimeBaseCycles:8667438530073294 realtimeBaseRef:1582876878081187308 realtimeFrequency:2299773572} D0228 08:01:19.080988 5497 parameters.go:238] Clock(Monotonic): error: -337 ns, adjusted frequency from 2299774487 Hz to 2299773889 Hz D0228 08:01:19.081232 5497 parameters.go:238] Clock(Realtime): error: 595 ns, adjusted frequency from 2299773572 Hz to 2299775992 Hz D0228 08:01:19.081366 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667440829334529 monotonicBaseRef:40000355722 monotonicFrequency:2299773889 realtimeReady:1 realtimeBaseCycles:8667440829920918 realtimeBaseRef:1582876879081219507 realtimeFrequency:2299775992} D0228 08:01:20.080948 5497 parameters.go:238] Clock(Monotonic): error: 295 ns, adjusted frequency from 2299773889 Hz to 2299775278 Hz D0228 08:01:20.081171 5497 parameters.go:238] Clock(Realtime): error: -615 ns, adjusted frequency from 2299775992 Hz to 2299773234 Hz D0228 08:01:20.081300 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667443129034854 monotonicBaseRef:41000323734 monotonicFrequency:2299775278 realtimeReady:1 realtimeBaseCycles:8667443129573986 realtimeBaseRef:1582876880081166056 realtimeFrequency:2299773234} D0228 08:01:21.081036 5497 parameters.go:238] Clock(Monotonic): error: 201 ns, adjusted frequency from 2299775278 Hz to 2299775110 Hz D0228 08:01:21.081326 5497 parameters.go:238] Clock(Realtime): error: 355 ns, adjusted frequency from 2299773234 Hz to 2299775382 Hz D0228 08:01:21.081457 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667445429002602 monotonicBaseRef:42000407424 monotonicFrequency:2299775110 realtimeReady:1 realtimeBaseCycles:8667445429701161 realtimeBaseRef:1582876881081319958 realtimeFrequency:2299775382} D0228 08:01:22.080940 5497 parameters.go:238] Clock(Monotonic): error: -488 ns, adjusted frequency from 2299775110 Hz to 2299773461 Hz D0228 08:01:22.081131 5497 parameters.go:238] Clock(Realtime): error: -161 ns, adjusted frequency from 2299775382 Hz to 2299774254 Hz D0228 08:01:22.081259 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667447728557384 monotonicBaseRef:43000311619 monotonicFrequency:2299773461 realtimeReady:1 realtimeBaseCycles:8667447729032120 realtimeBaseRef:1582876882081126711 realtimeFrequency:2299774254} D0228 08:01:23.080940 5497 parameters.go:238] Clock(Monotonic): error: 335 ns, adjusted frequency from 2299773461 Hz to 2299775362 Hz D0228 08:01:23.081172 5497 parameters.go:238] Clock(Realtime): error: 126 ns, adjusted frequency from 2299774254 Hz to 2299774897 Hz D0228 08:01:23.081280 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667450028334184 monotonicBaseRef:44000313070 monotonicFrequency:2299775362 realtimeReady:1 realtimeBaseCycles:8667450028897197 realtimeBaseRef:1582876883081166203 realtimeFrequency:2299774897} D0228 08:01:24.080877 5497 parameters.go:238] Clock(Monotonic): error: -23 ns, adjusted frequency from 2299775362 Hz to 2299774617 Hz D0228 08:01:24.081064 5497 parameters.go:238] Clock(Realtime): error: -91 ns, adjusted frequency from 2299774897 Hz to 2299774400 Hz D0228 08:01:24.081157 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667452327972478 monotonicBaseRef:45000253469 monotonicFrequency:2299774617 realtimeReady:1 realtimeBaseCycles:8667452328427514 realtimeBaseRef:1582876884081059853 realtimeFrequency:2299774400} I0228 08:01:24.227369 5497 watchdog.go:277] Watchdog starting loop, tasks: 14, discount: 0s D0228 08:01:25.081032 5497 parameters.go:238] Clock(Monotonic): error: -380 ns, adjusted frequency from 2299774617 Hz to 2299773704 Hz D0228 08:01:25.081197 5497 parameters.go:238] Clock(Realtime): error: -61 ns, adjusted frequency from 2299774400 Hz to 2299774433 Hz D0228 08:01:25.081277 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667454628033935 monotonicBaseRef:46000378194 monotonicFrequency:2299773704 realtimeReady:1 realtimeBaseCycles:8667454628505467 realtimeBaseRef:1582876885081191845 realtimeFrequency:2299774433} D0228 08:01:26.080957 5497 parameters.go:238] Clock(Monotonic): error: 300 ns, adjusted frequency from 2299773704 Hz to 2299775367 Hz D0228 08:01:26.081264 5497 parameters.go:238] Clock(Realtime): error: 311 ns, adjusted frequency from 2299774433 Hz to 2299775289 Hz D0228 08:01:26.081454 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667456927671739 monotonicBaseRef:47000319101 monotonicFrequency:2299775367 realtimeReady:1 realtimeBaseCycles:8667456928431163 realtimeBaseRef:1582876886081257617 realtimeFrequency:2299775289} D0228 08:01:27.080946 5497 parameters.go:238] Clock(Monotonic): error: -137 ns, adjusted frequency from 2299775367 Hz to 2299774360 Hz D0228 08:01:27.081155 5497 parameters.go:238] Clock(Realtime): error: -52 ns, adjusted frequency from 2299775289 Hz to 2299774435 Hz D0228 08:01:27.081278 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667459227438365 monotonicBaseRef:48000315300 monotonicFrequency:2299774360 realtimeReady:1 realtimeBaseCycles:8667459227954901 realtimeBaseRef:1582876887081148236 realtimeFrequency:2299774435} D0228 08:01:28.080915 5497 parameters.go:238] Clock(Monotonic): error: 144 ns, adjusted frequency from 2299774360 Hz to 2299774855 Hz D0228 08:01:28.081114 5497 parameters.go:238] Clock(Realtime): error: -129 ns, adjusted frequency from 2299774435 Hz to 2299774292 Hz D0228 08:01:28.081275 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667461527160055 monotonicBaseRef:49000292397 monotonicFrequency:2299774855 realtimeReady:1 realtimeBaseCycles:8667461527639825 realtimeBaseRef:1582876888081109314 realtimeFrequency:2299774292} D0228 08:01:29.080959 5497 parameters.go:238] Clock(Monotonic): error: 188 ns, adjusted frequency from 2299774855 Hz to 2299774977 Hz D0228 08:01:29.081259 5497 parameters.go:238] Clock(Realtime): error: 161 ns, adjusted frequency from 2299774292 Hz to 2299774948 Hz D0228 08:01:29.081388 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667463827008247 monotonicBaseRef:50000324285 monotonicFrequency:2299774977 realtimeReady:1 realtimeBaseCycles:8667463827742721 realtimeBaseRef:1582876889081252199 realtimeFrequency:2299774948} D0228 08:01:30.080930 5497 parameters.go:238] Clock(Monotonic): error: -493 ns, adjusted frequency from 2299774977 Hz to 2299773399 Hz D0228 08:01:30.081168 5497 parameters.go:238] Clock(Realtime): error: -179 ns, adjusted frequency from 2299774948 Hz to 2299774171 Hz D0228 08:01:30.081317 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667466126741765 monotonicBaseRef:51000306257 monotonicFrequency:2299773399 realtimeReady:1 realtimeBaseCycles:8667466127311465 realtimeBaseRef:1582876890081162536 realtimeFrequency:2299774171} D0228 08:01:31.080903 5497 parameters.go:238] Clock(Monotonic): error: 68 ns, adjusted frequency from 2299773399 Hz to 2299774759 Hz D0228 08:01:31.081098 5497 parameters.go:238] Clock(Realtime): error: -125 ns, adjusted frequency from 2299774171 Hz to 2299774280 Hz D0228 08:01:31.081219 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667468426455494 monotonicBaseRef:52000280310 monotonicFrequency:2299774759 realtimeReady:1 realtimeBaseCycles:8667468426918489 realtimeBaseRef:1582876891081089856 realtimeFrequency:2299774280} D0228 08:01:32.080920 5497 parameters.go:238] Clock(Monotonic): error: 323 ns, adjusted frequency from 2299774759 Hz to 2299775308 Hz D0228 08:01:32.081116 5497 parameters.go:238] Clock(Realtime): error: 201 ns, adjusted frequency from 2299774280 Hz to 2299775078 Hz D0228 08:01:32.081235 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667470726217899 monotonicBaseRef:53000274938 monotonicFrequency:2299775308 realtimeReady:1 realtimeBaseCycles:8667470726742264 realtimeBaseRef:1582876892081111377 realtimeFrequency:2299775078} D0228 08:01:32.249594 5497 urpc.go:577] urpc: unmarshal success. D0228 08:01:32.249817 5497 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0228 08:01:32.250008 5497 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:01:33.080963 5497 parameters.go:238] Clock(Monotonic): error: 67 ns, adjusted frequency from 2299775308 Hz to 2299774673 Hz D0228 08:01:33.081177 5497 parameters.go:238] Clock(Realtime): error: -22 ns, adjusted frequency from 2299775078 Hz to 2299774561 Hz D0228 08:01:33.081294 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667473026136149 monotonicBaseRef:54000337092 monotonicFrequency:2299774673 realtimeReady:1 realtimeBaseCycles:8667473026654976 realtimeBaseRef:1582876893081171223 realtimeFrequency:2299774561} D0228 08:01:34.080937 5497 parameters.go:238] Clock(Monotonic): error: -93 ns, adjusted frequency from 2299774673 Hz to 2299774408 Hz D0228 08:01:34.081224 5497 parameters.go:238] Clock(Realtime): error: 277 ns, adjusted frequency from 2299774561 Hz to 2299775171 Hz D0228 08:01:34.081373 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667475325836583 monotonicBaseRef:55000304811 monotonicFrequency:2299774408 realtimeReady:1 realtimeBaseCycles:8667475326535749 realtimeBaseRef:1582876894081217406 realtimeFrequency:2299775171} D0228 08:01:35.081069 5497 parameters.go:238] Clock(Monotonic): error: -192 ns, adjusted frequency from 2299774408 Hz to 2299774148 Hz D0228 08:01:35.081335 5497 parameters.go:238] Clock(Realtime): error: -410 ns, adjusted frequency from 2299775171 Hz to 2299773714 Hz D0228 08:01:35.081470 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667477625872703 monotonicBaseRef:56000418609 monotonicFrequency:2299774148 realtimeReady:1 realtimeBaseCycles:8667477626561684 realtimeBaseRef:1582876895081326444 realtimeFrequency:2299773714} D0228 08:01:36.080930 5497 parameters.go:238] Clock(Monotonic): error: 559 ns, adjusted frequency from 2299774148 Hz to 2299775826 Hz D0228 08:01:36.081170 5497 parameters.go:238] Clock(Realtime): error: 316 ns, adjusted frequency from 2299773714 Hz to 2299775347 Hz D0228 08:01:36.081344 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667479925385526 monotonicBaseRef:57000304978 monotonicFrequency:2299775826 realtimeReady:1 realtimeBaseCycles:8667479925962277 realtimeBaseRef:1582876896081164201 realtimeFrequency:2299775347} D0228 08:01:37.080906 5497 parameters.go:238] Clock(Monotonic): error: 356 ns, adjusted frequency from 2299775826 Hz to 2299775528 Hz D0228 08:01:37.081079 5497 parameters.go:238] Clock(Realtime): error: -202 ns, adjusted frequency from 2299775347 Hz to 2299774102 Hz D0228 08:01:37.081208 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667482225115128 monotonicBaseRef:58000284878 monotonicFrequency:2299775528 realtimeReady:1 realtimeBaseCycles:8667482225529425 realtimeBaseRef:1582876897081073670 realtimeFrequency:2299774102} D0228 08:01:38.081278 5497 parameters.go:238] Clock(Monotonic): error: -599 ns, adjusted frequency from 2299775528 Hz to 2299773229 Hz D0228 08:01:38.081472 5497 parameters.go:238] Clock(Realtime): error: -2 ns, adjusted frequency from 2299774102 Hz to 2299774573 Hz D0228 08:01:38.081613 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667484525738249 monotonicBaseRef:59000653432 monotonicFrequency:2299773229 realtimeReady:1 realtimeBaseCycles:8667484526209330 realtimeBaseRef:1582876898081467536 realtimeFrequency:2299774573} D0228 08:01:39.080916 5497 parameters.go:238] Clock(Monotonic): error: 136 ns, adjusted frequency from 2299773229 Hz to 2299774889 Hz D0228 08:01:39.081153 5497 parameters.go:238] Clock(Realtime): error: 189 ns, adjusted frequency from 2299774573 Hz to 2299775090 Hz D0228 08:01:39.081267 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667486824671444 monotonicBaseRef:60000288163 monotonicFrequency:2299774889 realtimeReady:1 realtimeBaseCycles:8667486825246548 realtimeBaseRef:1582876899081146915 realtimeFrequency:2299775090} D0228 08:01:40.080963 5497 parameters.go:238] Clock(Monotonic): error: -551 ns, adjusted frequency from 2299774889 Hz to 2299773312 Hz D0228 08:01:40.081177 5497 parameters.go:238] Clock(Realtime): error: -364 ns, adjusted frequency from 2299775090 Hz to 2299773767 Hz D0228 08:01:40.081288 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667489124569168 monotonicBaseRef:61000341574 monotonicFrequency:2299773312 realtimeReady:1 realtimeBaseCycles:8667489125076231 realtimeBaseRef:1582876900081170653 realtimeFrequency:2299773767} D0228 08:01:41.080932 5497 parameters.go:238] Clock(Monotonic): error: 48 ns, adjusted frequency from 2299773312 Hz to 2299774819 Hz D0228 08:01:41.081106 5497 parameters.go:238] Clock(Realtime): error: 128 ns, adjusted frequency from 2299773767 Hz to 2299774869 Hz D0228 08:01:41.081231 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667491424272607 monotonicBaseRef:62000311191 monotonicFrequency:2299774819 realtimeReady:1 realtimeBaseCycles:8667491424690541 realtimeBaseRef:1582876901081101317 realtimeFrequency:2299774869} D0228 08:01:42.080873 5497 parameters.go:238] Clock(Monotonic): error: 325 ns, adjusted frequency from 2299774819 Hz to 2299775446 Hz D0228 08:01:42.081060 5497 parameters.go:238] Clock(Realtime): error: 38 ns, adjusted frequency from 2299774869 Hz to 2299774686 Hz D0228 08:01:42.081161 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667493723908815 monotonicBaseRef:63000250919 monotonicFrequency:2299775446 realtimeReady:1 realtimeBaseCycles:8667493724358575 realtimeBaseRef:1582876902081054862 realtimeFrequency:2299774686} D0228 08:01:43.081314 5497 parameters.go:238] Clock(Monotonic): error: -435 ns, adjusted frequency from 2299775446 Hz to 2299773585 Hz D0228 08:01:43.081594 5497 parameters.go:238] Clock(Realtime): error: -276 ns, adjusted frequency from 2299774686 Hz to 2299774062 Hz D0228 08:01:43.081732 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667496024686670 monotonicBaseRef:64000686791 monotonicFrequency:2299773585 realtimeReady:1 realtimeBaseCycles:8667496025351312 realtimeBaseRef:1582876903081584501 realtimeFrequency:2299774062} D0228 08:01:44.081396 5497 parameters.go:238] Clock(Monotonic): error: 175 ns, adjusted frequency from 2299773585 Hz to 2299775012 Hz D0228 08:01:44.081614 5497 parameters.go:238] Clock(Realtime): error: 488 ns, adjusted frequency from 2299774062 Hz to 2299775756 Hz D0228 08:01:44.081763 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667498324642239 monotonicBaseRef:65000765922 monotonicFrequency:2299775012 realtimeReady:1 realtimeBaseCycles:8667498325177684 realtimeBaseRef:1582876904081607246 realtimeFrequency:2299775756} D0228 08:01:45.080992 5497 parameters.go:238] Clock(Monotonic): error: 143 ns, adjusted frequency from 2299775012 Hz to 2299774989 Hz D0228 08:01:45.081230 5497 parameters.go:238] Clock(Realtime): error: -154 ns, adjusted frequency from 2299775756 Hz to 2299774201 Hz D0228 08:01:45.081403 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667500623435032 monotonicBaseRef:66000338828 monotonicFrequency:2299774989 realtimeReady:1 realtimeBaseCycles:8667500624066184 realtimeBaseRef:1582876905081221444 realtimeFrequency:2299774201} D0228 08:01:46.080967 5497 parameters.go:238] Clock(Monotonic): error: 143 ns, adjusted frequency from 2299774989 Hz to 2299774868 Hz D0228 08:01:46.081219 5497 parameters.go:238] Clock(Realtime): error: 72 ns, adjusted frequency from 2299774201 Hz to 2299774808 Hz D0228 08:01:46.081332 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667502923218750 monotonicBaseRef:67000342623 monotonicFrequency:2299774868 realtimeReady:1 realtimeBaseCycles:8667502923822164 realtimeBaseRef:1582876906081213521 realtimeFrequency:2299774808} D0228 08:01:47.080928 5497 parameters.go:238] Clock(Monotonic): error: -245 ns, adjusted frequency from 2299774868 Hz to 2299774104 Hz D0228 08:01:47.081120 5497 parameters.go:238] Clock(Realtime): error: -22 ns, adjusted frequency from 2299774808 Hz to 2299774548 Hz D0228 08:01:47.081240 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667505222905382 monotonicBaseRef:68000304255 monotonicFrequency:2299774104 realtimeReady:1 realtimeBaseCycles:8667505223357419 realtimeBaseRef:1582876907081109357 realtimeFrequency:2299774548} D0228 08:01:48.081097 5497 parameters.go:238] Clock(Monotonic): error: -59 ns, adjusted frequency from 2299774104 Hz to 2299774507 Hz D0228 08:01:48.081278 5497 parameters.go:238] Clock(Realtime): error: -150 ns, adjusted frequency from 2299774548 Hz to 2299774259 Hz D0228 08:01:48.081408 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667507523063694 monotonicBaseRef:69000471318 monotonicFrequency:2299774507 realtimeReady:1 realtimeBaseCycles:8667507523509055 realtimeBaseRef:1582876908081273324 realtimeFrequency:2299774259} D0228 08:01:49.080921 5497 parameters.go:238] Clock(Monotonic): error: -163 ns, adjusted frequency from 2299774507 Hz to 2299774246 Hz D0228 08:01:49.081320 5497 parameters.go:238] Clock(Realtime): error: -19 ns, adjusted frequency from 2299774259 Hz to 2299774549 Hz D0228 08:01:49.081436 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667509822424750 monotonicBaseRef:70000291539 monotonicFrequency:2299774246 realtimeReady:1 realtimeBaseCycles:8667509823369215 realtimeBaseRef:1582876909081310675 realtimeFrequency:2299774549} D0228 08:01:50.080961 5497 parameters.go:238] Clock(Monotonic): error: -23 ns, adjusted frequency from 2299774246 Hz to 2299774526 Hz D0228 08:01:50.081152 5497 parameters.go:238] Clock(Realtime): error: 5 ns, adjusted frequency from 2299774549 Hz to 2299774564 Hz D0228 08:01:50.081247 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667512122307834 monotonicBaseRef:71000338864 monotonicFrequency:2299774526 realtimeReady:1 realtimeBaseCycles:8667512122767561 realtimeBaseRef:1582876910081147092 realtimeFrequency:2299774564} D0228 08:01:51.080912 5497 parameters.go:238] Clock(Monotonic): error: 320 ns, adjusted frequency from 2299774526 Hz to 2299775319 Hz D0228 08:01:51.081112 5497 parameters.go:238] Clock(Realtime): error: 44 ns, adjusted frequency from 2299774564 Hz to 2299774655 Hz D0228 08:01:51.081223 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667514421974744 monotonicBaseRef:72000292069 monotonicFrequency:2299775319 realtimeReady:1 realtimeBaseCycles:8667514422450705 realtimeBaseRef:1582876911081107340 realtimeFrequency:2299774655} D0228 08:01:52.080908 5497 parameters.go:238] Clock(Monotonic): error: 26 ns, adjusted frequency from 2299775319 Hz to 2299774613 Hz D0228 08:01:52.081079 5497 parameters.go:238] Clock(Realtime): error: -59 ns, adjusted frequency from 2299774655 Hz to 2299774458 Hz D0228 08:01:52.081210 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667516721730204 monotonicBaseRef:73000283433 monotonicFrequency:2299774613 realtimeReady:1 realtimeBaseCycles:8667516722152298 realtimeBaseRef:1582876912081075570 realtimeFrequency:2299774458} D0228 08:01:53.080878 5497 parameters.go:238] Clock(Monotonic): error: -82 ns, adjusted frequency from 2299774613 Hz to 2299774359 Hz D0228 08:01:53.081044 5497 parameters.go:238] Clock(Realtime): error: -37 ns, adjusted frequency from 2299774458 Hz to 2299774509 Hz D0228 08:01:53.081133 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667519021442052 monotonicBaseRef:74000256141 monotonicFrequency:2299774359 realtimeReady:1 realtimeBaseCycles:8667519021846072 realtimeBaseRef:1582876913081040486 realtimeFrequency:2299774509} D0228 08:01:54.080936 5497 parameters.go:238] Clock(Monotonic): error: -154 ns, adjusted frequency from 2299774359 Hz to 2299774234 Hz D0228 08:01:54.081157 5497 parameters.go:238] Clock(Realtime): error: -69 ns, adjusted frequency from 2299774509 Hz to 2299774513 Hz D0228 08:01:54.081283 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667521321322914 monotonicBaseRef:75000302451 monotonicFrequency:2299774234 realtimeReady:1 realtimeBaseCycles:8667521321875971 realtimeBaseRef:1582876914081151536 realtimeFrequency:2299774513} D0228 08:01:55.080892 5497 parameters.go:238] Clock(Monotonic): error: 295 ns, adjusted frequency from 2299774234 Hz to 2299775271 Hz D0228 08:01:55.081065 5497 parameters.go:238] Clock(Realtime): error: 155 ns, adjusted frequency from 2299774513 Hz to 2299774950 Hz D0228 08:01:55.081224 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667523620988950 monotonicBaseRef:76000255403 monotonicFrequency:2299775271 realtimeReady:1 realtimeBaseCycles:8667523621438246 realtimeBaseRef:1582876915081059249 realtimeFrequency:2299774950} D0228 08:01:56.081014 5497 parameters.go:238] Clock(Monotonic): error: -345 ns, adjusted frequency from 2299775271 Hz to 2299773790 Hz D0228 08:01:56.081233 5497 parameters.go:238] Clock(Realtime): error: 35 ns, adjusted frequency from 2299774950 Hz to 2299774669 Hz D0228 08:01:56.081335 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667525921078593 monotonicBaseRef:77000392099 monotonicFrequency:2299773790 realtimeReady:1 realtimeBaseCycles:8667525921603015 realtimeBaseRef:1582876916081228752 realtimeFrequency:2299774669} D0228 08:01:57.080983 5497 parameters.go:238] Clock(Monotonic): error: -26 ns, adjusted frequency from 2299773790 Hz to 2299774536 Hz D0228 08:01:57.081220 5497 parameters.go:238] Clock(Realtime): error: -92 ns, adjusted frequency from 2299774669 Hz to 2299774350 Hz D0228 08:01:57.081349 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667528220764320 monotonicBaseRef:78000353806 monotonicFrequency:2299774536 realtimeReady:1 realtimeBaseCycles:8667528221335722 realtimeBaseRef:1582876917081210505 realtimeFrequency:2299774350} D0228 08:01:58.080912 5497 parameters.go:238] Clock(Monotonic): error: -12 ns, adjusted frequency from 2299774536 Hz to 2299774567 Hz D0228 08:01:58.081110 5497 parameters.go:238] Clock(Realtime): error: 3 ns, adjusted frequency from 2299774350 Hz to 2299774608 Hz D0228 08:01:58.081229 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667530520388359 monotonicBaseRef:79000288366 monotonicFrequency:2299774567 realtimeReady:1 realtimeBaseCycles:8667530520866193 realtimeBaseRef:1582876918081104460 realtimeFrequency:2299774608} D0228 08:01:59.080919 5497 sampler.go:197] Time: Adjusting syscall overhead down to 7000 D0228 08:01:59.081087 5497 parameters.go:238] Clock(Monotonic): error: 10 ns, adjusted frequency from 2299774567 Hz to 2299774635 Hz D0228 08:01:59.081227 5497 parameters.go:238] Clock(Realtime): error: 91 ns, adjusted frequency from 2299774608 Hz to 2299774881 Hz D0228 08:01:59.081331 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667532820192159 monotonicBaseRef:80000301077 monotonicFrequency:2299774635 realtimeReady:1 realtimeBaseCycles:8667532820911096 realtimeBaseRef:1582876919081221991 realtimeFrequency:2299774881} D0228 08:02:00.080869 5497 parameters.go:238] Clock(Monotonic): error: 431 ns, adjusted frequency from 2299774635 Hz to 2299775570 Hz D0228 08:02:00.081125 5497 parameters.go:238] Clock(Realtime): error: 69 ns, adjusted frequency from 2299774881 Hz to 2299774778 Hz D0228 08:02:00.081243 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667535119841825 monotonicBaseRef:81000246737 monotonicFrequency:2299775570 realtimeReady:1 realtimeBaseCycles:8667535120452771 realtimeBaseRef:1582876920081120587 realtimeFrequency:2299774778} D0228 08:02:01.080913 5497 parameters.go:238] Clock(Monotonic): error: -425 ns, adjusted frequency from 2299775570 Hz to 2299773661 Hz D0228 08:02:01.081137 5497 parameters.go:238] Clock(Realtime): error: -91 ns, adjusted frequency from 2299774778 Hz to 2299774315 Hz D0228 08:02:01.081259 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667537419698804 monotonicBaseRef:82000282135 monotonicFrequency:2299773661 realtimeReady:1 realtimeBaseCycles:8667537420254979 realtimeBaseRef:1582876921081132514 realtimeFrequency:2299774315} D0228 08:02:02.080947 5497 parameters.go:238] Clock(Monotonic): error: 313 ns, adjusted frequency from 2299773661 Hz to 2299775257 Hz D0228 08:02:02.081149 5497 parameters.go:238] Clock(Realtime): error: -235 ns, adjusted frequency from 2299774315 Hz to 2299774084 Hz D0228 08:02:02.081268 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667539719568628 monotonicBaseRef:83000323949 monotonicFrequency:2299775257 realtimeReady:1 realtimeBaseCycles:8667539720045297 realtimeBaseRef:1582876922081139472 realtimeFrequency:2299774084} D0228 08:02:03.081119 5497 parameters.go:238] Clock(Monotonic): error: -300 ns, adjusted frequency from 2299775257 Hz to 2299773918 Hz D0228 08:02:03.081294 5497 parameters.go:238] Clock(Realtime): error: 227 ns, adjusted frequency from 2299774084 Hz to 2299775101 Hz D0228 08:02:03.081397 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667542019738579 monotonicBaseRef:84000495571 monotonicFrequency:2299773918 realtimeReady:1 realtimeBaseCycles:8667542020163963 realtimeBaseRef:1582876923081289304 realtimeFrequency:2299775101} D0228 08:02:04.080972 5497 parameters.go:238] Clock(Monotonic): error: 67 ns, adjusted frequency from 2299773918 Hz to 2299774800 Hz D0228 08:02:04.081247 5497 parameters.go:238] Clock(Realtime): error: 81 ns, adjusted frequency from 2299775101 Hz to 2299774723 Hz D0228 08:02:04.081367 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667544319128304 monotonicBaseRef:85000328514 monotonicFrequency:2299774800 realtimeReady:1 realtimeBaseCycles:8667544319823850 realtimeBaseRef:1582876924081239206 realtimeFrequency:2299774723} D0228 08:02:05.080909 5497 parameters.go:238] Clock(Monotonic): error: 428 ns, adjusted frequency from 2299774800 Hz to 2299775524 Hz D0228 08:02:05.081050 5497 parameters.go:238] Clock(Realtime): error: -126 ns, adjusted frequency from 2299774723 Hz to 2299774354 Hz D0228 08:02:05.081164 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667546618795519 monotonicBaseRef:86000281733 monotonicFrequency:2299775524 realtimeReady:1 realtimeBaseCycles:8667546619149524 realtimeBaseRef:1582876925081043948 realtimeFrequency:2299774354} D0228 08:02:05.085104 5497 urpc.go:577] urpc: unmarshal success. D0228 08:02:05.085425 5497 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0228 08:02:05.085827 5497 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:02:06.081452 5497 parameters.go:238] Clock(Monotonic): error: -73 ns, adjusted frequency from 2299775524 Hz to 2299774373 Hz D0228 08:02:06.081624 5497 parameters.go:238] Clock(Realtime): error: 15 ns, adjusted frequency from 2299774354 Hz to 2299774671 Hz D0228 08:02:06.081713 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667548919828649 monotonicBaseRef:87000828571 monotonicFrequency:2299774373 realtimeReady:1 realtimeBaseCycles:8667548920248883 realtimeBaseRef:1582876926081620093 realtimeFrequency:2299774671} I0228 08:02:06.790105 15922 main.go:296] *************************** I0228 08:02:06.790239 15922 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-3 /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 /syzkaller203731212] I0228 08:02:06.790678 15922 main.go:298] Version release-20200219.0-52-gabf7ebcd38e8 I0228 08:02:06.790750 15922 main.go:299] PID: 15922 I0228 08:02:06.790842 15922 main.go:300] UID: 0, GID: 0 I0228 08:02:06.790918 15922 main.go:301] Configuration: I0228 08:02:06.791006 15922 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 08:02:06.791097 15922 main.go:303] Platform: ptrace I0228 08:02:06.791172 15922 main.go:304] FileAccess: shared, overlay: false I0228 08:02:06.791306 15922 main.go:305] Network: sandbox, logging: false I0228 08:02:06.791416 15922 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 08:02:06.791507 15922 main.go:307] *************************** W0228 08:02:06.791563 15922 main.go:312] Block the TERM signal. This is only safe in tests! D0228 08:02:06.791991 15922 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.799223 15922 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-3": signal 0 D0228 08:02:06.799408 15922 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.799533 15922 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.800019 15922 urpc.go:534] urpc: successfully marshalled 117 bytes. D0228 08:02:06.800428 5497 urpc.go:577] urpc: unmarshal success. D0228 08:02:06.800669 5497 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0228 08:02:06.800948 5497 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:02:06.801207 15922 urpc.go:577] urpc: unmarshal success. D0228 08:02:06.801407 15922 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 /syzkaller203731212 D0228 08:02:06.801560 15922 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0228 08:02:06.801714 15922 container.go:532] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-3", 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 /syzkaller203731212 D0228 08:02:06.801880 15922 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-3" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.802013 15922 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.802743 15922 urpc.go:534] urpc: successfully marshalled 635 bytes. D0228 08:02:06.803123 5497 urpc.go:577] urpc: unmarshal success. D0228 08:02:06.804347 5497 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 /syzkaller203731212 D0228 08:02:06.804592 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0228 08:02:06.805245 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:06.805423 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:02:06.805905 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} I0228 08:02:06.806400 5497 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 /syzkaller203731212] D0228 08:02:06.807402 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0228 08:02:06.808708 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876840, NanoSec: 108678070}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350300}]} D0228 08:02:06.809122 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0228 08:02:06.809580 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:06.810054 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetattr{FID: 5, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:02:06.811186 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18350300}, 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: 1582876840, NanoSec: 108678070}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:02:06.811353 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalk{FID: 5, NewFID: 6, Names: []} D0228 08:02:06.811851 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rwalk{QIDs: []} D0228 08:02:06.811980 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tlopen{FID: 6, Flags: ReadOnly} D0228 08:02:06.812740 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350300}, IoUnit: 0, File: &{{33}}} D0228 08:02:06.817886 5497 syscalls.go:266] Allocating stack with size of 8388608 bytes D0228 08:02:06.819236 5497 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-3 0}:0xc0003608a0 {ci-gvisor-ptrace-proxy-sandbox-race-3 20}:0xc0001b1540] D0228 08:02:06.819514 5497 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 08:02:06.819649 15922 urpc.go:577] urpc: unmarshal success. D0228 08:02:06.819828 15922 container.go:579] Wait on PID 20 in container "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.819975 15922 sandbox.go:743] Waiting for PID 20 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.820066 15922 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:06.820430 15922 urpc.go:534] urpc: successfully marshalled 100 bytes. D0228 08:02:06.820829 5497 urpc.go:577] urpc: unmarshal success. D0228 08:02:06.821090 5497 controller.go:443] containerManager.Wait D0228 08:02:06.821393 5497 task_block.go:223] [ 20] Interrupt queued D0228 08:02:07.020497 5497 task_block.go:223] [ 21] Interrupt queued D0228 08:02:07.021199 5497 task_block.go:223] [ 22] Interrupt queued D0228 08:02:07.023284 5497 task_block.go:223] [ 23] Interrupt queued D0228 08:02:07.026714 5497 task_block.go:223] [ 24] Interrupt queued D0228 08:02:07.037929 5497 task_block.go:223] [ 25] Interrupt queued D0228 08:02:07.048359 5497 task_block.go:223] [ 26] Interrupt queued D0228 08:02:07.053867 5497 task_block.go:223] [ 27] Interrupt queued D0228 08:02:07.080913 5497 parameters.go:238] Clock(Monotonic): error: -64 ns, adjusted frequency from 2299774373 Hz to 2299774414 Hz D0228 08:02:07.081132 5497 parameters.go:238] Clock(Realtime): error: -180 ns, adjusted frequency from 2299774671 Hz to 2299774224 Hz D0228 08:02:07.081273 5497 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8667551218372508 monotonicBaseRef:88000293512 monotonicFrequency:2299774414 realtimeReady:1 realtimeBaseCycles:8667551218888101 realtimeBaseRef:1582876927081126369 realtimeFrequency:2299774224} D0228 08:02:07.097233 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0228 08:02:07.097921 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.098098 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:02:07.098877 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.133532 5497 task_block.go:223] [ 28] Interrupt queued D0228 08:02:07.138107 5497 task_block.go:223] [ 29] Interrupt queued D0228 08:02:07.149394 5497 task_block.go:223] [ 30] Interrupt queued D0228 08:02:07.158258 5497 task_block.go:223] [ 31] Interrupt queued D0228 08:02:07.188099 5497 task_block.go:223] [ 32] Interrupt queued D0228 08:02:07.191034 5497 task_block.go:223] [ 33] Interrupt queued D0228 08:02:07.195730 5497 task_block.go:223] [ 34] Interrupt queued D0228 08:02:07.225529 5497 task_block.go:223] [ 35] Interrupt queued D0228 08:02:07.231257 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller203731212]} D0228 08:02:07.231506 5497 task_block.go:223] [ 36] Interrupt queued D0228 08:02:07.232723 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876926, NanoSec: 753169177}, MTime: {Sec: 1582876926, NanoSec: 753169177}, CTime: {Sec: 1582876926, NanoSec: 753169177}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350236}]} D0228 08:02:07.232993 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller203731212, Size: 1} D0228 08:02:07.233521 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.233868 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetattr{FID: 7, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:02:07.234832 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876926, NanoSec: 753169177}, MTime: {Sec: 1582876926, NanoSec: 753169177}, CTime: {Sec: 1582876926, NanoSec: 753169177}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:02:07.234987 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalk{FID: 7, NewFID: 8, Names: []} D0228 08:02:07.235726 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rwalk{QIDs: []} D0228 08:02:07.235916 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tlopen{FID: 8, Flags: ReadOnly} D0228 08:02:07.236811 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350236}, IoUnit: 0, File: &{{27}}} D0228 08:02:07.237802 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetattr{FID: 8, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:02:07.238889 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876926, NanoSec: 753169177}, MTime: {Sec: 1582876926, NanoSec: 753169177}, CTime: {Sec: 1582876926, NanoSec: 753169177}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 08:02:07 parsed 1 programs D0228 08:02:07.246745 5497 task_stop.go:118] [ 30] Entering internal stop (*kernel.vforkStop)(nil) D0228 08:02:07.247473 5497 task_block.go:223] [ 37] Interrupt queued D0228 08:02:07.252523 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0228 08:02:07.253925 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876840, NanoSec: 112678462}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350302}]} D0228 08:02:07.254191 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0228 08:02:07.254677 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.255004 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:02:07.255845 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876840, NanoSec: 112678462}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:02:07.256056 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalk{FID: 9, NewFID: 10, Names: []} D0228 08:02:07.256680 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rwalk{QIDs: []} D0228 08:02:07.256792 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tlopen{FID: 10, Flags: ReadOnly} D0228 08:02:07.257953 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18350302}, IoUnit: 0, File: &{{28}}} D0228 08:02:07.258789 5497 syscalls.go:266] [ 37] Allocating stack with size of 8388608 bytes D0228 08:02:07.259545 5497 task_stop.go:137] [ 30] Leaving internal stop (*kernel.vforkStop)(nil) D0228 08:02:07.280838 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 08:02:07.281432 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.281623 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:02:07.282239 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.283605 5497 task_exit.go:221] [ 37] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 08:02:07.284927 5497 task_exit.go:221] [ 37] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 08:02:07.285073 5497 task_signals.go:446] [ 20] Notified of signal 17 D0228 08:02:07.285223 5497 task_block.go:223] [ 20] Interrupt queued D0228 08:02:07.285360 5497 task_block.go:223] [ 20] Interrupt queued D0228 08:02:07.285588 5497 task_signals.go:179] [ 20] Restarting syscall 202 after errno 512: interrupted by signal 17 D0228 08:02:07.285713 5497 task_signals.go:220] [ 20] Signal 17: delivering to handler D0228 08:02:07.285764 5497 task_exit.go:221] [ 37] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 08:02:07.287312 5497 task_block.go:223] [ 38] Interrupt queued D0228 08:02:07.290940 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 08:02:07.292216 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876840, NanoSec: 112678462}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350302}]} D0228 08:02:07.292364 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tclunk{FID: 11} D0228 08:02:07.292843 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rclunk{} D0228 08:02:07.293019 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:02:07.294051 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876840, NanoSec: 112678462}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 08:02:07 executed programs: 0 D0228 08:02:07.303143 5497 task_stop.go:118] [ 27] Entering internal stop (*kernel.vforkStop)(nil) D0228 08:02:07.303967 5497 task_block.go:223] [ 39] Interrupt queued D0228 08:02:07.315708 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 08:02:07.317097 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876840, NanoSec: 112678462}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18350302}]} D0228 08:02:07.317225 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tclunk{FID: 11} D0228 08:02:07.317777 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rclunk{} D0228 08:02:07.317970 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 08:02:07.319005 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] 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: 1582876840, NanoSec: 112678462}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 08:02:07.319991 5497 syscalls.go:266] [ 39] Allocating stack with size of 8388608 bytes D0228 08:02:07.320692 5497 task_stop.go:137] [ 27] Leaving internal stop (*kernel.vforkStop)(nil) D0228 08:02:07.327729 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 08:02:07.328426 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.328581 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 08:02:07.329079 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.339977 5497 task_block.go:223] [ 40] Interrupt queued D0228 08:02:07.344011 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.344710 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.344956 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.345555 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.346060 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.346927 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.347121 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.347631 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.348283 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.348893 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.349028 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.349383 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.349710 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.350162 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.350334 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.350742 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.351236 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.351800 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.351991 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.352457 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.352980 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.375478 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.375700 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.376266 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.376848 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.377343 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.377515 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.377981 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.378535 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.379142 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.379325 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.379984 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.380852 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.381534 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.381747 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.382272 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.405300 5497 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 08:02:07.405442 5497 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0228 08:02:07.405563 5497 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0228 08:02:07.405670 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.405783 5497 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:02:07.406416 5497 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 08:02:07.406473 5497 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0228 08:02:07.406543 5497 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0228 08:02:07.406619 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.406697 5497 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:02:07.407287 5497 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 08:02:07.407371 5497 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 08:02:07.407503 5497 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 08:02:07.407566 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.407658 5497 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:02:07.408237 5497 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 08:02:07.408376 5497 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:02:07.409055 5497 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 08:02:07.409125 5497 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 08:02:07.409193 5497 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 08:02:07.409251 5497 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 08:02:07.409305 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.409362 5497 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:02:07.409786 5497 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 08:02:07.409873 5497 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0228 08:02:07.409967 5497 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0228 08:02:07.410029 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.410100 5497 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:02:07.410514 5497 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 08:02:07.410575 5497 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 08:02:07.410633 5497 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 08:02:07.410743 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.410860 5497 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:02:07.411603 5497 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 08:02:07.411681 5497 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0228 08:02:07.411759 5497 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0228 08:02:07.411835 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.411946 5497 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:02:07.412549 5497 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0228 08:02:07.412633 5497 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:02:07.413155 5497 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 08:02:07.413263 5497 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 08:02:07.413391 5497 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 08:02:07.413491 5497 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 08:02:07.413600 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.413692 5497 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:02:07.414249 5497 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 08:02:07.414330 5497 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0228 08:02:07.414397 5497 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0228 08:02:07.414457 5497 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 08:02:07.414531 5497 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:02:07.415022 5497 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 08:02:07.415097 5497 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:02:07.415568 5497 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 08:02:07.521618 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.522228 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.522397 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.523154 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.523384 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.524118 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.524296 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.524727 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.525117 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.525637 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.525790 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.526218 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.526490 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.526919 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.527087 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.527572 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.527821 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.528433 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.528537 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.529181 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.529503 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.530021 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.530167 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.530561 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.530834 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.531336 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.531599 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.532121 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.532435 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.533012 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.533132 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.533616 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.533884 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.534360 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.534542 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.534922 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.535205 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 08:02:07.535613 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 2} D0228 08:02:07.535735 5497 transport_flipcall.go:127] send [channel @0xc0003b83c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 08:02:07.536260 5497 transport_flipcall.go:234] recv [channel @0xc0003b83c0] Rlerror{Error: 95} D0228 08:02:07.550636 5497 task_block.go:223] [ 41] Interrupt queued D0228 08:02:07.560453 5497 task_block.go:223] [ 42] Interrupt queued D0228 08:02:07.616021 5497 task_block.go:223] [ 43] Interrupt queued ================== WARNING: DATA RACE Read at 0x00c000676470 by goroutine 369: 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 DIAGNOSIS: I0228 08:02:07.647072 16152 main.go:296] *************************** I0228 08:02:07.647208 16152 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-3] I0228 08:02:07.647371 16152 main.go:298] Version release-20200219.0-52-gabf7ebcd38e8 I0228 08:02:07.647450 16152 main.go:299] PID: 16152 I0228 08:02:07.647542 16152 main.go:300] UID: 0, GID: 0 I0228 08:02:07.647624 16152 main.go:301] Configuration: I0228 08:02:07.647697 16152 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 08:02:07.647786 16152 main.go:303] Platform: ptrace I0228 08:02:07.647895 16152 main.go:304] FileAccess: shared, overlay: false I0228 08:02:07.648000 16152 main.go:305] Network: sandbox, logging: false I0228 08:02:07.648097 16152 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 08:02:07.648183 16152 main.go:307] *************************** W0228 08:02:07.648266 16152 main.go:312] Block the TERM signal. This is only safe in tests! D0228 08:02:07.648406 16152 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.654920 16152 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-3": signal 0 D0228 08:02:07.655112 16152 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.655216 16152 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.655609 16152 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 08:02:07.795826 16152 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3", PID: 5497 I0228 08:02:07.795972 16152 debug.go:131] Retrieving sandbox stacks D0228 08:02:07.796069 16152 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.796206 16152 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" W0228 08:02:07.796366 16152 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 5497: connection refused retrieving stacks: connecting to control server at PID 5497: connection refused W0228 08:02:07.796603 16152 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-3"]: exit status 128 I0228 08:02:07.647072 16152 main.go:296] *************************** I0228 08:02:07.647208 16152 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-3] I0228 08:02:07.647371 16152 main.go:298] Version release-20200219.0-52-gabf7ebcd38e8 I0228 08:02:07.647450 16152 main.go:299] PID: 16152 I0228 08:02:07.647542 16152 main.go:300] UID: 0, GID: 0 I0228 08:02:07.647624 16152 main.go:301] Configuration: I0228 08:02:07.647697 16152 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 08:02:07.647786 16152 main.go:303] Platform: ptrace I0228 08:02:07.647895 16152 main.go:304] FileAccess: shared, overlay: false I0228 08:02:07.648000 16152 main.go:305] Network: sandbox, logging: false I0228 08:02:07.648097 16152 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 08:02:07.648183 16152 main.go:307] *************************** W0228 08:02:07.648266 16152 main.go:312] Block the TERM signal. This is only safe in tests! D0228 08:02:07.648406 16152 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.654920 16152 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-3": signal 0 D0228 08:02:07.655112 16152 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.655216 16152 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.655609 16152 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 08:02:07.795826 16152 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3", PID: 5497 I0228 08:02:07.795972 16152 debug.go:131] Retrieving sandbox stacks D0228 08:02:07.796069 16152 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.796206 16152 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" W0228 08:02:07.796366 16152 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 5497: connection refused retrieving stacks: connecting to control server at PID 5497: connection refused W0228 08:02:07.796603 16152 main.go:329] Failure to execute command, err: 1 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous write at 0x00c000676470 by goroutine 344: 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 369 (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 344 (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:02:07.788272 15922 error.go:48] FATAL ERROR: waiting on pid 20: waiting on PID 20 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 20: waiting on PID 20 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3": urpc method "containerManager.WaitPID" failed: EOF W0228 08:02:07.788610 15922 main.go:329] Failure to execute command, err: 1 W0228 08:02:07.795751 5488 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-3" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0228 08:02:07.796320 5488 container.go:713] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.796487 5488 container.go:800] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.796579 5488 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-3" by destroying sandbox D0228 08:02:07.796725 5488 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0228 08:02:07.796898 5488 container.go:814] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-3", PID: 5496 I0228 08:02:07.897954 5488 main.go:320] Exiting with status: 16896