D0227 13:15:12.868081 13465 parameters.go:238] Clock(Monotonic): error: 89 ns, adjusted frequency from 2299774423 Hz to 2299774676 Hz D0227 13:15:12.868454 13465 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 13:15:12.868622 13465 parameters.go:238] Clock(Realtime): error: 381 ns, adjusted frequency from 2299774242 Hz to 2299775197 Hz D0227 13:15:12.868764 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512053767391276 monotonicBaseRef:2001075417 monotonicFrequency:2299774676 realtimeReady:1 realtimeBaseCycles:8512053768665510 realtimeBaseRef:1582809312868603860 realtimeFrequency:2299775197} D0227 13:15:13.867871 13465 parameters.go:238] Clock(Monotonic): error: 129 ns, adjusted frequency from 2299774676 Hz to 2299774888 Hz D0227 13:15:13.868141 13465 parameters.go:238] Clock(Realtime): error: 273 ns, adjusted frequency from 2299775197 Hz to 2299775078 Hz D0227 13:15:13.868291 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512056066687846 monotonicBaseRef:3000867524 monotonicFrequency:2299774888 realtimeReady:1 realtimeBaseCycles:8512056067363347 realtimeBaseRef:1582809313868135396 realtimeFrequency:2299775078} D0227 13:15:14.868853 13465 parameters.go:238] Clock(Monotonic): error: 24 ns, adjusted frequency from 2299774888 Hz to 2299774678 Hz D0227 13:15:14.869111 13465 parameters.go:238] Clock(Realtime): error: -179 ns, adjusted frequency from 2299775078 Hz to 2299774179 Hz D0227 13:15:14.869227 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512058368707945 monotonicBaseRef:4001843798 monotonicFrequency:2299774678 realtimeReady:1 realtimeBaseCycles:8512058369355440 realtimeBaseRef:1582809314869099409 realtimeFrequency:2299774179} D0227 13:15:15.867289 13465 parameters.go:238] Clock(Monotonic): error: 33 ns, adjusted frequency from 2299774678 Hz to 2299774715 Hz D0227 13:15:15.867544 13465 parameters.go:238] Clock(Realtime): error: 330 ns, adjusted frequency from 2299774179 Hz to 2299775302 Hz D0227 13:15:15.867655 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512060664930126 monotonicBaseRef:5000299082 monotonicFrequency:2299774715 realtimeReady:1 realtimeBaseCycles:8512060665540603 realtimeBaseRef:1582809315867538814 realtimeFrequency:2299775302} D0227 13:15:16.869024 13465 parameters.go:238] Clock(Monotonic): error: 46 ns, adjusted frequency from 2299774715 Hz to 2299774757 Hz D0227 13:15:16.869269 13465 parameters.go:238] Clock(Realtime): error: -180 ns, adjusted frequency from 2299775302 Hz to 2299774199 Hz D0227 13:15:16.869990 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512062968680753 monotonicBaseRef:6002027908 monotonicFrequency:2299774757 realtimeReady:1 realtimeBaseCycles:8512062969280849 realtimeBaseRef:1582809316869262871 realtimeFrequency:2299774199} D0227 13:15:17.869049 13465 parameters.go:238] Clock(Monotonic): error: 75 ns, adjusted frequency from 2299774757 Hz to 2299774842 Hz D0227 13:15:17.869270 13465 parameters.go:238] Clock(Realtime): error: 53 ns, adjusted frequency from 2299774199 Hz to 2299774766 Hz D0227 13:15:17.870174 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512065268507612 monotonicBaseRef:7002050563 monotonicFrequency:2299774842 realtimeReady:1 realtimeBaseCycles:8512065269057789 realtimeBaseRef:1582809317869264062 realtimeFrequency:2299774766} D0227 13:15:18.868112 13465 parameters.go:238] Clock(Monotonic): error: -56 ns, adjusted frequency from 2299774842 Hz to 2299774535 Hz D0227 13:15:18.868321 13465 parameters.go:238] Clock(Realtime): error: 259 ns, adjusted frequency from 2299774766 Hz to 2299775150 Hz D0227 13:15:18.868457 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512067566085087 monotonicBaseRef:8001095092 monotonicFrequency:2299774535 realtimeReady:1 realtimeBaseCycles:8512067566646864 realtimeBaseRef:1582809318868313668 realtimeFrequency:2299775150} D0227 13:15:19.868928 13465 parameters.go:238] Clock(Monotonic): error: 20 ns, adjusted frequency from 2299774535 Hz to 2299774712 Hz D0227 13:15:19.869178 13465 parameters.go:238] Clock(Realtime): error: -227 ns, adjusted frequency from 2299775150 Hz to 2299774129 Hz D0227 13:15:19.869299 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512069867787757 monotonicBaseRef:9001933493 monotonicFrequency:2299774712 realtimeReady:1 realtimeBaseCycles:8512069868396015 realtimeBaseRef:1582809319869172013 realtimeFrequency:2299774129} D0227 13:15:20.867423 13465 parameters.go:238] Clock(Monotonic): error: 51 ns, adjusted frequency from 2299774712 Hz to 2299774819 Hz D0227 13:15:20.867678 13465 parameters.go:238] Clock(Realtime): error: 301 ns, adjusted frequency from 2299774129 Hz to 2299775359 Hz D0227 13:15:20.867802 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512072164092815 monotonicBaseRef:10000424800 monotonicFrequency:2299774819 realtimeReady:1 realtimeBaseCycles:8512072164713855 realtimeBaseRef:1582809320867669131 realtimeFrequency:2299775359} D0227 13:15:21.867379 13465 parameters.go:238] Clock(Monotonic): error: 14 ns, adjusted frequency from 2299774819 Hz to 2299774755 Hz D0227 13:15:21.867728 13465 parameters.go:238] Clock(Realtime): error: 77 ns, adjusted frequency from 2299775359 Hz to 2299774821 Hz D0227 13:15:21.867830 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512074463747276 monotonicBaseRef:11000372465 monotonicFrequency:2299774755 realtimeReady:1 realtimeBaseCycles:8512074464598126 realtimeBaseRef:1582809321867716488 realtimeFrequency:2299774821} D0227 13:15:22.867647 13465 parameters.go:238] Clock(Monotonic): error: -58 ns, adjusted frequency from 2299774755 Hz to 2299774569 Hz D0227 13:15:22.868538 13465 parameters.go:238] Clock(Realtime): error: -62 ns, adjusted frequency from 2299774821 Hz to 2299774562 Hz D0227 13:15:22.868655 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512076764167045 monotonicBaseRef:12000652933 monotonicFrequency:2299774569 realtimeReady:1 realtimeBaseCycles:8512076766246890 realtimeBaseRef:1582809322868531325 realtimeFrequency:2299774562} D0227 13:15:23.869523 13465 parameters.go:238] Clock(Monotonic): error: 7 ns, adjusted frequency from 2299774569 Hz to 2299774721 Hz D0227 13:15:23.869742 13465 parameters.go:238] Clock(Realtime): error: 167 ns, adjusted frequency from 2299774562 Hz to 2299775065 Hz D0227 13:15:23.869863 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512079068229909 monotonicBaseRef:13002517591 monotonicFrequency:2299774721 realtimeReady:1 realtimeBaseCycles:8512079068792301 realtimeBaseRef:1582809323869736160 realtimeFrequency:2299775065} D0227 13:15:24.868375 13465 parameters.go:238] Clock(Monotonic): error: -8 ns, adjusted frequency from 2299774721 Hz to 2299774686 Hz D0227 13:15:24.868580 13465 parameters.go:238] Clock(Realtime): error: -213 ns, adjusted frequency from 2299775065 Hz to 2299774185 Hz D0227 13:15:24.868727 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512081365308920 monotonicBaseRef:14001345428 monotonicFrequency:2299774686 realtimeReady:1 realtimeBaseCycles:8512081365896921 realtimeBaseRef:1582809324868574983 realtimeFrequency:2299774185} D0227 13:15:25.867593 13465 parameters.go:238] Clock(Monotonic): error: -6 ns, adjusted frequency from 2299774686 Hz to 2299774690 Hz D0227 13:15:25.867835 13465 parameters.go:238] Clock(Realtime): error: 162 ns, adjusted frequency from 2299774185 Hz to 2299775054 Hz D0227 13:15:25.867994 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512083663360932 monotonicBaseRef:15000596365 monotonicFrequency:2299774690 realtimeReady:1 realtimeBaseCycles:8512083663955038 realtimeBaseRef:1582809325867828793 realtimeFrequency:2299775054} D0227 13:15:26.867418 13465 parameters.go:238] Clock(Monotonic): error: -24 ns, adjusted frequency from 2299774690 Hz to 2299774636 Hz D0227 13:15:26.867612 13465 parameters.go:238] Clock(Realtime): error: -120 ns, adjusted frequency from 2299775054 Hz to 2299774387 Hz D0227 13:15:26.867712 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512085962689640 monotonicBaseRef:16000402440 monotonicFrequency:2299774636 realtimeReady:1 realtimeBaseCycles:8512085963219609 realtimeBaseRef:1582809326867606822 realtimeFrequency:2299774387} D0227 13:15:27.867372 13465 parameters.go:238] Clock(Monotonic): error: 96 ns, adjusted frequency from 2299774636 Hz to 2299774933 Hz D0227 13:15:27.867551 13465 parameters.go:238] Clock(Realtime): error: 36 ns, adjusted frequency from 2299774387 Hz to 2299774854 Hz D0227 13:15:27.867685 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512088262413303 monotonicBaseRef:17000380275 monotonicFrequency:2299774933 realtimeReady:1 realtimeBaseCycles:8512088262854078 realtimeBaseRef:1582809327867545982 realtimeFrequency:2299774854} D0227 13:15:28.868612 13465 parameters.go:238] Clock(Monotonic): error: -75 ns, adjusted frequency from 2299774933 Hz to 2299774533 Hz D0227 13:15:28.868857 13465 parameters.go:238] Clock(Realtime): error: 160 ns, adjusted frequency from 2299774854 Hz to 2299775060 Hz D0227 13:15:28.868969 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512090565023219 monotonicBaseRef:18001612996 monotonicFrequency:2299774533 realtimeReady:1 realtimeBaseCycles:8512090565631072 realtimeBaseRef:1582809328868851388 realtimeFrequency:2299775060} D0227 13:15:29.867277 13465 parameters.go:238] Clock(Monotonic): error: 28 ns, adjusted frequency from 2299774533 Hz to 2299774769 Hz D0227 13:15:29.867523 13465 parameters.go:238] Clock(Realtime): error: -358 ns, adjusted frequency from 2299775060 Hz to 2299773910 Hz D0227 13:15:29.867641 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512092861746221 monotonicBaseRef:19000286113 monotonicFrequency:2299774769 realtimeReady:1 realtimeBaseCycles:8512092862335336 realtimeBaseRef:1582809329867516128 realtimeFrequency:2299773910} D0227 13:15:30.869555 13465 parameters.go:238] Clock(Monotonic): error: -24 ns, adjusted frequency from 2299774769 Hz to 2299774642 Hz D0227 13:15:30.869848 13465 parameters.go:238] Clock(Realtime): error: -25 ns, adjusted frequency from 2299773910 Hz to 2299774728 Hz D0227 13:15:30.869985 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512095166751062 monotonicBaseRef:20002560280 monotonicFrequency:2299774642 realtimeReady:1 realtimeBaseCycles:8512095167450555 realtimeBaseRef:1582809330869838664 realtimeFrequency:2299774728} D0227 13:15:31.868364 13465 parameters.go:238] Clock(Monotonic): error: -7 ns, adjusted frequency from 2299774642 Hz to 2299774687 Hz D0227 13:15:31.868893 13465 parameters.go:238] Clock(Realtime): error: 74 ns, adjusted frequency from 2299774728 Hz to 2299774900 Hz D0227 13:15:31.869068 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512097463792646 monotonicBaseRef:21001371877 monotonicFrequency:2299774687 realtimeReady:1 realtimeBaseCycles:8512097464988352 realtimeBaseRef:1582809331868865990 realtimeFrequency:2299774900} D0227 13:15:32.867225 13465 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 13:15:32.867449 13465 parameters.go:238] Clock(Monotonic): error: 217 ns, adjusted frequency from 2299774687 Hz to 2299775215 Hz D0227 13:15:32.867593 13465 parameters.go:238] Clock(Realtime): error: 163 ns, adjusted frequency from 2299774900 Hz to 2299775075 Hz D0227 13:15:32.867719 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512099761481499 monotonicBaseRef:22000464903 monotonicFrequency:2299775215 realtimeReady:1 realtimeBaseCycles:8512099761824211 realtimeBaseRef:1582809332867588021 realtimeFrequency:2299775075} D0227 13:15:33.867332 13465 parameters.go:238] Clock(Monotonic): error: 80 ns, adjusted frequency from 2299775215 Hz to 2299774810 Hz D0227 13:15:33.867566 13465 parameters.go:238] Clock(Realtime): error: 36 ns, adjusted frequency from 2299775075 Hz to 2299774737 Hz D0227 13:15:33.867680 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512102060961715 monotonicBaseRef:23000336630 monotonicFrequency:2299774810 realtimeReady:1 realtimeBaseCycles:8512102061533085 realtimeBaseRef:1582809333867559235 realtimeFrequency:2299774737} D0227 13:15:34.867930 13465 parameters.go:238] Clock(Monotonic): error: 138 ns, adjusted frequency from 2299774810 Hz to 2299774961 Hz D0227 13:15:34.868131 13465 parameters.go:238] Clock(Realtime): error: -196 ns, adjusted frequency from 2299774737 Hz to 2299774252 Hz D0227 13:15:34.868241 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512104362118456 monotonicBaseRef:24000937528 monotonicFrequency:2299774961 realtimeReady:1 realtimeBaseCycles:8512104362609366 realtimeBaseRef:1582809334868125179 realtimeFrequency:2299774252} D0227 13:15:35.867253 13465 parameters.go:238] Clock(Monotonic): error: -1 ns, adjusted frequency from 2299774961 Hz to 2299774626 Hz D0227 13:15:35.867466 13465 parameters.go:238] Clock(Realtime): error: 135 ns, adjusted frequency from 2299774252 Hz to 2299774987 Hz D0227 13:15:35.867601 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512106660342800 monotonicBaseRef:25000263280 monotonicFrequency:2299774626 realtimeReady:1 realtimeBaseCycles:8512106660852851 realtimeBaseRef:1582809335867459562 realtimeFrequency:2299774987} D0227 13:15:36.867825 13465 parameters.go:238] Clock(Monotonic): error: 105 ns, adjusted frequency from 2299774626 Hz to 2299774875 Hz D0227 13:15:36.868031 13465 parameters.go:238] Clock(Realtime): error: -36 ns, adjusted frequency from 2299774987 Hz to 2299774624 Hz D0227 13:15:36.868144 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512108961392813 monotonicBaseRef:26000817850 monotonicFrequency:2299774875 realtimeReady:1 realtimeBaseCycles:8512108961930123 realtimeBaseRef:1582809336868025828 realtimeFrequency:2299774624} D0227 13:15:37.867668 13465 parameters.go:238] Clock(Monotonic): error: 176 ns, adjusted frequency from 2299774875 Hz to 2299775065 Hz D0227 13:15:37.867919 13465 parameters.go:238] Clock(Realtime): error: 77 ns, adjusted frequency from 2299774624 Hz to 2299774859 Hz D0227 13:15:37.868064 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512111260846998 monotonicBaseRef:27000678405 monotonicFrequency:2299775065 realtimeReady:1 realtimeBaseCycles:8512111261447777 realtimeBaseRef:1582809337867914090 realtimeFrequency:2299774859} D0227 13:15:38.868082 13465 parameters.go:238] Clock(Monotonic): error: -590 ns, adjusted frequency from 2299775065 Hz to 2299773341 Hz D0227 13:15:38.868287 13465 parameters.go:238] Clock(Realtime): error: 77 ns, adjusted frequency from 2299774859 Hz to 2299774830 Hz D0227 13:15:38.868416 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512113561570151 monotonicBaseRef:28001090657 monotonicFrequency:2299773341 realtimeReady:1 realtimeBaseCycles:8512113562067985 realtimeBaseRef:1582809338868281669 realtimeFrequency:2299774830} D0227 13:15:39.868275 13465 parameters.go:238] Clock(Monotonic): error: 41 ns, adjusted frequency from 2299773341 Hz to 2299774796 Hz D0227 13:15:39.868531 13465 parameters.go:238] Clock(Realtime): error: -345 ns, adjusted frequency from 2299774830 Hz to 2299773924 Hz D0227 13:15:39.868652 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512115861777604 monotonicBaseRef:29001279419 monotonicFrequency:2299774796 realtimeReady:1 realtimeBaseCycles:8512115862401761 realtimeBaseRef:1582809339868524712 realtimeFrequency:2299773924} D0227 13:15:40.867685 13465 parameters.go:238] Clock(Monotonic): error: 24 ns, adjusted frequency from 2299774796 Hz to 2299774766 Hz D0227 13:15:40.867921 13465 parameters.go:238] Clock(Realtime): error: 316 ns, adjusted frequency from 2299773924 Hz to 2299775381 Hz D0227 13:15:40.868020 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512118160201739 monotonicBaseRef:30000692117 monotonicFrequency:2299774766 realtimeReady:1 realtimeBaseCycles:8512118160773410 realtimeBaseRef:1582809340867914967 realtimeFrequency:2299775381} D0227 13:15:41.868520 13465 parameters.go:238] Clock(Monotonic): error: 192 ns, adjusted frequency from 2299774766 Hz to 2299775148 Hz D0227 13:15:41.868912 13465 parameters.go:238] Clock(Realtime): error: -1 ns, adjusted frequency from 2299775381 Hz to 2299774622 Hz D0227 13:15:41.869084 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512120461886257 monotonicBaseRef:31001522525 monotonicFrequency:2299775148 realtimeReady:1 realtimeBaseCycles:8512120462821865 realtimeBaseRef:1582809341868903356 realtimeFrequency:2299774622} D0227 13:15:42.868790 13465 parameters.go:238] Clock(Monotonic): error: -41 ns, adjusted frequency from 2299775148 Hz to 2299774696 Hz D0227 13:15:42.869139 13465 parameters.go:238] Clock(Realtime): error: -315 ns, adjusted frequency from 2299774622 Hz to 2299774091 Hz D0227 13:15:42.869318 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512122762291707 monotonicBaseRef:32001796596 monotonicFrequency:2299774696 realtimeReady:1 realtimeBaseCycles:8512122763097746 realtimeBaseRef:1582809342869121316 realtimeFrequency:2299774091} D0227 13:15:43.867832 13465 parameters.go:238] Clock(Monotonic): error: 66 ns, adjusted frequency from 2299774696 Hz to 2299774798 Hz D0227 13:15:43.868047 13465 parameters.go:238] Clock(Realtime): error: 269 ns, adjusted frequency from 2299774091 Hz to 2299775319 Hz D0227 13:15:43.868193 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512125059804427 monotonicBaseRef:33000813031 monotonicFrequency:2299774798 realtimeReady:1 realtimeBaseCycles:8512125060388474 realtimeBaseRef:1582809343868041486 realtimeFrequency:2299775319} D0227 13:15:44.867321 13465 parameters.go:238] Clock(Monotonic): error: -239 ns, adjusted frequency from 2299774798 Hz to 2299774229 Hz D0227 13:15:44.867531 13465 parameters.go:238] Clock(Realtime): error: 4 ns, adjusted frequency from 2299775319 Hz to 2299774748 Hz D0227 13:15:44.867650 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512127358460343 monotonicBaseRef:34000326512 monotonicFrequency:2299774229 realtimeReady:1 realtimeBaseCycles:8512127358975368 realtimeBaseRef:1582809344867524728 realtimeFrequency:2299774748} D0227 13:15:45.867311 13465 parameters.go:238] Clock(Monotonic): error: 153 ns, adjusted frequency from 2299774229 Hz to 2299775039 Hz D0227 13:15:45.867508 13465 parameters.go:238] Clock(Realtime): error: -187 ns, adjusted frequency from 2299774748 Hz to 2299774248 Hz D0227 13:15:45.867591 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512129658214209 monotonicBaseRef:35000317657 monotonicFrequency:2299775039 realtimeReady:1 realtimeBaseCycles:8512129658702067 realtimeBaseRef:1582809345867503835 realtimeFrequency:2299774248} D0227 13:15:46.867989 13465 parameters.go:238] Clock(Monotonic): error: 280 ns, adjusted frequency from 2299775039 Hz to 2299775285 Hz D0227 13:15:46.868720 13465 parameters.go:238] Clock(Realtime): error: 233 ns, adjusted frequency from 2299774248 Hz to 2299775221 Hz D0227 13:15:46.868861 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512131959465466 monotonicBaseRef:36000959553 monotonicFrequency:2299775285 realtimeReady:1 realtimeBaseCycles:8512131961255054 realtimeBaseRef:1582809346868712100 realtimeFrequency:2299775221} D0227 13:15:47.077225 13465 urpc.go:577] urpc: unmarshal success. D0227 13:15:47.077452 13465 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0227 13:15:47.077747 13465 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 13:15:47.870316 13465 parameters.go:238] Clock(Monotonic): error: -73 ns, adjusted frequency from 2299775285 Hz to 2299774514 Hz D0227 13:15:47.870525 13465 parameters.go:238] Clock(Realtime): error: -131 ns, adjusted frequency from 2299775221 Hz to 2299774424 Hz D0227 13:15:47.870640 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512134264682884 monotonicBaseRef:37003325928 monotonicFrequency:2299774514 realtimeReady:1 realtimeBaseCycles:8512134265187648 realtimeBaseRef:1582809347870519830 realtimeFrequency:2299774424} D0227 13:15:48.867630 13465 parameters.go:238] Clock(Monotonic): error: -51 ns, adjusted frequency from 2299774514 Hz to 2299774500 Hz D0227 13:15:48.867908 13465 parameters.go:238] Clock(Realtime): error: -178 ns, adjusted frequency from 2299774424 Hz to 2299774290 Hz D0227 13:15:48.868009 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512136558267950 monotonicBaseRef:38000634599 monotonicFrequency:2299774500 realtimeReady:1 realtimeBaseCycles:8512136558940306 realtimeBaseRef:1582809348867901414 realtimeFrequency:2299774290} D0227 13:15:49.867243 13465 parameters.go:238] Clock(Monotonic): error: 63 ns, adjusted frequency from 2299774500 Hz to 2299774797 Hz D0227 13:15:49.867474 13465 parameters.go:238] Clock(Realtime): error: 333 ns, adjusted frequency from 2299774290 Hz to 2299775439 Hz D0227 13:15:49.867640 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512138857164491 monotonicBaseRef:39000252840 monotonicFrequency:2299774797 realtimeReady:1 realtimeBaseCycles:8512138857715588 realtimeBaseRef:1582809349867467020 realtimeFrequency:2299775439} D0227 13:15:50.869042 13465 parameters.go:238] Clock(Monotonic): error: 53 ns, adjusted frequency from 2299774797 Hz to 2299774772 Hz D0227 13:15:50.869223 13465 parameters.go:238] Clock(Realtime): error: -59 ns, adjusted frequency from 2299775439 Hz to 2299774589 Hz D0227 13:15:50.869360 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512141161076007 monotonicBaseRef:40002051589 monotonicFrequency:2299774772 realtimeReady:1 realtimeBaseCycles:8512141161514972 realtimeBaseRef:1582809350869216732 realtimeFrequency:2299774589} D0227 13:15:51.869017 13465 parameters.go:238] Clock(Monotonic): error: 46 ns, adjusted frequency from 2299774772 Hz to 2299774784 Hz D0227 13:15:51.869250 13465 parameters.go:238] Clock(Realtime): error: 71 ns, adjusted frequency from 2299774589 Hz to 2299774851 Hz D0227 13:15:51.869349 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512143460785357 monotonicBaseRef:41002023141 monotonicFrequency:2299774784 realtimeReady:1 realtimeBaseCycles:8512143461353572 realtimeBaseRef:1582809351869244565 realtimeFrequency:2299774851} D0227 13:15:52.867272 13465 parameters.go:238] Clock(Monotonic): error: -70 ns, adjusted frequency from 2299774784 Hz to 2299774540 Hz D0227 13:15:52.867444 13465 parameters.go:238] Clock(Realtime): error: -55 ns, adjusted frequency from 2299774851 Hz to 2299774570 Hz D0227 13:15:52.867551 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512145756555113 monotonicBaseRef:42000281653 monotonicFrequency:2299774540 realtimeReady:1 realtimeBaseCycles:8512145756973078 realtimeBaseRef:1582809352867437716 realtimeFrequency:2299774570} D0227 13:15:53.868316 13465 parameters.go:238] Clock(Monotonic): error: -286 ns, adjusted frequency from 2299774540 Hz to 2299774052 Hz D0227 13:15:53.868540 13465 parameters.go:238] Clock(Realtime): error: -267 ns, adjusted frequency from 2299774570 Hz to 2299774121 Hz D0227 13:15:53.868681 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512148058728177 monotonicBaseRef:43001324591 monotonicFrequency:2299774052 realtimeReady:1 realtimeBaseCycles:8512148059257290 realtimeBaseRef:1582809353868528971 realtimeFrequency:2299774121} D0227 13:15:54.867289 13465 parameters.go:238] Clock(Monotonic): error: -19 ns, adjusted frequency from 2299774052 Hz to 2299774737 Hz D0227 13:15:54.867509 13465 parameters.go:238] Clock(Realtime): error: 152 ns, adjusted frequency from 2299774121 Hz to 2299775052 Hz D0227 13:15:54.867636 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512150356139201 monotonicBaseRef:44000297086 monotonicFrequency:2299774737 realtimeReady:1 realtimeBaseCycles:8512150356675639 realtimeBaseRef:1582809354867504621 realtimeFrequency:2299775052} D0227 13:15:55.868729 13465 parameters.go:238] Clock(Monotonic): error: 102 ns, adjusted frequency from 2299774737 Hz to 2299775050 Hz D0227 13:15:55.868974 13465 parameters.go:238] Clock(Realtime): error: 284 ns, adjusted frequency from 2299775052 Hz to 2299775327 Hz D0227 13:15:55.869130 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512152659230093 monotonicBaseRef:45001739033 monotonicFrequency:2299775050 realtimeReady:1 realtimeBaseCycles:8512152659812973 realtimeBaseRef:1582809355868966625 realtimeFrequency:2299775327} I0227 13:15:56.068828 13465 watchdog.go:277] Watchdog starting loop, tasks: 10, discount: 0s D0227 13:15:56.867532 13465 parameters.go:238] Clock(Monotonic): error: -129 ns, adjusted frequency from 2299775050 Hz to 2299774436 Hz D0227 13:15:56.867710 13465 parameters.go:238] Clock(Realtime): error: -137 ns, adjusted frequency from 2299775327 Hz to 2299774381 Hz D0227 13:15:56.867839 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512154956169254 monotonicBaseRef:46000505917 monotonicFrequency:2299774436 realtimeReady:1 realtimeBaseCycles:8512154956670152 realtimeBaseRef:1582809356867697741 realtimeFrequency:2299774381} D0227 13:15:57.868650 13465 parameters.go:238] Clock(Monotonic): error: -68 ns, adjusted frequency from 2299774436 Hz to 2299774642 Hz D0227 13:15:57.868859 13465 parameters.go:238] Clock(Realtime): error: -228 ns, adjusted frequency from 2299774381 Hz to 2299774132 Hz D0227 13:15:57.868992 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512157258571040 monotonicBaseRef:47001648355 monotonicFrequency:2299774642 realtimeReady:1 realtimeBaseCycles:8512157259100193 realtimeBaseRef:1582809357868852489 realtimeFrequency:2299774132} D0227 13:15:58.868671 13465 parameters.go:238] Clock(Monotonic): error: 653 ns, adjusted frequency from 2299774642 Hz to 2299776253 Hz D0227 13:15:58.868920 13465 parameters.go:238] Clock(Realtime): error: 97 ns, adjusted frequency from 2299774132 Hz to 2299775027 Hz D0227 13:15:58.869115 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512159558420464 monotonicBaseRef:48001680872 monotonicFrequency:2299776253 realtimeReady:1 realtimeBaseCycles:8512159559011346 realtimeBaseRef:1582809358868912069 realtimeFrequency:2299775027} D0227 13:15:59.867313 13465 parameters.go:238] Clock(Monotonic): error: -377 ns, adjusted frequency from 2299776253 Hz to 2299773807 Hz D0227 13:15:59.867539 13465 parameters.go:238] Clock(Realtime): error: -88 ns, adjusted frequency from 2299775027 Hz to 2299774581 Hz D0227 13:15:59.867666 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512161855065390 monotonicBaseRef:49000319293 monotonicFrequency:2299773807 realtimeReady:1 realtimeBaseCycles:8512161855611294 realtimeBaseRef:1582809359867531464 realtimeFrequency:2299774581} D0227 13:16:00.868986 13465 parameters.go:238] Clock(Monotonic): error: -253 ns, adjusted frequency from 2299773807 Hz to 2299774100 Hz D0227 13:16:00.869217 13465 parameters.go:238] Clock(Realtime): error: 204 ns, adjusted frequency from 2299774581 Hz to 2299775137 Hz D0227 13:16:00.869363 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512164158676758 monotonicBaseRef:50001987961 monotonicFrequency:2299774100 realtimeReady:1 realtimeBaseCycles:8512164159240334 realtimeBaseRef:1582809360869207480 realtimeFrequency:2299775137} D0227 13:16:01.867951 13465 parameters.go:238] Clock(Monotonic): error: 214 ns, adjusted frequency from 2299774100 Hz to 2299775276 Hz D0227 13:16:01.868146 13465 parameters.go:238] Clock(Realtime): error: -28 ns, adjusted frequency from 2299775137 Hz to 2299774610 Hz D0227 13:16:01.868267 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512166456061165 monotonicBaseRef:51000948861 monotonicFrequency:2299775276 realtimeReady:1 realtimeBaseCycles:8512166456560220 realtimeBaseRef:1582809361868139875 realtimeFrequency:2299774610} D0227 13:16:02.867834 13465 parameters.go:238] Clock(Monotonic): error: -296 ns, adjusted frequency from 2299775276 Hz to 2299774026 Hz D0227 13:16:02.868089 13465 parameters.go:238] Clock(Realtime): error: 4 ns, adjusted frequency from 2299774610 Hz to 2299774667 Hz D0227 13:16:02.868209 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512168755583759 monotonicBaseRef:52000838988 monotonicFrequency:2299774026 realtimeReady:1 realtimeBaseCycles:8512168756204383 realtimeBaseRef:1582809362868083153 realtimeFrequency:2299774667} D0227 13:16:03.868861 13465 parameters.go:238] Clock(Monotonic): error: -32 ns, adjusted frequency from 2299774026 Hz to 2299774632 Hz D0227 13:16:03.869537 13465 parameters.go:238] Clock(Realtime): error: -301 ns, adjusted frequency from 2299774667 Hz to 2299774046 Hz D0227 13:16:03.869647 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512171057703852 monotonicBaseRef:53001859117 monotonicFrequency:2299774632 realtimeReady:1 realtimeBaseCycles:8512171059295947 realtimeBaseRef:1582809363869525423 realtimeFrequency:2299774046} D0227 13:16:04.868387 13465 parameters.go:238] Clock(Monotonic): error: 589 ns, adjusted frequency from 2299774632 Hz to 2299776016 Hz D0227 13:16:04.868595 13465 parameters.go:238] Clock(Realtime): error: 36 ns, adjusted frequency from 2299774046 Hz to 2299774873 Hz D0227 13:16:04.868722 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512173356417743 monotonicBaseRef:54001397880 monotonicFrequency:2299776016 realtimeReady:1 realtimeBaseCycles:8512173356915904 realtimeBaseRef:1582809364868588770 realtimeFrequency:2299774873} D0227 13:16:05.868563 13465 parameters.go:238] Clock(Monotonic): error: -363 ns, adjusted frequency from 2299776016 Hz to 2299773872 Hz D0227 13:16:05.868832 13465 parameters.go:238] Clock(Realtime): error: 97 ns, adjusted frequency from 2299774873 Hz to 2299774980 Hz D0227 13:16:05.869081 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512175656586371 monotonicBaseRef:55001568597 monotonicFrequency:2299773872 realtimeReady:1 realtimeBaseCycles:8512175657234121 realtimeBaseRef:1582809365868825029 realtimeFrequency:2299774980} D0227 13:16:06.867439 13465 parameters.go:238] Clock(Monotonic): error: 1079 ns, adjusted frequency from 2299773872 Hz to 2299777279 Hz D0227 13:16:06.867659 13465 parameters.go:238] Clock(Realtime): error: 11 ns, adjusted frequency from 2299774980 Hz to 2299774770 Hz D0227 13:16:06.867847 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512177953702599 monotonicBaseRef:56000412985 monotonicFrequency:2299777279 realtimeReady:1 realtimeBaseCycles:8512177954306223 realtimeBaseRef:1582809366867649749 realtimeFrequency:2299774770} D0227 13:16:07.867629 13465 parameters.go:238] Clock(Monotonic): error: -383 ns, adjusted frequency from 2299777279 Hz to 2299773857 Hz D0227 13:16:07.867896 13465 parameters.go:238] Clock(Realtime): error: 225 ns, adjusted frequency from 2299774770 Hz to 2299775146 Hz D0227 13:16:07.868091 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512180253988426 monotonicBaseRef:57000634114 monotonicFrequency:2299773857 realtimeReady:1 realtimeBaseCycles:8512180254594904 realtimeBaseRef:1582809367867873210 realtimeFrequency:2299775146} D0227 13:16:08.868067 13465 parameters.go:238] Clock(Monotonic): error: -915 ns, adjusted frequency from 2299773857 Hz to 2299772667 Hz D0227 13:16:08.868277 13465 parameters.go:238] Clock(Realtime): error: -54 ns, adjusted frequency from 2299775146 Hz to 2299774490 Hz D0227 13:16:08.868405 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512182554756227 monotonicBaseRef:58001066306 monotonicFrequency:2299772667 realtimeReady:1 realtimeBaseCycles:8512182555282875 realtimeBaseRef:1582809368868270129 realtimeFrequency:2299774490} D0227 13:16:09.868264 13465 parameters.go:238] Clock(Monotonic): error: -66 ns, adjusted frequency from 2299772667 Hz to 2299774592 Hz D0227 13:16:09.868480 13465 parameters.go:238] Clock(Realtime): error: 19 ns, adjusted frequency from 2299774490 Hz to 2299774732 Hz D0227 13:16:09.868630 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512184854976959 monotonicBaseRef:59001261136 monotonicFrequency:2299774592 realtimeReady:1 realtimeBaseCycles:8512184855525734 realtimeBaseRef:1582809369868473787 realtimeFrequency:2299774732} D0227 13:16:10.869581 13465 parameters.go:238] Clock(Monotonic): error: 165 ns, adjusted frequency from 2299774592 Hz to 2299775146 Hz D0227 13:16:10.869827 13465 parameters.go:238] Clock(Realtime): error: 85 ns, adjusted frequency from 2299774732 Hz to 2299774918 Hz D0227 13:16:10.869994 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512187157771227 monotonicBaseRef:60002574167 monotonicFrequency:2299775146 realtimeReady:1 realtimeBaseCycles:8512187158395880 realtimeBaseRef:1582809370869819751 realtimeFrequency:2299774918} D0227 13:16:11.869764 13465 parameters.go:238] Clock(Monotonic): error: -205 ns, adjusted frequency from 2299775146 Hz to 2299774230 Hz D0227 13:16:11.870045 13465 parameters.go:238] Clock(Realtime): error: 96 ns, adjusted frequency from 2299774918 Hz to 2299774904 Hz D0227 13:16:11.870156 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512189457992828 monotonicBaseRef:61002768296 monotonicFrequency:2299774230 realtimeReady:1 realtimeBaseCycles:8512189458674086 realtimeBaseRef:1582809371870038593 realtimeFrequency:2299774904} D0227 13:16:12.867449 13465 parameters.go:238] Clock(Monotonic): error: 277 ns, adjusted frequency from 2299774230 Hz to 2299775246 Hz D0227 13:16:12.867689 13465 parameters.go:238] Clock(Realtime): error: -153 ns, adjusted frequency from 2299774904 Hz to 2299774317 Hz D0227 13:16:12.867808 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512191752430906 monotonicBaseRef:62000448002 monotonicFrequency:2299775246 realtimeReady:1 realtimeBaseCycles:8512191753029524 realtimeBaseRef:1582809372867682072 realtimeFrequency:2299774317} D0227 13:16:13.868332 13465 parameters.go:238] Clock(Monotonic): error: -224 ns, adjusted frequency from 2299775246 Hz to 2299774228 Hz D0227 13:16:13.868644 13465 parameters.go:238] Clock(Realtime): error: -353 ns, adjusted frequency from 2299774317 Hz to 2299773889 Hz D0227 13:16:13.868772 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512194054251743 monotonicBaseRef:63001337476 monotonicFrequency:2299774228 realtimeReady:1 realtimeBaseCycles:8512194054998892 realtimeBaseRef:1582809373868636535 realtimeFrequency:2299773889} D0227 13:16:14.868307 13465 parameters.go:238] Clock(Monotonic): error: -6 ns, adjusted frequency from 2299774228 Hz to 2299774675 Hz D0227 13:16:14.868541 13465 parameters.go:238] Clock(Realtime): error: 32 ns, adjusted frequency from 2299773889 Hz to 2299774770 Hz D0227 13:16:14.868654 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512196353947704 monotonicBaseRef:64001303443 monotonicFrequency:2299774675 realtimeReady:1 realtimeBaseCycles:8512196354538663 realtimeBaseRef:1582809374868534734 realtimeFrequency:2299774770} D0227 13:16:15.867632 13465 parameters.go:238] Clock(Monotonic): error: 296 ns, adjusted frequency from 2299774675 Hz to 2299775225 Hz D0227 13:16:15.867810 13465 parameters.go:238] Clock(Realtime): error: 517 ns, adjusted frequency from 2299774770 Hz to 2299775822 Hz D0227 13:16:15.869187 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512198652175870 monotonicBaseRef:65000630981 monotonicFrequency:2299775225 realtimeReady:1 realtimeBaseCycles:8512198652634641 realtimeBaseRef:1582809375867804752 realtimeFrequency:2299775822} D0227 13:16:16.868325 13465 parameters.go:238] Clock(Monotonic): error: 83 ns, adjusted frequency from 2299775225 Hz to 2299774785 Hz D0227 13:16:16.868554 13465 parameters.go:238] Clock(Realtime): error: -61 ns, adjusted frequency from 2299775822 Hz to 2299774593 Hz D0227 13:16:16.868681 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512200953541327 monotonicBaseRef:66001322453 monotonicFrequency:2299774785 realtimeReady:1 realtimeBaseCycles:8512200954114590 realtimeBaseRef:1582809376868545749 realtimeFrequency:2299774593} D0227 13:16:17.868852 13465 parameters.go:238] Clock(Monotonic): error: -214 ns, adjusted frequency from 2299774785 Hz to 2299774212 Hz D0227 13:16:17.869100 13465 parameters.go:238] Clock(Realtime): error: -141 ns, adjusted frequency from 2299774593 Hz to 2299774389 Hz D0227 13:16:17.869248 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512203254537182 monotonicBaseRef:67001853404 monotonicFrequency:2299774212 realtimeReady:1 realtimeBaseCycles:8512203255147924 realtimeBaseRef:1582809377869093081 realtimeFrequency:2299774389} D0227 13:16:18.868670 13465 parameters.go:238] Clock(Monotonic): error: 79 ns, adjusted frequency from 2299774212 Hz to 2299774859 Hz D0227 13:16:18.868897 13465 parameters.go:238] Clock(Realtime): error: -178 ns, adjusted frequency from 2299774389 Hz to 2299774373 Hz D0227 13:16:18.869019 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512205553902293 monotonicBaseRef:68001675516 monotonicFrequency:2299774859 realtimeReady:1 realtimeBaseCycles:8512205554455140 realtimeBaseRef:1582809378868889942 realtimeFrequency:2299774373} D0227 13:16:19.867938 13465 parameters.go:238] Clock(Monotonic): error: 423 ns, adjusted frequency from 2299774859 Hz to 2299775565 Hz D0227 13:16:19.868241 13465 parameters.go:238] Clock(Realtime): error: 379 ns, adjusted frequency from 2299774373 Hz to 2299775683 Hz D0227 13:16:19.868382 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512207851997778 monotonicBaseRef:69000945281 monotonicFrequency:2299775565 realtimeReady:1 realtimeBaseCycles:8512207852715540 realtimeBaseRef:1582809379868231628 realtimeFrequency:2299775683} D0227 13:16:20.083093 13465 urpc.go:577] urpc: unmarshal success. D0227 13:16:20.083327 13465 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0227 13:16:20.083603 13465 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 13:16:20.868093 13465 parameters.go:238] Clock(Monotonic): error: -185 ns, adjusted frequency from 2299775565 Hz to 2299774238 Hz D0227 13:16:20.868353 13465 parameters.go:238] Clock(Realtime): error: -305 ns, adjusted frequency from 2299775683 Hz to 2299774028 Hz D0227 13:16:20.868488 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512210152126989 monotonicBaseRef:70001099055 monotonicFrequency:2299774238 realtimeReady:1 realtimeBaseCycles:8512210152753583 realtimeBaseRef:1582809380868345708 realtimeFrequency:2299774028} D0227 13:16:21.869583 13465 parameters.go:238] Clock(Monotonic): error: -246 ns, adjusted frequency from 2299774238 Hz to 2299774228 Hz D0227 13:16:21.869809 13465 parameters.go:238] Clock(Realtime): error: 357 ns, adjusted frequency from 2299774028 Hz to 2299775523 Hz D0227 13:16:21.869918 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512212455324423 monotonicBaseRef:71002587547 monotonicFrequency:2299774228 realtimeReady:1 realtimeBaseCycles:8512212455876633 realtimeBaseRef:1582809381869801947 realtimeFrequency:2299775523} D0227 13:16:22.868561 13465 parameters.go:238] Clock(Monotonic): error: 452 ns, adjusted frequency from 2299774228 Hz to 2299775668 Hz D0227 13:16:22.868775 13465 parameters.go:238] Clock(Realtime): error: -294 ns, adjusted frequency from 2299775523 Hz to 2299773991 Hz D0227 13:16:22.868937 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512214752745683 monotonicBaseRef:72001564417 monotonicFrequency:2299775668 realtimeReady:1 realtimeBaseCycles:8512214753265412 realtimeBaseRef:1582809382868764130 realtimeFrequency:2299773991} D0227 13:16:23.870129 13465 parameters.go:238] Clock(Monotonic): error: -452 ns, adjusted frequency from 2299775668 Hz to 2299773673 Hz D0227 13:16:23.870357 13465 parameters.go:238] Clock(Realtime): error: 19 ns, adjusted frequency from 2299773991 Hz to 2299774727 Hz D0227 13:16:23.870472 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512217056133794 monotonicBaseRef:73003135197 monotonicFrequency:2299773673 realtimeReady:1 realtimeBaseCycles:8512217056689746 realtimeBaseRef:1582809383870351391 realtimeFrequency:2299774727} D0227 13:16:24.867444 13465 parameters.go:238] Clock(Monotonic): error: -77 ns, adjusted frequency from 2299773673 Hz to 2299774584 Hz D0227 13:16:24.867640 13465 parameters.go:238] Clock(Realtime): error: -344 ns, adjusted frequency from 2299774727 Hz to 2299773997 Hz D0227 13:16:24.867757 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512219349738714 monotonicBaseRef:74000452866 monotonicFrequency:2299774584 realtimeReady:1 realtimeBaseCycles:8512219350214222 realtimeBaseRef:1582809384867633624 realtimeFrequency:2299773997} D0227 13:16:25.868031 13465 parameters.go:238] Clock(Monotonic): error: -1 ns, adjusted frequency from 2299774584 Hz to 2299774778 Hz D0227 13:16:25.868188 13465 parameters.go:238] Clock(Realtime): error: 113 ns, adjusted frequency from 2299773997 Hz to 2299774978 Hz D0227 13:16:25.868326 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512221650872542 monotonicBaseRef:75001043899 monotonicFrequency:2299774778 realtimeReady:1 realtimeBaseCycles:8512221651224385 realtimeBaseRef:1582809385868171140 realtimeFrequency:2299774978} D0227 13:16:26.869887 13465 parameters.go:238] Clock(Monotonic): error: 337 ns, adjusted frequency from 2299774778 Hz to 2299775413 Hz D0227 13:16:26.870089 13465 parameters.go:238] Clock(Realtime): error: 109 ns, adjusted frequency from 2299774978 Hz to 2299775010 Hz D0227 13:16:26.870202 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512223954896370 monotonicBaseRef:76002891492 monotonicFrequency:2299775413 realtimeReady:1 realtimeBaseCycles:8512223955395589 realtimeBaseRef:1582809386870082729 realtimeFrequency:2299775010} D0227 13:16:27.868173 13465 parameters.go:238] Clock(Monotonic): error: -344 ns, adjusted frequency from 2299775413 Hz to 2299773939 Hz D0227 13:16:27.868484 13465 parameters.go:238] Clock(Realtime): error: -142 ns, adjusted frequency from 2299775010 Hz to 2299774378 Hz D0227 13:16:27.868669 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512226250732456 monotonicBaseRef:77001178573 monotonicFrequency:2299773939 realtimeReady:1 realtimeBaseCycles:8512226251475614 realtimeBaseRef:1582809387868476056 realtimeFrequency:2299774378} D0227 13:16:28.867484 13465 parameters.go:238] Clock(Monotonic): error: 256 ns, adjusted frequency from 2299773939 Hz to 2299775320 Hz D0227 13:16:28.867680 13465 parameters.go:238] Clock(Realtime): error: 167 ns, adjusted frequency from 2299774378 Hz to 2299775007 Hz D0227 13:16:28.867796 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512228548912341 monotonicBaseRef:78000485437 monotonicFrequency:2299775320 realtimeReady:1 realtimeBaseCycles:8512228549404566 realtimeBaseRef:1582809388867673618 realtimeFrequency:2299775007} D0227 13:16:29.867994 13465 parameters.go:238] Clock(Monotonic): error: 89 ns, adjusted frequency from 2299775320 Hz to 2299774863 Hz D0227 13:16:29.868201 13465 parameters.go:238] Clock(Realtime): error: 66 ns, adjusted frequency from 2299775007 Hz to 2299774831 Hz D0227 13:16:29.868330 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512230849835523 monotonicBaseRef:79000984556 monotonicFrequency:2299774863 realtimeReady:1 realtimeBaseCycles:8512230850377930 realtimeBaseRef:1582809389868194693 realtimeFrequency:2299774831} D0227 13:16:30.867343 13465 parameters.go:238] Clock(Monotonic): error: 74 ns, adjusted frequency from 2299774863 Hz to 2299774925 Hz D0227 13:16:30.867592 13465 parameters.go:238] Clock(Realtime): error: 67 ns, adjusted frequency from 2299774831 Hz to 2299774839 Hz D0227 13:16:30.867775 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512233148143390 monotonicBaseRef:80000346669 monotonicFrequency:2299774925 realtimeReady:1 realtimeBaseCycles:8512233148737183 realtimeBaseRef:1582809390867579164 realtimeFrequency:2299774839} D0227 13:16:31.867840 13465 parameters.go:238] Clock(Monotonic): error: -106 ns, adjusted frequency from 2299774925 Hz to 2299774466 Hz D0227 13:16:31.868019 13465 parameters.go:238] Clock(Realtime): error: -148 ns, adjusted frequency from 2299774839 Hz to 2299774375 Hz D0227 13:16:31.868116 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512235449047988 monotonicBaseRef:81000837879 monotonicFrequency:2299774466 realtimeReady:1 realtimeBaseCycles:8512235449509631 realtimeBaseRef:1582809391868012949 realtimeFrequency:2299774375} D0227 13:16:32.867374 13465 parameters.go:238] Clock(Monotonic): error: -394 ns, adjusted frequency from 2299774466 Hz to 2299773792 Hz D0227 13:16:32.867571 13465 parameters.go:238] Clock(Realtime): error: -37 ns, adjusted frequency from 2299774375 Hz to 2299774603 Hz D0227 13:16:32.867687 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512237747776970 monotonicBaseRef:82000383276 monotonicFrequency:2299773792 realtimeReady:1 realtimeBaseCycles:8512237748256663 realtimeBaseRef:1582809392867566234 realtimeFrequency:2299774603} D0227 13:16:33.867776 13465 parameters.go:238] Clock(Monotonic): error: 362 ns, adjusted frequency from 2299773792 Hz to 2299775495 Hz D0227 13:16:33.867983 13465 parameters.go:238] Clock(Realtime): error: 36 ns, adjusted frequency from 2299774603 Hz to 2299774756 Hz D0227 13:16:33.868112 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512240048479560 monotonicBaseRef:83000787140 monotonicFrequency:2299775495 realtimeReady:1 realtimeBaseCycles:8512240048979494 realtimeBaseRef:1582809393867978547 realtimeFrequency:2299774756} D0227 13:16:34.867282 13465 parameters.go:238] Clock(Monotonic): error: 3 ns, adjusted frequency from 2299775495 Hz to 2299774617 Hz D0227 13:16:34.867498 13465 parameters.go:238] Clock(Realtime): error: -238 ns, adjusted frequency from 2299774756 Hz to 2299774162 Hz D0227 13:16:34.867632 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512242347117541 monotonicBaseRef:84000292520 monotonicFrequency:2299774617 realtimeReady:1 realtimeBaseCycles:8512242347634073 realtimeBaseRef:1582809394867491465 realtimeFrequency:2299774162} D0227 13:16:35.867372 13465 parameters.go:238] Clock(Monotonic): error: 60 ns, adjusted frequency from 2299774617 Hz to 2299774837 Hz D0227 13:16:35.867587 13465 parameters.go:238] Clock(Realtime): error: 265 ns, adjusted frequency from 2299774162 Hz to 2299775307 Hz D0227 13:16:35.867735 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512244647094148 monotonicBaseRef:85000380350 monotonicFrequency:2299774837 realtimeReady:1 realtimeBaseCycles:8512244647613140 realtimeBaseRef:1582809395867580562 realtimeFrequency:2299775307} D0227 13:16:36.868142 13465 parameters.go:238] Clock(Monotonic): error: 7 ns, adjusted frequency from 2299774837 Hz to 2299774660 Hz D0227 13:16:36.868319 13465 parameters.go:238] Clock(Realtime): error: 696 ns, adjusted frequency from 2299775307 Hz to 2299776314 Hz D0227 13:16:36.868425 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512246948568467 monotonicBaseRef:86001119327 monotonicFrequency:2299774660 realtimeReady:1 realtimeBaseCycles:8512246949059455 realtimeBaseRef:1582809396868307158 realtimeFrequency:2299776314} D0227 13:16:37.867754 13465 parameters.go:238] Clock(Monotonic): error: -294 ns, adjusted frequency from 2299774660 Hz to 2299774088 Hz D0227 13:16:37.868015 13465 parameters.go:238] Clock(Realtime): error: -626 ns, adjusted frequency from 2299776314 Hz to 2299773261 Hz D0227 13:16:37.868378 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512249247516591 monotonicBaseRef:87000759928 monotonicFrequency:2299774088 realtimeReady:1 realtimeBaseCycles:8512249248146624 realtimeBaseRef:1582809397868007500 realtimeFrequency:2299773261} D0227 13:16:38.868051 13465 parameters.go:238] Clock(Monotonic): error: 363 ns, adjusted frequency from 2299774088 Hz to 2299775562 Hz D0227 13:16:38.868264 13465 parameters.go:238] Clock(Realtime): error: -17 ns, adjusted frequency from 2299773261 Hz to 2299774686 Hz D0227 13:16:38.868424 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512251547984874 monotonicBaseRef:88001061781 monotonicFrequency:2299775562 realtimeReady:1 realtimeBaseCycles:8512251548486505 realtimeBaseRef:1582809398868253880 realtimeFrequency:2299774686} D0227 13:16:39.867622 13465 parameters.go:238] Clock(Monotonic): error: -129 ns, adjusted frequency from 2299775562 Hz to 2299774286 Hz D0227 13:16:39.867822 13465 parameters.go:238] Clock(Realtime): error: -45 ns, adjusted frequency from 2299774686 Hz to 2299774626 Hz D0227 13:16:39.867940 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512253846771752 monotonicBaseRef:89000631876 monotonicFrequency:2299774286 realtimeReady:1 realtimeBaseCycles:8512253847255164 realtimeBaseRef:1582809399867816434 realtimeFrequency:2299774626} D0227 13:16:40.869155 13465 parameters.go:238] Clock(Monotonic): error: -174 ns, adjusted frequency from 2299774286 Hz to 2299774371 Hz D0227 13:16:40.869442 13465 parameters.go:238] Clock(Realtime): error: -306 ns, adjusted frequency from 2299774626 Hz to 2299774025 Hz D0227 13:16:40.869569 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512256150062400 monotonicBaseRef:90002160879 monotonicFrequency:2299774371 realtimeReady:1 realtimeBaseCycles:8512256150738054 realtimeBaseRef:1582809400869428880 realtimeFrequency:2299774025} I0227 13:16:41.071601 13465 watchdog.go:277] Watchdog starting loop, tasks: 10, discount: 0s D0227 13:16:41.868925 13465 parameters.go:238] Clock(Monotonic): error: -13 ns, adjusted frequency from 2299774371 Hz to 2299774675 Hz D0227 13:16:41.869171 13465 parameters.go:238] Clock(Realtime): error: -14 ns, adjusted frequency from 2299774025 Hz to 2299774693 Hz D0227 13:16:41.869285 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512258449301651 monotonicBaseRef:91001928195 monotonicFrequency:2299774675 realtimeReady:1 realtimeBaseCycles:8512258449904459 realtimeBaseRef:1582809401869164671 realtimeFrequency:2299774693} D0227 13:16:42.870443 13465 parameters.go:238] Clock(Monotonic): error: 207 ns, adjusted frequency from 2299774675 Hz to 2299775192 Hz D0227 13:16:42.870641 13465 parameters.go:238] Clock(Realtime): error: 212 ns, adjusted frequency from 2299774693 Hz to 2299775202 Hz D0227 13:16:42.870749 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512260752584529 monotonicBaseRef:92003453650 monotonicFrequency:2299775192 realtimeReady:1 realtimeBaseCycles:8512260753063015 realtimeBaseRef:1582809402870636059 realtimeFrequency:2299775202} D0227 13:16:43.474970 13465 urpc.go:577] urpc: unmarshal success. D0227 13:16:43.475175 13465 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0227 13:16:43.475399 13465 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 13:16:43.867729 13465 parameters.go:238] Clock(Monotonic): error: 251 ns, adjusted frequency from 2299775192 Hz to 2299775310 Hz D0227 13:16:43.867991 13465 parameters.go:238] Clock(Realtime): error: 125 ns, adjusted frequency from 2299775202 Hz to 2299774978 Hz D0227 13:16:43.868106 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512263046103191 monotonicBaseRef:93000733153 monotonicFrequency:2299775310 realtimeReady:1 realtimeBaseCycles:8512263046740256 realtimeBaseRef:1582809403867984512 realtimeFrequency:2299774978} I0227 13:16:44.831952 22819 main.go:296] *************************** I0227 13:16:44.832074 22819 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot exec -user=0:0 -cap CAP_CHOWN -cap CAP_DAC_OVERRIDE -cap CAP_DAC_READ_SEARCH -cap CAP_FOWNER -cap CAP_FSETID -cap CAP_KILL -cap CAP_SETGID -cap CAP_SETUID -cap CAP_SETPCAP -cap CAP_LINUX_IMMUTABLE -cap CAP_NET_BIND_SERVICE -cap CAP_NET_BROADCAST -cap CAP_NET_ADMIN -cap CAP_NET_RAW -cap CAP_IPC_LOCK -cap CAP_IPC_OWNER -cap CAP_SYS_MODULE -cap CAP_SYS_RAWIO -cap CAP_SYS_CHROOT -cap CAP_SYS_PTRACE -cap CAP_SYS_PACCT -cap CAP_SYS_ADMIN -cap CAP_SYS_BOOT -cap CAP_SYS_NICE -cap CAP_SYS_RESOURCE -cap CAP_SYS_TIME -cap CAP_SYS_TTY_CONFIG -cap CAP_MKNOD -cap CAP_LEASE -cap CAP_AUDIT_WRITE -cap CAP_AUDIT_CONTROL -cap CAP_SETFCAP -cap CAP_MAC_OVERRIDE -cap CAP_MAC_ADMIN -cap CAP_SYSLOG -cap CAP_WAKE_ALARM -cap CAP_BLOCK_SUSPEND -cap CAP_AUDIT_READ ci-gvisor-ptrace-proxy-sandbox-race-1 /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller184864878] I0227 13:16:44.832472 22819 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 13:16:44.832556 22819 main.go:299] PID: 22819 I0227 13:16:44.832648 22819 main.go:300] UID: 0, GID: 0 I0227 13:16:44.832720 22819 main.go:301] Configuration: I0227 13:16:44.832781 22819 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 13:16:44.832844 22819 main.go:303] Platform: ptrace I0227 13:16:44.832921 22819 main.go:304] FileAccess: shared, overlay: false I0227 13:16:44.833009 22819 main.go:305] Network: sandbox, logging: false I0227 13:16:44.833100 22819 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 13:16:44.833191 22819 main.go:307] *************************** W0227 13:16:44.833272 22819 main.go:312] Block the TERM signal. This is only safe in tests! D0227 13:16:44.833643 22819 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.840689 22819 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-1": signal 0 D0227 13:16:44.840981 22819 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.841185 22819 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.842435 13465 urpc.go:577] urpc: unmarshal success. D0227 13:16:44.842655 13465 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-1 Signo:0 PID:0 Mode:Process} D0227 13:16:44.842896 13465 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 13:16:44.843164 22819 urpc.go:534] urpc: successfully marshalled 117 bytes. D0227 13:16:44.843694 22819 urpc.go:577] urpc: unmarshal success. D0227 13:16:44.844049 22819 exec.go:120] Exec arguments: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller184864878 D0227 13:16:44.844231 22819 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0227 13:16:44.844395 22819 container.go:532] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-1", args: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller184864878 D0227 13:16:44.844539 22819 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-1" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.844717 22819 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.846262 13465 urpc.go:577] urpc: unmarshal success. D0227 13:16:44.848994 13465 controller.go:267] containerManager.ExecuteAsync: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller184864878 D0227 13:16:44.849775 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0227 13:16:44.851411 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:44.851653 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 13:16:44.853100 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} I0227 13:16:44.859623 13465 kernel.go:795] EXEC: [/syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller184864878] D0227 13:16:44.863091 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0227 13:16:44.864552 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] 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: 1582792705, NanoSec: 196725805}, MTime: {Sec: 1582792705, NanoSec: 196725805}, CTime: {Sec: 1582809312, NanoSec: 251663463}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515331}]} D0227 13:16:44.865399 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0227 13:16:44.865869 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:44.866917 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetattr{FID: 5, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 13:16:44.867647 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515331}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582792705, NanoSec: 196725805}, MTime: {Sec: 1582792705, NanoSec: 196725805}, CTime: {Sec: 1582809312, NanoSec: 251663463}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 13:16:44.867786 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalk{FID: 5, NewFID: 6, Names: []} D0227 13:16:44.867985 13465 parameters.go:238] Clock(Monotonic): error: -284 ns, adjusted frequency from 2299775310 Hz to 2299774091 Hz D0227 13:16:44.868147 13465 parameters.go:238] Clock(Realtime): error: -129 ns, adjusted frequency from 2299774978 Hz to 2299774414 Hz D0227 13:16:44.868244 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512265346489454 monotonicBaseRef:94000998810 monotonicFrequency:2299774091 realtimeReady:1 realtimeBaseCycles:8512265346877541 realtimeBaseRef:1582809404868142052 realtimeFrequency:2299774414} D0227 13:16:44.869594 22819 urpc.go:534] urpc: successfully marshalled 634 bytes. D0227 13:16:44.869296 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rwalk{QIDs: []} D0227 13:16:44.869462 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tlopen{FID: 6, Flags: ReadOnly} D0227 13:16:44.870428 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515331}, IoUnit: 0, File: &{{33}}} D0227 13:16:44.873473 13465 syscalls.go:266] Allocating stack with size of 8388608 bytes D0227 13:16:44.875360 13465 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-1 0}:0xc00036a6e0 {ci-gvisor-ptrace-proxy-sandbox-race-1 16}:0xc00060b3c0] D0227 13:16:44.876049 13465 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 13:16:44.876330 22819 urpc.go:577] urpc: unmarshal success. D0227 13:16:44.876650 22819 container.go:579] Wait on PID 16 in container "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.876778 22819 sandbox.go:743] Waiting for PID 16 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.876907 22819 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:44.877391 22819 urpc.go:534] urpc: successfully marshalled 100 bytes. D0227 13:16:44.878051 13465 urpc.go:577] urpc: unmarshal success. D0227 13:16:44.878289 13465 controller.go:443] containerManager.Wait D0227 13:16:44.888191 13465 task_block.go:223] [ 16] Interrupt queued D0227 13:16:45.155443 13465 task_block.go:223] [ 18] Interrupt queued D0227 13:16:45.156316 13465 task_block.go:223] [ 17] Interrupt queued D0227 13:16:45.168351 13465 task_block.go:223] [ 19] Interrupt queued D0227 13:16:45.175247 13465 task_block.go:223] [ 20] Interrupt queued D0227 13:16:45.227008 13465 task_block.go:223] [ 21] Interrupt queued D0227 13:16:45.237032 13465 task_block.go:223] [ 22] Interrupt queued D0227 13:16:45.275699 13465 task_block.go:223] [ 23] Interrupt queued D0227 13:16:45.319728 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0227 13:16:45.323400 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.323552 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 13:16:45.324145 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.351905 13465 task_block.go:223] [ 24] Interrupt queued D0227 13:16:45.364899 13465 task_block.go:223] [ 25] Interrupt queued D0227 13:16:45.396860 13465 task_block.go:223] [ 26] Interrupt queued D0227 13:16:45.428068 13465 task_block.go:223] [ 27] Interrupt queued D0227 13:16:45.477195 13465 task_block.go:223] [ 28] Interrupt queued D0227 13:16:45.485193 13465 task_block.go:223] [ 29] Interrupt queued D0227 13:16:45.536100 13465 task_block.go:223] [ 30] Interrupt queued D0227 13:16:45.559482 13465 task_block.go:223] [ 31] Interrupt queued D0227 13:16:45.559677 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller184864878]} D0227 13:16:45.561231 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] 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: 271, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582809404, NanoSec: 780727091}, MTime: {Sec: 1582809404, NanoSec: 780727091}, CTime: {Sec: 1582809404, NanoSec: 784727483}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515213}]} D0227 13:16:45.561511 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller184864878, Size: 1} D0227 13:16:45.562073 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.562359 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetattr{FID: 7, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 13:16:45.563302 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515213}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 271, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582809404, NanoSec: 780727091}, MTime: {Sec: 1582809404, NanoSec: 780727091}, CTime: {Sec: 1582809404, NanoSec: 784727483}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 13:16:45.563462 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalk{FID: 7, NewFID: 8, Names: []} D0227 13:16:45.564079 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rwalk{QIDs: []} D0227 13:16:45.564214 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tlopen{FID: 8, Flags: ReadOnly} D0227 13:16:45.565157 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515213}, IoUnit: 0, File: &{{27}}} D0227 13:16:45.566136 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetattr{FID: 8, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 13:16:45.566892 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515213}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 271, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582809404, NanoSec: 780727091}, MTime: {Sec: 1582809404, NanoSec: 780727091}, CTime: {Sec: 1582809404, NanoSec: 784727483}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/27 13:16:45 parsed 1 programs D0227 13:16:45.581975 13465 task_stop.go:118] [ 29] Entering internal stop (*kernel.vforkStop)(nil) D0227 13:16:45.582720 13465 task_block.go:223] [ 32] Interrupt queued D0227 13:16:45.588933 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0227 13:16:45.590438 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] 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: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582809312, NanoSec: 255663855}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515336}]} D0227 13:16:45.590785 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0227 13:16:45.591250 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.591467 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 13:16:45.592504 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515336}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582809312, NanoSec: 255663855}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 13:16:45.592662 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalk{FID: 9, NewFID: 10, Names: []} D0227 13:16:45.605410 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rwalk{QIDs: []} D0227 13:16:45.605599 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tlopen{FID: 10, Flags: ReadOnly} D0227 13:16:45.608845 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515336}, IoUnit: 0, File: &{{28}}} D0227 13:16:45.610114 13465 syscalls.go:266] [ 32] Allocating stack with size of 8388608 bytes D0227 13:16:45.610909 13465 task_stop.go:137] [ 29] Leaving internal stop (*kernel.vforkStop)(nil) D0227 13:16:45.702713 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 13:16:45.703258 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.703379 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 13:16:45.703765 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.706138 13465 task_exit.go:221] [ 32] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 13:16:45.709179 13465 task_exit.go:221] [ 32] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 13:16:45.713160 13465 task_signals.go:446] [ 16] Notified of signal 17 D0227 13:16:45.713316 13465 task_block.go:223] [ 16] Interrupt queued D0227 13:16:45.713523 13465 task_block.go:223] [ 16] Interrupt queued D0227 13:16:45.713708 13465 task_signals.go:179] [ 16] Restarting syscall 202 after errno 512: interrupted by signal 17 D0227 13:16:45.713849 13465 task_signals.go:220] [ 16] Signal 17: delivering to handler D0227 13:16:45.715526 13465 task_exit.go:221] [ 32] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 13:16:45.717643 13465 task_block.go:223] [ 33] Interrupt queued D0227 13:16:45.735186 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 13:16:45.736913 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] 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: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582809312, NanoSec: 255663855}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515336}]} D0227 13:16:45.737102 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tclunk{FID: 11} D0227 13:16:45.738073 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rclunk{} D0227 13:16:45.738409 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 13:16:45.789154 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515336}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582809312, NanoSec: 255663855}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/27 13:16:45 executed programs: 0 D0227 13:16:45.800413 13465 task_stop.go:118] [ 16] Entering internal stop (*kernel.vforkStop)(nil) D0227 13:16:45.801090 13465 task_block.go:223] [ 34] Interrupt queued D0227 13:16:45.815705 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 13:16:45.821436 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] 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: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582809312, NanoSec: 255663855}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515336}]} D0227 13:16:45.825751 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tclunk{FID: 11} D0227 13:16:45.828283 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rclunk{} D0227 13:16:45.828681 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 13:16:45.831381 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515336}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582809312, NanoSec: 255663855}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 13:16:45.833525 13465 syscalls.go:266] [ 34] Allocating stack with size of 8388608 bytes D0227 13:16:45.834487 13465 task_stop.go:137] [ 16] Leaving internal stop (*kernel.vforkStop)(nil) D0227 13:16:45.867227 13465 parameters.go:238] Clock(Monotonic): error: 161 ns, adjusted frequency from 2299774091 Hz to 2299775012 Hz D0227 13:16:45.867500 13465 parameters.go:238] Clock(Realtime): error: -217 ns, adjusted frequency from 2299774414 Hz to 2299774187 Hz D0227 13:16:45.867601 13465 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8512267644513493 monotonicBaseRef:95000237843 monotonicFrequency:2299775012 realtimeReady:1 realtimeBaseCycles:8512267645153807 realtimeBaseRef:1582809405867490619 realtimeFrequency:2299774187} D0227 13:16:45.873679 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 13:16:45.878173 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.878398 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 13:16:45.879577 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.902889 13465 task_block.go:223] [ 35] Interrupt queued D0227 13:16:45.929305 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.933685 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.934112 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.934824 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.945918 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.947338 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.947614 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.948160 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.949157 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.950574 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.950774 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.951253 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.951627 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.952116 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.952305 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.952727 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.956205 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.957019 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.957201 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.957893 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.958347 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.958755 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.958904 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.959253 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.959503 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.959903 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.960038 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.960393 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.960640 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.961144 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.961326 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.962012 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.962394 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:45.962820 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:45.962981 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:45.963422 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:45.999249 13465 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 13:16:45.999643 13465 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 13:16:45.999807 13465 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 13:16:46.000233 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.000414 13465 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]} D0227 13:16:46.001142 13465 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 13:16:46.001316 13465 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0227 13:16:46.001481 13465 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0227 13:16:46.001645 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.001793 13465 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]} D0227 13:16:46.002389 13465 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 13:16:46.002519 13465 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 13:16:46.002670 13465 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 13:16:46.002778 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.002852 13465 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]} D0227 13:16:46.003415 13465 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 13:16:46.003537 13465 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0227 13:16:46.003663 13465 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0227 13:16:46.003760 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.003865 13465 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]} D0227 13:16:46.004367 13465 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0227 13:16:46.004618 13465 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]} D0227 13:16:46.006463 13465 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 13:16:46.006622 13465 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 13:16:46.006746 13465 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 13:16:46.006859 13465 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 13:16:46.006970 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.007112 13465 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]} D0227 13:16:46.008008 13465 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 13:16:46.008193 13465 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0227 13:16:46.008348 13465 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0227 13:16:46.008488 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.008765 13465 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]} D0227 13:16:46.009365 13465 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 13:16:46.009563 13465 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]} D0227 13:16:46.010283 13465 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 13:16:46.010396 13465 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 13:16:46.010461 13465 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0227 13:16:46.010546 13465 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0227 13:16:46.010609 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.010677 13465 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]} D0227 13:16:46.011141 13465 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 13:16:46.011209 13465 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0227 13:16:46.011298 13465 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0227 13:16:46.011357 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.011480 13465 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]} D0227 13:16:46.012025 13465 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 13:16:46.012121 13465 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 13:16:46.012224 13465 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 13:16:46.012370 13465 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 13:16:46.012537 13465 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]} D0227 13:16:46.013584 13465 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 13:16:46.013777 13465 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]} D0227 13:16:46.015329 13465 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 13:16:46.264473 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.265976 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.266225 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.266727 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.267268 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.268148 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.271409 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.275081 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.275582 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.276504 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.285162 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.285894 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.286671 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.296406 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.296862 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.297588 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.298035 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.298516 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.298719 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.299225 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.299587 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.300071 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.300250 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.300700 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.301020 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.301517 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.301664 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.301985 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.302202 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.302614 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.302759 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.303095 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.303451 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.304210 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.304417 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.304998 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.305352 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.305871 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.306188 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.306645 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.353078 13465 task_block.go:223] [ 36] Interrupt queued D0227 13:16:46.383105 13465 task_block.go:223] [ 37] Interrupt queued D0227 13:16:46.482714 13465 task_block.go:223] [ 37] Interrupt queued D0227 13:16:46.482826 13465 task_block.go:223] [ 37] Interrupt queued D0227 13:16:46.482921 13465 task_exit.go:221] [ 36] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 13:16:46.483161 13465 task_signals.go:189] [ 37] Signal 9: terminating thread group D0227 13:16:46.483318 13465 task_exit.go:221] [ 36] Transitioning from exit state TaskExitInitiated to TaskExitZombie I0227 13:16:46.483600 13465 compat.go:129] Uncaught signal: "killed" (9), PID: 36, TID: 37, fault addr: 0x0 D0227 13:16:46.483750 13465 task_exit.go:221] [ 37] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 13:16:46.486057 13465 task_exit.go:221] [ 37] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 13:16:46.486168 13465 task_exit.go:221] [ 37] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 13:16:46.486281 13465 task_signals.go:419] [ 35] Discarding ignored signal 17 D0227 13:16:46.486505 13465 task_exit.go:221] [ 36] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 13:16:46.498195 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.498791 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.499048 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.499560 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.500296 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.500788 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.500946 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.501331 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.501878 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 13:16:46.502246 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 2} D0227 13:16:46.502391 13465 transport_flipcall.go:127] send [channel @0xc0003c63c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 13:16:46.502719 13465 transport_flipcall.go:234] recv [channel @0xc0003c63c0] Rlerror{Error: 95} D0227 13:16:46.517523 13465 task_block.go:223] [ 38] Interrupt queued D0227 13:16:46.529125 13465 task_block.go:223] [ 39] Interrupt queued D0227 13:16:46.572835 13465 task_block.go:223] [ 40] Interrupt queued ================== WARNING: DATA RACE Read at 0x00c00044a490 by goroutine 179: gvisor.dev/gvisor/pkg/tcpip/stack.(*TransportEndpointInfo).AddrNetProto() pkg/tcpip/stack/stack.go:573 +0x79 gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).checkV4Mapped() pkg/tcpip/transport/udp/endpoint.go:931 +0xee gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Connect() pkg/tcpip/transport/udp/endpoint.go:984 +0x6c gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Connect() pkg/sentry/socket/netstack/netstack.go:698 +0x4c5 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Connect() pkg/sentry/syscalls/linux/sys_socket.go:280 +0x251 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous write at 0x00c00044a490 by goroutine 199: gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).bindLocked() pkg/tcpip/transport/udp/endpoint.go:1176 +0x28a gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).prepareForWrite() pkg/tcpip/transport/udp/endpoint.go:323 +0x267 gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).write() pkg/tcpip/transport/udp/endpoint.go:400 +0x12b gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Write() pkg/tcpip/transport/udp/endpoint.go:360 +0x81 gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).SendMsg() pkg/sentry/socket/netstack/netstack.go:2567 +0x1d5 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.sendSingleMsg() pkg/sentry/syscalls/linux/sys_socket.go:1055 +0x489 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.SendMMsg() pkg/sentry/syscalls/linux/sys_socket.go:979 +0x302 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 179 (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 199 (running) created at: DIAGNOSIS: I0227 13:16:46.658508 23020 main.go:296] *************************** I0227 13:16:46.658683 23020 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-1] I0227 13:16:46.658849 23020 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 13:16:46.658924 23020 main.go:299] PID: 23020 I0227 13:16:46.659000 23020 main.go:300] UID: 0, GID: 0 I0227 13:16:46.659101 23020 main.go:301] Configuration: I0227 13:16:46.659168 23020 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 13:16:46.659242 23020 main.go:303] Platform: ptrace I0227 13:16:46.659341 23020 main.go:304] FileAccess: shared, overlay: false I0227 13:16:46.659457 23020 main.go:305] Network: sandbox, logging: false I0227 13:16:46.659543 23020 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 13:16:46.659624 23020 main.go:307] *************************** W0227 13:16:46.659712 23020 main.go:312] Block the TERM signal. This is only safe in tests! D0227 13:16:46.659906 23020 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.668003 23020 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-1": signal 0 D0227 13:16:46.668183 23020 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.668324 23020 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.668891 23020 urpc.go:534] urpc: successfully marshalled 117 bytes. I0227 13:16:46.690452 23020 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1", PID: 13465 I0227 13:16:46.690651 23020 debug.go:131] Retrieving sandbox stacks D0227 13:16:46.690764 23020 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.690882 23020 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" W0227 13:16:46.691023 23020 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 13465: connection refused retrieving stacks: connecting to control server at PID 13465: connection refused W0227 13:16:46.691285 23020 main.go:329] Failure to execute command, err: 1 Error collecting stacks: failed to run ["/syzkaller/managers/ptrace-proxy-sandbox-race/current/image" "-root" "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "-watchdog-action=panic" "-network=none" "-debug" "-alsologtostderr" "-platform=ptrace" "-file-access=shared" "-network=sandbox" "-TESTONLY-unsafe-nonroot" "debug" "-stacks" "--ps" "ci-gvisor-ptrace-proxy-sandbox-race-1"]: exit status 128 I0227 13:16:46.658508 23020 main.go:296] *************************** I0227 13:16:46.658683 23020 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-1] I0227 13:16:46.658849 23020 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 13:16:46.658924 23020 main.go:299] PID: 23020 I0227 13:16:46.659000 23020 main.go:300] UID: 0, GID: 0 I0227 13:16:46.659101 23020 main.go:301] Configuration: I0227 13:16:46.659168 23020 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 13:16:46.659242 23020 main.go:303] Platform: ptrace I0227 13:16:46.659341 23020 main.go:304] FileAccess: shared, overlay: false I0227 13:16:46.659457 23020 main.go:305] Network: sandbox, logging: false I0227 13:16:46.659543 23020 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 13:16:46.659624 23020 main.go:307] *************************** W0227 13:16:46.659712 23020 main.go:312] Block the TERM signal. This is only safe in tests! D0227 13:16:46.659906 23020 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.668003 23020 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-1": signal 0 D0227 13:16:46.668183 23020 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.668324 23020 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.668891 23020 urpc.go:534] urpc: successfully marshalled 117 bytes. I0227 13:16:46.690452 23020 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1", PID: 13465 I0227 13:16:46.690651 23020 debug.go:131] Retrieving sandbox stacks D0227 13:16:46.690764 23020 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.690882 23020 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" W0227 13:16:46.691023 23020 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 13465: connection refused retrieving stacks: connecting to control server at PID 13465: connection refused W0227 13:16:46.691285 23020 main.go:329] Failure to execute command, err: 1 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 ================== W0227 13:16:46.681489 22819 error.go:48] FATAL ERROR: waiting on pid 16: waiting on PID 16 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 16: waiting on PID 16 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1": urpc method "containerManager.WaitPID" failed: EOF W0227 13:16:46.681896 22819 main.go:329] Failure to execute command, err: 1 W0227 13:16:46.691131 13450 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-1" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0227 13:16:46.692267 13450 container.go:713] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.692479 13450 container.go:800] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.692592 13450 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-1" by destroying sandbox D0227 13:16:46.692714 13450 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-1" D0227 13:16:46.692821 13450 container.go:814] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-1", PID: 13461 I0227 13:16:46.793848 13450 main.go:320] Exiting with status: 16896