D0227 18:59:32.371819 20813 parameters.go:238] Clock(Monotonic): error: 127 ns, adjusted frequency from 2299774370 Hz to 2299774829 Hz D0227 18:59:32.372178 20813 parameters.go:238] Clock(Realtime): error: 258 ns, adjusted frequency from 2299774214 Hz to 2299775069 Hz D0227 18:59:32.372311 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559565969781162 monotonicBaseRef:2000247515 monotonicFrequency:2299774829 realtimeReady:1 realtimeBaseCycles:8559565970642766 realtimeBaseRef:1582829972372171487 realtimeFrequency:2299775069} D0227 18:59:33.371921 20813 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 18:59:33.372147 20813 parameters.go:238] Clock(Monotonic): error: 157 ns, adjusted frequency from 2299774829 Hz to 2299774958 Hz D0227 18:59:33.372352 20813 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 18:59:33.372473 20813 parameters.go:238] Clock(Realtime): error: 360 ns, adjusted frequency from 2299775069 Hz to 2299775299 Hz D0227 18:59:33.372617 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559568270341813 monotonicBaseRef:3000589210 monotonicFrequency:2299774958 realtimeReady:1 realtimeBaseCycles:8559568271097093 realtimeBaseRef:1582829973372466845 realtimeFrequency:2299775299} D0227 18:59:34.373404 20813 parameters.go:238] Clock(Monotonic): error: -33 ns, adjusted frequency from 2299774958 Hz to 2299774520 Hz D0227 18:59:34.373635 20813 parameters.go:238] Clock(Realtime): error: -5 ns, adjusted frequency from 2299775299 Hz to 2299774487 Hz D0227 18:59:34.373757 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559570572952280 monotonicBaseRef:4001822160 monotonicFrequency:2299774520 realtimeReady:1 realtimeBaseCycles:8559570573546015 realtimeBaseRef:1582829974373629403 realtimeFrequency:2299774487} D0227 18:59:35.372410 20813 parameters.go:238] Clock(Monotonic): error: 9 ns, adjusted frequency from 2299774520 Hz to 2299774652 Hz D0227 18:59:35.372657 20813 parameters.go:238] Clock(Realtime): error: 175 ns, adjusted frequency from 2299774487 Hz to 2299774953 Hz D0227 18:59:35.372837 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559572870479335 monotonicBaseRef:5000844905 monotonicFrequency:2299774652 realtimeReady:1 realtimeBaseCycles:8559572871071258 realtimeBaseRef:1582829975372651374 realtimeFrequency:2299774953} D0227 18:59:36.372452 20813 parameters.go:238] Clock(Monotonic): error: 344 ns, adjusted frequency from 2299774652 Hz to 2299775262 Hz D0227 18:59:36.372710 20813 parameters.go:238] Clock(Realtime): error: 14 ns, adjusted frequency from 2299774953 Hz to 2299774522 Hz D0227 18:59:36.372869 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559575170346686 monotonicBaseRef:6000885212 monotonicFrequency:2299775262 realtimeReady:1 realtimeBaseCycles:8559575170966873 realtimeBaseRef:1582829976372703840 realtimeFrequency:2299774522} D0227 18:59:37.372581 20813 parameters.go:238] Clock(Monotonic): error: -150 ns, adjusted frequency from 2299775262 Hz to 2299774314 Hz D0227 18:59:37.372835 20813 parameters.go:238] Clock(Realtime): error: 216 ns, adjusted frequency from 2299774522 Hz to 2299775079 Hz D0227 18:59:37.372948 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559577470390441 monotonicBaseRef:7001001959 monotonicFrequency:2299774314 realtimeReady:1 realtimeBaseCycles:8559577471030979 realtimeBaseRef:1582829977372829758 realtimeFrequency:2299775079} D0227 18:59:38.371860 20813 parameters.go:238] Clock(Monotonic): error: 242 ns, adjusted frequency from 2299774314 Hz to 2299775107 Hz D0227 18:59:38.372046 20813 parameters.go:238] Clock(Realtime): error: -111 ns, adjusted frequency from 2299775079 Hz to 2299774348 Hz D0227 18:59:38.372181 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559579768503166 monotonicBaseRef:8000279458 monotonicFrequency:2299775107 realtimeReady:1 realtimeBaseCycles:8559579768990778 realtimeBaseRef:1582829978372040428 realtimeFrequency:2299774348} D0227 18:59:39.372428 20813 parameters.go:238] Clock(Monotonic): error: -159 ns, adjusted frequency from 2299775107 Hz to 2299774308 Hz D0227 18:59:39.372679 20813 parameters.go:238] Clock(Realtime): error: 217 ns, adjusted frequency from 2299774348 Hz to 2299775122 Hz D0227 18:59:39.372778 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559582069619992 monotonicBaseRef:9000862871 monotonicFrequency:2299774308 realtimeReady:1 realtimeBaseCycles:8559582070221714 realtimeBaseRef:1582829979372673789 realtimeFrequency:2299775122} D0227 18:59:40.372926 20813 parameters.go:238] Clock(Monotonic): error: 13 ns, adjusted frequency from 2299774308 Hz to 2299774742 Hz D0227 18:59:40.373133 20813 parameters.go:238] Clock(Realtime): error: -236 ns, adjusted frequency from 2299775122 Hz to 2299774178 Hz D0227 18:59:40.373256 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559584370529392 monotonicBaseRef:10001356437 monotonicFrequency:2299774742 realtimeReady:1 realtimeBaseCycles:8559584371039330 realtimeBaseRef:1582829980373127091 realtimeFrequency:2299774178} D0227 18:59:41.372568 20813 parameters.go:238] Clock(Monotonic): error: 353 ns, adjusted frequency from 2299774742 Hz to 2299775458 Hz D0227 18:59:41.372792 20813 parameters.go:238] Clock(Realtime): error: 270 ns, adjusted frequency from 2299774178 Hz to 2299775296 Hz D0227 18:59:41.372908 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559586669469398 monotonicBaseRef:11000993472 monotonicFrequency:2299775458 realtimeReady:1 realtimeBaseCycles:8559586670027615 realtimeBaseRef:1582829981372785364 realtimeFrequency:2299775296} D0227 18:59:42.372022 20813 parameters.go:238] Clock(Monotonic): error: -180 ns, adjusted frequency from 2299775458 Hz to 2299774305 Hz D0227 18:59:42.372246 20813 parameters.go:238] Clock(Realtime): error: -10 ns, adjusted frequency from 2299775296 Hz to 2299774684 Hz D0227 18:59:42.372383 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559588967990893 monotonicBaseRef:12000448217 monotonicFrequency:2299774305 realtimeReady:1 realtimeBaseCycles:8559588968540105 realtimeBaseRef:1582829982372236264 realtimeFrequency:2299774684} D0227 18:59:43.372436 20813 parameters.go:238] Clock(Monotonic): error: -80 ns, adjusted frequency from 2299774305 Hz to 2299774543 Hz D0227 18:59:43.372683 20813 parameters.go:238] Clock(Realtime): error: -255 ns, adjusted frequency from 2299774684 Hz to 2299774171 Hz D0227 18:59:43.372810 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559591268716403 monotonicBaseRef:13000861824 monotonicFrequency:2299774543 realtimeReady:1 realtimeBaseCycles:8559591269328150 realtimeBaseRef:1582829983372676898 realtimeFrequency:2299774171} D0227 18:59:44.373291 20813 parameters.go:238] Clock(Monotonic): error: 314 ns, adjusted frequency from 2299774543 Hz to 2299775380 Hz D0227 18:59:44.373548 20813 parameters.go:238] Clock(Realtime): error: 248 ns, adjusted frequency from 2299774171 Hz to 2299775274 Hz D0227 18:59:44.373676 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559593570467337 monotonicBaseRef:14001721208 monotonicFrequency:2299775380 realtimeReady:1 realtimeBaseCycles:8559593571093595 realtimeBaseRef:1582829984373542754 realtimeFrequency:2299775274} D0227 18:59:45.372560 20813 parameters.go:238] Clock(Monotonic): error: -287 ns, adjusted frequency from 2299775380 Hz to 2299774154 Hz D0227 18:59:45.372829 20813 parameters.go:238] Clock(Realtime): error: 52 ns, adjusted frequency from 2299775274 Hz to 2299774865 Hz D0227 18:59:45.372965 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559595868556295 monotonicBaseRef:15000987909 monotonicFrequency:2299774154 realtimeReady:1 realtimeBaseCycles:8559595869214679 realtimeBaseRef:1582829985372823470 realtimeFrequency:2299774865} D0227 18:59:46.372921 20813 parameters.go:238] Clock(Monotonic): error: -54 ns, adjusted frequency from 2299774154 Hz to 2299774584 Hz D0227 18:59:46.373169 20813 parameters.go:238] Clock(Realtime): error: -23 ns, adjusted frequency from 2299774865 Hz to 2299774679 Hz D0227 18:59:46.373322 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559598169119669 monotonicBaseRef:16001331081 monotonicFrequency:2299774584 realtimeReady:1 realtimeBaseCycles:8559598169766168 realtimeBaseRef:1582829986373161165 realtimeFrequency:2299774679} D0227 18:59:47.371930 20813 parameters.go:238] Clock(Monotonic): error: 351 ns, adjusted frequency from 2299774584 Hz to 2299775564 Hz D0227 18:59:47.372166 20813 parameters.go:238] Clock(Realtime): error: -142 ns, adjusted frequency from 2299774679 Hz to 2299774399 Hz D0227 18:59:47.372308 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559600466659306 monotonicBaseRef:17000359269 monotonicFrequency:2299775564 realtimeReady:1 realtimeBaseCycles:8559600467239914 realtimeBaseRef:1582829987372160661 realtimeFrequency:2299774399} D0227 18:59:48.372098 20813 parameters.go:238] Clock(Monotonic): error: -271 ns, adjusted frequency from 2299775564 Hz to 2299774093 Hz D0227 18:59:48.372359 20813 parameters.go:238] Clock(Realtime): error: 245 ns, adjusted frequency from 2299774399 Hz to 2299775239 Hz D0227 18:59:48.372537 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559602766807342 monotonicBaseRef:18000521229 monotonicFrequency:2299774093 realtimeReady:1 realtimeBaseCycles:8559602767455803 realtimeBaseRef:1582829988372352632 realtimeFrequency:2299775239} D0227 18:59:49.371870 20813 parameters.go:238] Clock(Monotonic): error: 472 ns, adjusted frequency from 2299774093 Hz to 2299775774 Hz D0227 18:59:49.372116 20813 parameters.go:238] Clock(Realtime): error: -111 ns, adjusted frequency from 2299775239 Hz to 2299774405 Hz D0227 18:59:49.372255 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559605066084769 monotonicBaseRef:19000305266 monotonicFrequency:2299775774 realtimeReady:1 realtimeBaseCycles:8559605066672683 realtimeBaseRef:1582829989372109843 realtimeFrequency:2299774405} D0227 18:59:50.372076 20813 parameters.go:238] Clock(Monotonic): error: -104 ns, adjusted frequency from 2299775774 Hz to 2299774481 Hz D0227 18:59:50.372365 20813 parameters.go:238] Clock(Realtime): error: -18 ns, adjusted frequency from 2299774405 Hz to 2299774661 Hz D0227 18:59:50.372513 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559607366313935 monotonicBaseRef:20000502412 monotonicFrequency:2299774481 realtimeReady:1 realtimeBaseCycles:8559607367019735 realtimeBaseRef:1582829990372358844 realtimeFrequency:2299774661} D0227 18:59:51.372949 20813 parameters.go:238] Clock(Monotonic): error: -296 ns, adjusted frequency from 2299774481 Hz to 2299774025 Hz D0227 18:59:51.373154 20813 parameters.go:238] Clock(Realtime): error: -330 ns, adjusted frequency from 2299774661 Hz to 2299773990 Hz D0227 18:59:51.373312 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559609668111524 monotonicBaseRef:21001382110 monotonicFrequency:2299774025 realtimeReady:1 realtimeBaseCycles:8559609668610326 realtimeBaseRef:1582829991373148456 realtimeFrequency:2299773990} D0227 18:59:52.371825 20813 parameters.go:238] Clock(Monotonic): error: -164 ns, adjusted frequency from 2299774025 Hz to 2299774345 Hz D0227 18:59:52.372097 20813 parameters.go:238] Clock(Realtime): error: 72 ns, adjusted frequency from 2299773990 Hz to 2299774887 Hz D0227 18:59:52.372208 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559611965295314 monotonicBaseRef:22000255810 monotonicFrequency:2299774345 realtimeReady:1 realtimeBaseCycles:8559611965952757 realtimeBaseRef:1582829992372091152 realtimeFrequency:2299774887} D0227 18:59:53.371850 20813 parameters.go:238] Clock(Monotonic): error: 19 ns, adjusted frequency from 2299774345 Hz to 2299774829 Hz D0227 18:59:53.372114 20813 parameters.go:238] Clock(Realtime): error: 317 ns, adjusted frequency from 2299774887 Hz to 2299775425 Hz D0227 18:59:53.372259 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559614265124059 monotonicBaseRef:23000279464 monotonicFrequency:2299774829 realtimeReady:1 realtimeBaseCycles:8559614265766611 realtimeBaseRef:1582829993372108095 realtimeFrequency:2299775425} D0227 18:59:54.372112 20813 parameters.go:238] Clock(Monotonic): error: 327 ns, adjusted frequency from 2299774829 Hz to 2299775421 Hz D0227 18:59:54.372367 20813 parameters.go:238] Clock(Realtime): error: -277 ns, adjusted frequency from 2299775425 Hz to 2299774154 Hz D0227 18:59:54.372520 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559616565509319 monotonicBaseRef:24000544894 monotonicFrequency:2299775421 realtimeReady:1 realtimeBaseCycles:8559616566112863 realtimeBaseRef:1582829994372356304 realtimeFrequency:2299774154} D0227 18:59:55.371972 20813 parameters.go:238] Clock(Monotonic): error: -367 ns, adjusted frequency from 2299775421 Hz to 2299773884 Hz D0227 18:59:55.372251 20813 parameters.go:238] Clock(Realtime): error: 214 ns, adjusted frequency from 2299774154 Hz to 2299775202 Hz D0227 18:59:55.372386 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559618864951962 monotonicBaseRef:25000400193 monotonicFrequency:2299773884 realtimeReady:1 realtimeBaseCycles:8559618865630759 realtimeBaseRef:1582829995372244876 realtimeFrequency:2299775202} D0227 18:59:56.371928 20813 parameters.go:238] Clock(Monotonic): error: 238 ns, adjusted frequency from 2299773884 Hz to 2299775344 Hz D0227 18:59:56.372172 20813 parameters.go:238] Clock(Realtime): error: 41 ns, adjusted frequency from 2299775202 Hz to 2299774801 Hz D0227 18:59:56.372269 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559621164515626 monotonicBaseRef:26000308784 monotonicFrequency:2299775344 realtimeReady:1 realtimeBaseCycles:8559621165224672 realtimeBaseRef:1582829996372166046 realtimeFrequency:2299774801} D0227 18:59:57.373260 20813 parameters.go:238] Clock(Monotonic): error: 9 ns, adjusted frequency from 2299775344 Hz to 2299774670 Hz D0227 18:59:57.373465 20813 parameters.go:238] Clock(Realtime): error: -27 ns, adjusted frequency from 2299774801 Hz to 2299774686 Hz D0227 18:59:57.373605 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559623467449756 monotonicBaseRef:27001682303 monotonicFrequency:2299774670 realtimeReady:1 realtimeBaseCycles:8559623467973641 realtimeBaseRef:1582829997373459289 realtimeFrequency:2299774686} D0227 18:59:58.371902 20813 parameters.go:238] Clock(Monotonic): error: 285 ns, adjusted frequency from 2299774670 Hz to 2299775361 Hz D0227 18:59:58.372134 20813 parameters.go:238] Clock(Realtime): error: -17 ns, adjusted frequency from 2299774686 Hz to 2299774694 Hz D0227 18:59:58.372271 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559625764089588 monotonicBaseRef:28000319196 monotonicFrequency:2299775361 realtimeReady:1 realtimeBaseCycles:8559625764686246 realtimeBaseRef:1582829998372127819 realtimeFrequency:2299774694} D0227 18:59:59.372678 20813 parameters.go:238] Clock(Monotonic): error: 472 ns, adjusted frequency from 2299775361 Hz to 2299775896 Hz D0227 18:59:59.372887 20813 parameters.go:238] Clock(Realtime): error: -61 ns, adjusted frequency from 2299774694 Hz to 2299774554 Hz D0227 18:59:59.373021 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559628065688810 monotonicBaseRef:29001112256 monotonicFrequency:2299775896 realtimeReady:1 realtimeBaseCycles:8559628066193323 realtimeBaseRef:1582829999372881102 realtimeFrequency:2299774554} D0227 19:00:00.371923 20813 parameters.go:238] Clock(Monotonic): error: -1038 ns, adjusted frequency from 2299775896 Hz to 2299772340 Hz D0227 19:00:00.372160 20813 parameters.go:238] Clock(Realtime): error: 20 ns, adjusted frequency from 2299774554 Hz to 2299774727 Hz D0227 19:00:00.372277 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559630363721332 monotonicBaseRef:30000354193 monotonicFrequency:2299772340 realtimeReady:1 realtimeBaseCycles:8559630364297501 realtimeBaseRef:1582830000372154780 realtimeFrequency:2299774727} D0227 19:00:01.371874 20813 parameters.go:238] Clock(Monotonic): error: 158 ns, adjusted frequency from 2299772340 Hz to 2299775095 Hz D0227 19:00:01.372161 20813 parameters.go:238] Clock(Realtime): error: 369 ns, adjusted frequency from 2299774727 Hz to 2299775530 Hz D0227 19:00:01.372304 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559632663386701 monotonicBaseRef:31000307679 monotonicFrequency:2299775095 realtimeReady:1 realtimeBaseCycles:8559632664067701 realtimeBaseRef:1582830001372152811 realtimeFrequency:2299775530} D0227 19:00:02.372459 20813 parameters.go:238] Clock(Monotonic): error: -191 ns, adjusted frequency from 2299775095 Hz to 2299774276 Hz D0227 19:00:02.372700 20813 parameters.go:238] Clock(Realtime): error: -262 ns, adjusted frequency from 2299775530 Hz to 2299774135 Hz D0227 19:00:02.372856 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559634964492398 monotonicBaseRef:32000886258 monotonicFrequency:2299774276 realtimeReady:1 realtimeBaseCycles:8559634965086503 realtimeBaseRef:1582830002372693416 realtimeFrequency:2299774135} D0227 19:00:03.371971 20813 parameters.go:238] Clock(Monotonic): error: -22 ns, adjusted frequency from 2299774276 Hz to 2299774736 Hz D0227 19:00:03.372203 20813 parameters.go:238] Clock(Realtime): error: -50 ns, adjusted frequency from 2299774135 Hz to 2299774551 Hz D0227 19:00:03.372352 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559637263137893 monotonicBaseRef:33000395435 monotonicFrequency:2299774736 realtimeReady:1 realtimeBaseCycles:8559637263717602 realtimeBaseRef:1582830003372196395 realtimeFrequency:2299774551} D0227 19:00:04.373565 20813 parameters.go:238] Clock(Monotonic): error: 88 ns, adjusted frequency from 2299774736 Hz to 2299774923 Hz D0227 19:00:04.373760 20813 parameters.go:238] Clock(Realtime): error: 60 ns, adjusted frequency from 2299774551 Hz to 2299774859 Hz D0227 19:00:04.373894 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559639566605994 monotonicBaseRef:34002001403 monotonicFrequency:2299774923 realtimeReady:1 realtimeBaseCycles:8559639567073849 realtimeBaseRef:1582830004373753806 realtimeFrequency:2299774859} D0227 19:00:05.238523 20813 urpc.go:577] urpc: unmarshal success. D0227 19:00:05.239510 20813 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0227 19:00:05.239789 20813 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 19:00:05.371947 20813 parameters.go:238] Clock(Monotonic): error: 285 ns, adjusted frequency from 2299774923 Hz to 2299775278 Hz D0227 19:00:05.372183 20813 parameters.go:238] Clock(Realtime): error: -3 ns, adjusted frequency from 2299774859 Hz to 2299774717 Hz D0227 19:00:05.372338 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559641862628228 monotonicBaseRef:35000369639 monotonicFrequency:2299775278 realtimeReady:1 realtimeBaseCycles:8559641863221225 realtimeBaseRef:1582830005372176485 realtimeFrequency:2299774717} D0227 19:00:06.372063 20813 parameters.go:238] Clock(Monotonic): error: -60 ns, adjusted frequency from 2299775278 Hz to 2299774569 Hz D0227 19:00:06.372288 20813 parameters.go:238] Clock(Realtime): error: 754 ns, adjusted frequency from 2299774717 Hz to 2299776558 Hz D0227 19:00:06.373223 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559644162650085 monotonicBaseRef:36000476857 monotonicFrequency:2299774569 realtimeReady:1 realtimeBaseCycles:8559644163236181 realtimeBaseRef:1582830006372280946 realtimeFrequency:2299776558} D0227 19:00:07.372877 20813 parameters.go:238] Clock(Monotonic): error: 181 ns, adjusted frequency from 2299774569 Hz to 2299775118 Hz D0227 19:00:07.373110 20813 parameters.go:238] Clock(Realtime): error: -1103 ns, adjusted frequency from 2299776558 Hz to 2299772221 Hz D0227 19:00:07.373240 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559646464292810 monotonicBaseRef:37001289178 monotonicFrequency:2299775118 realtimeReady:1 realtimeBaseCycles:8559646464894569 realtimeBaseRef:1582830007373099212 realtimeFrequency:2299772221} D0227 19:00:08.371807 20813 parameters.go:238] Clock(Monotonic): error: -115 ns, adjusted frequency from 2299775118 Hz to 2299774309 Hz D0227 19:00:08.372006 20813 parameters.go:238] Clock(Realtime): error: 253 ns, adjusted frequency from 2299772221 Hz to 2299775339 Hz D0227 19:00:08.372130 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559648761660175 monotonicBaseRef:38000242226 monotonicFrequency:2299774309 realtimeReady:1 realtimeBaseCycles:8559648762139432 realtimeBaseRef:1582830008372000251 realtimeFrequency:2299775339} D0227 19:00:09.371835 20813 parameters.go:238] Clock(Monotonic): error: 43 ns, adjusted frequency from 2299774309 Hz to 2299774767 Hz D0227 19:00:09.372049 20813 parameters.go:238] Clock(Realtime): error: -64 ns, adjusted frequency from 2299775339 Hz to 2299774574 Hz D0227 19:00:09.372175 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559651061497636 monotonicBaseRef:39000269686 monotonicFrequency:2299774767 realtimeReady:1 realtimeBaseCycles:8559651062013952 realtimeBaseRef:1582830009372043377 realtimeFrequency:2299774574} D0227 19:00:10.371850 20813 parameters.go:238] Clock(Monotonic): error: -254 ns, adjusted frequency from 2299774767 Hz to 2299774120 Hz D0227 19:00:10.372062 20813 parameters.go:238] Clock(Realtime): error: -261 ns, adjusted frequency from 2299774574 Hz to 2299774150 Hz D0227 19:00:10.372194 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559653361289350 monotonicBaseRef:40000277054 monotonicFrequency:2299774120 realtimeReady:1 realtimeBaseCycles:8559653361815697 realtimeBaseRef:1582830010372055191 realtimeFrequency:2299774150} D0227 19:00:11.371870 20813 parameters.go:238] Clock(Monotonic): error: 359 ns, adjusted frequency from 2299774120 Hz to 2299775496 Hz D0227 19:00:11.372104 20813 parameters.go:238] Clock(Realtime): error: 304 ns, adjusted frequency from 2299774150 Hz to 2299775413 Hz D0227 19:00:11.372231 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559655661127717 monotonicBaseRef:41000304990 monotonicFrequency:2299775496 realtimeReady:1 realtimeBaseCycles:8559655661687480 realtimeBaseRef:1582830011372097644 realtimeFrequency:2299775413} D0227 19:00:12.371866 20813 parameters.go:238] Clock(Monotonic): error: -312 ns, adjusted frequency from 2299775496 Hz to 2299773995 Hz D0227 19:00:12.372124 20813 parameters.go:238] Clock(Realtime): error: -256 ns, adjusted frequency from 2299775413 Hz to 2299774182 Hz D0227 19:00:12.372285 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559657960884896 monotonicBaseRef:42000297025 monotonicFrequency:2299773995 realtimeReady:1 realtimeBaseCycles:8559657961508238 realtimeBaseRef:1582830012372117361 realtimeFrequency:2299774182} D0227 19:00:13.372304 20813 parameters.go:238] Clock(Monotonic): error: 118 ns, adjusted frequency from 2299773995 Hz to 2299774994 Hz D0227 19:00:13.372558 20813 parameters.go:238] Clock(Realtime): error: 425 ns, adjusted frequency from 2299774182 Hz to 2299775656 Hz D0227 19:00:13.372732 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559660261635294 monotonicBaseRef:43000721589 monotonicFrequency:2299774994 realtimeReady:1 realtimeBaseCycles:8559660262268261 realtimeBaseRef:1582830013372546029 realtimeFrequency:2299775656} D0227 19:00:14.372772 20813 parameters.go:238] Clock(Monotonic): error: 742 ns, adjusted frequency from 2299774994 Hz to 2299776560 Hz D0227 19:00:14.372982 20813 parameters.go:238] Clock(Realtime): error: -165 ns, adjusted frequency from 2299775656 Hz to 2299774351 Hz D0227 19:00:14.373152 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559662562529964 monotonicBaseRef:44001208452 monotonicFrequency:2299776560 realtimeReady:1 realtimeBaseCycles:8559662563032651 realtimeBaseRef:1582830014372975955 realtimeFrequency:2299774351} D0227 19:00:15.372015 20813 parameters.go:238] Clock(Monotonic): error: -553 ns, adjusted frequency from 2299776560 Hz to 2299773483 Hz D0227 19:00:15.372244 20813 parameters.go:238] Clock(Realtime): error: 31 ns, adjusted frequency from 2299774351 Hz to 2299774654 Hz D0227 19:00:15.372372 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559664860557199 monotonicBaseRef:45000447802 monotonicFrequency:2299773483 realtimeReady:1 realtimeBaseCycles:8559664861107452 realtimeBaseRef:1582830015372236947 realtimeFrequency:2299774654} I0227 19:00:15.520361 20813 watchdog.go:277] Watchdog starting loop, tasks: 12, discount: 0s D0227 19:00:16.371906 20813 parameters.go:238] Clock(Monotonic): error: 40 ns, adjusted frequency from 2299773483 Hz to 2299774832 Hz D0227 19:00:16.372141 20813 parameters.go:238] Clock(Realtime): error: -229 ns, adjusted frequency from 2299774654 Hz to 2299774197 Hz D0227 19:00:16.372290 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559667160007454 monotonicBaseRef:46000307254 monotonicFrequency:2299774832 realtimeReady:1 realtimeBaseCycles:8559667160644022 realtimeBaseRef:1582830016372133422 realtimeFrequency:2299774197} D0227 19:00:17.372292 20813 parameters.go:238] Clock(Monotonic): error: -355 ns, adjusted frequency from 2299774832 Hz to 2299774007 Hz D0227 19:00:17.372511 20813 parameters.go:238] Clock(Realtime): error: 389 ns, adjusted frequency from 2299774197 Hz to 2299775609 Hz D0227 19:00:17.372682 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559669460745743 monotonicBaseRef:47000726189 monotonicFrequency:2299774007 realtimeReady:1 realtimeBaseCycles:8559669461271065 realtimeBaseRef:1582830017372504261 realtimeFrequency:2299775609} D0227 19:00:18.373306 20813 parameters.go:238] Clock(Monotonic): error: 181 ns, adjusted frequency from 2299774007 Hz to 2299775143 Hz D0227 19:00:18.373528 20813 parameters.go:238] Clock(Realtime): error: -61 ns, adjusted frequency from 2299775609 Hz to 2299774579 Hz D0227 19:00:18.373625 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559671762857159 monotonicBaseRef:48001742553 monotonicFrequency:2299775143 realtimeReady:1 realtimeBaseCycles:8559671763388378 realtimeBaseRef:1582830018373522492 realtimeFrequency:2299774579} D0227 19:00:19.371848 20813 parameters.go:238] Clock(Monotonic): error: 84 ns, adjusted frequency from 2299775143 Hz to 2299774849 Hz D0227 19:00:19.372068 20813 parameters.go:238] Clock(Realtime): error: -54 ns, adjusted frequency from 2299774579 Hz to 2299774569 Hz D0227 19:00:19.372186 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559674059278430 monotonicBaseRef:49000284205 monotonicFrequency:2299774849 realtimeReady:1 realtimeBaseCycles:8559674059790201 realtimeBaseRef:1582830019372055932 realtimeFrequency:2299774569} D0227 19:00:20.371868 20813 parameters.go:238] Clock(Monotonic): error: -10 ns, adjusted frequency from 2299774849 Hz to 2299774716 Hz D0227 19:00:20.372091 20813 parameters.go:238] Clock(Realtime): error: -320 ns, adjusted frequency from 2299774569 Hz to 2299774040 Hz D0227 19:00:20.372233 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559676359072427 monotonicBaseRef:50000292531 monotonicFrequency:2299774716 realtimeReady:1 realtimeBaseCycles:8559676359629640 realtimeBaseRef:1582830020372084139 realtimeFrequency:2299774040} D0227 19:00:21.372496 20813 parameters.go:238] Clock(Monotonic): error: -69 ns, adjusted frequency from 2299774716 Hz to 2299774475 Hz D0227 19:00:21.372704 20813 parameters.go:238] Clock(Realtime): error: 282 ns, adjusted frequency from 2299774040 Hz to 2299775333 Hz D0227 19:00:21.372812 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559678660316670 monotonicBaseRef:51000931518 monotonicFrequency:2299774475 realtimeReady:1 realtimeBaseCycles:8559678660816287 realtimeBaseRef:1582830021372698376 realtimeFrequency:2299775333} D0227 19:00:22.371861 20813 parameters.go:238] Clock(Monotonic): error: 430 ns, adjusted frequency from 2299774475 Hz to 2299775728 Hz D0227 19:00:22.372058 20813 parameters.go:238] Clock(Realtime): error: -27 ns, adjusted frequency from 2299775333 Hz to 2299774694 Hz D0227 19:00:22.372164 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559680958624132 monotonicBaseRef:52000293623 monotonicFrequency:2299775728 realtimeReady:1 realtimeBaseCycles:8559680959106528 realtimeBaseRef:1582830022372052620 realtimeFrequency:2299774694} D0227 19:00:23.371795 20813 parameters.go:238] Clock(Monotonic): error: -420 ns, adjusted frequency from 2299775728 Hz to 2299773660 Hz D0227 19:00:23.372022 20813 parameters.go:238] Clock(Realtime): error: 13 ns, adjusted frequency from 2299774694 Hz to 2299774733 Hz D0227 19:00:23.372146 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559683258251304 monotonicBaseRef:53000229027 monotonicFrequency:2299773660 realtimeReady:1 realtimeBaseCycles:8559683258796040 realtimeBaseRef:1582830023372015580 realtimeFrequency:2299774733} D0227 19:00:24.372485 20813 parameters.go:238] Clock(Monotonic): error: -118 ns, adjusted frequency from 2299773660 Hz to 2299774443 Hz D0227 19:00:24.372711 20813 parameters.go:238] Clock(Realtime): error: 67 ns, adjusted frequency from 2299774733 Hz to 2299774920 Hz D0227 19:00:24.372848 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559685559618297 monotonicBaseRef:54000921848 monotonicFrequency:2299774443 realtimeReady:1 realtimeBaseCycles:8559685560155430 realtimeBaseRef:1582830024372704628 realtimeFrequency:2299774920} D0227 19:00:25.372536 20813 parameters.go:238] Clock(Monotonic): error: 147 ns, adjusted frequency from 2299774443 Hz to 2299774974 Hz D0227 19:00:25.372745 20813 parameters.go:238] Clock(Realtime): error: -126 ns, adjusted frequency from 2299774920 Hz to 2299774380 Hz D0227 19:00:25.372895 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559687859509226 monotonicBaseRef:55000972499 monotonicFrequency:2299774974 realtimeReady:1 realtimeBaseCycles:8559687859981425 realtimeBaseRef:1582830025372726836 realtimeFrequency:2299774380} D0227 19:00:26.373305 20813 parameters.go:238] Clock(Monotonic): error: -252 ns, adjusted frequency from 2299774974 Hz to 2299774143 Hz D0227 19:00:26.373516 20813 parameters.go:238] Clock(Realtime): error: 99 ns, adjusted frequency from 2299774380 Hz to 2299774961 Hz D0227 19:00:26.373625 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559690161013251 monotonicBaseRef:56001724333 monotonicFrequency:2299774143 realtimeReady:1 realtimeBaseCycles:8559690161556372 realtimeBaseRef:1582830026373509768 realtimeFrequency:2299774961} D0227 19:00:27.372296 20813 parameters.go:238] Clock(Monotonic): error: 29 ns, adjusted frequency from 2299774143 Hz to 2299774820 Hz D0227 19:00:27.372506 20813 parameters.go:238] Clock(Realtime): error: -59 ns, adjusted frequency from 2299774961 Hz to 2299774565 Hz D0227 19:00:27.372653 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559692458475466 monotonicBaseRef:57000719048 monotonicFrequency:2299774820 realtimeReady:1 realtimeBaseCycles:8559692459009887 realtimeBaseRef:1582830027372500344 realtimeFrequency:2299774565} D0227 19:00:28.372097 20813 parameters.go:238] Clock(Monotonic): error: 118 ns, adjusted frequency from 2299774820 Hz to 2299775043 Hz D0227 19:00:28.372291 20813 parameters.go:238] Clock(Realtime): error: 18 ns, adjusted frequency from 2299774565 Hz to 2299774725 Hz D0227 19:00:28.372424 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559694757828015 monotonicBaseRef:58000535433 monotonicFrequency:2299775043 realtimeReady:1 realtimeBaseCycles:8559694758289025 realtimeBaseRef:1582830028372284919 realtimeFrequency:2299774725} D0227 19:00:29.371938 20813 parameters.go:238] Clock(Monotonic): error: 507 ns, adjusted frequency from 2299775043 Hz to 2299775985 Hz D0227 19:00:29.372231 20813 parameters.go:238] Clock(Realtime): error: 167 ns, adjusted frequency from 2299774725 Hz to 2299775039 Hz D0227 19:00:29.372395 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559697057215219 monotonicBaseRef:59000366790 monotonicFrequency:2299775985 realtimeReady:1 realtimeBaseCycles:8559697057924134 realtimeBaseRef:1582830029372224210 realtimeFrequency:2299775039} D0227 19:00:30.371898 20813 parameters.go:238] Clock(Monotonic): error: -318 ns, adjusted frequency from 2299775985 Hz to 2299774009 Hz D0227 19:00:30.372109 20813 parameters.go:238] Clock(Realtime): error: -110 ns, adjusted frequency from 2299775039 Hz to 2299774450 Hz D0227 19:00:30.372247 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559699356872047 monotonicBaseRef:60000314977 monotonicFrequency:2299774009 realtimeReady:1 realtimeBaseCycles:8559699357418606 realtimeBaseRef:1582830030372102212 realtimeFrequency:2299774450} D0227 19:00:31.372030 20813 parameters.go:238] Clock(Monotonic): error: -186 ns, adjusted frequency from 2299774009 Hz to 2299774100 Hz D0227 19:00:31.372291 20813 parameters.go:238] Clock(Realtime): error: -258 ns, adjusted frequency from 2299774450 Hz to 2299774166 Hz D0227 19:00:31.372432 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559701656970781 monotonicBaseRef:61000456175 monotonicFrequency:2299774100 realtimeReady:1 realtimeBaseCycles:8559701657613795 realtimeBaseRef:1582830031372285159 realtimeFrequency:2299774166} D0227 19:00:32.371963 20813 parameters.go:238] Clock(Monotonic): error: -182 ns, adjusted frequency from 2299774100 Hz to 2299774339 Hz D0227 19:00:32.372292 20813 parameters.go:238] Clock(Realtime): error: 287 ns, adjusted frequency from 2299774166 Hz to 2299775351 Hz D0227 19:00:32.372436 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559703956606935 monotonicBaseRef:62000396192 monotonicFrequency:2299774339 realtimeReady:1 realtimeBaseCycles:8559703957388622 realtimeBaseRef:1582830032372285446 realtimeFrequency:2299775351} D0227 19:00:33.372491 20813 parameters.go:238] Clock(Monotonic): error: -76 ns, adjusted frequency from 2299774339 Hz to 2299774589 Hz D0227 19:00:33.372720 20813 parameters.go:238] Clock(Realtime): error: -183 ns, adjusted frequency from 2299775351 Hz to 2299774267 Hz D0227 19:00:33.372885 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559706257583917 monotonicBaseRef:63000919131 monotonicFrequency:2299774589 realtimeReady:1 realtimeBaseCycles:8559706258152262 realtimeBaseRef:1582830033372715178 realtimeFrequency:2299774267} D0227 19:00:34.372856 20813 parameters.go:238] Clock(Monotonic): error: 1131 ns, adjusted frequency from 2299774589 Hz to 2299777508 Hz D0227 19:00:34.373087 20813 parameters.go:238] Clock(Realtime): error: 477 ns, adjusted frequency from 2299774267 Hz to 2299775804 Hz D0227 19:00:34.373217 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559708558185620 monotonicBaseRef:64001278781 monotonicFrequency:2299777508 realtimeReady:1 realtimeBaseCycles:8559708558767243 realtimeBaseRef:1582830034373080741 realtimeFrequency:2299775804} D0227 19:00:35.371999 20813 parameters.go:238] Clock(Monotonic): error: -1167 ns, adjusted frequency from 2299777508 Hz to 2299772043 Hz D0227 19:00:35.372235 20813 parameters.go:238] Clock(Realtime): error: -369 ns, adjusted frequency from 2299775804 Hz to 2299773835 Hz D0227 19:00:35.372357 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559710856009783 monotonicBaseRef:65000429418 monotonicFrequency:2299772043 realtimeReady:1 realtimeBaseCycles:8559710856571850 realtimeBaseRef:1582830035372223615 realtimeFrequency:2299773835} D0227 19:00:36.371985 20813 parameters.go:238] Clock(Monotonic): error: 236 ns, adjusted frequency from 2299772043 Hz to 2299775265 Hz D0227 19:00:36.372181 20813 parameters.go:238] Clock(Realtime): error: 54 ns, adjusted frequency from 2299773835 Hz to 2299774796 Hz D0227 19:00:36.372419 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559713155720101 monotonicBaseRef:66000402578 monotonicFrequency:2299775265 realtimeReady:1 realtimeBaseCycles:8559713156229414 realtimeBaseRef:1582830036372173057 realtimeFrequency:2299774796} D0227 19:00:37.372447 20813 parameters.go:238] Clock(Monotonic): error: -274 ns, adjusted frequency from 2299775265 Hz to 2299774091 Hz D0227 19:00:37.372659 20813 parameters.go:238] Clock(Realtime): error: 59 ns, adjusted frequency from 2299774796 Hz to 2299774877 Hz D0227 19:00:37.372773 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559715456599056 monotonicBaseRef:67000882490 monotonicFrequency:2299774091 realtimeReady:1 realtimeBaseCycles:8559715457107498 realtimeBaseRef:1582830037372652794 realtimeFrequency:2299774877} D0227 19:00:37.717684 20813 urpc.go:577] urpc: unmarshal success. D0227 19:00:37.717920 20813 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0227 19:00:37.718151 20813 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 19:00:38.372654 20813 parameters.go:238] Clock(Monotonic): error: 343 ns, adjusted frequency from 2299774091 Hz to 2299775383 Hz D0227 19:00:38.372837 20813 parameters.go:238] Clock(Realtime): error: -50 ns, adjusted frequency from 2299774877 Hz to 2299774663 Hz D0227 19:00:38.372992 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559717756850672 monotonicBaseRef:68001090129 monotonicFrequency:2299775383 realtimeReady:1 realtimeBaseCycles:8559717757292471 realtimeBaseRef:1582830038372831114 realtimeFrequency:2299774663} D0227 19:00:39.372182 20813 parameters.go:238] Clock(Monotonic): error: -266 ns, adjusted frequency from 2299775383 Hz to 2299774180 Hz D0227 19:00:39.372435 20813 parameters.go:238] Clock(Realtime): error: -274 ns, adjusted frequency from 2299774663 Hz to 2299774135 Hz D0227 19:00:39.372616 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559720055518020 monotonicBaseRef:69000608327 monotonicFrequency:2299774180 realtimeReady:1 realtimeBaseCycles:8559720056140686 realtimeBaseRef:1582830039372428271 realtimeFrequency:2299774135} D0227 19:00:40.371829 20813 parameters.go:238] Clock(Monotonic): error: 330 ns, adjusted frequency from 2299774180 Hz to 2299775603 Hz D0227 19:00:40.372418 20813 parameters.go:238] Clock(Realtime): error: 293 ns, adjusted frequency from 2299774135 Hz to 2299775338 Hz D0227 19:00:40.372561 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559722354500179 monotonicBaseRef:70000263936 monotonicFrequency:2299775603 realtimeReady:1 realtimeBaseCycles:8559722355878105 realtimeBaseRef:1582830040372412305 realtimeFrequency:2299775338} D0227 19:00:41.372857 20813 parameters.go:238] Clock(Monotonic): error: -430 ns, adjusted frequency from 2299775603 Hz to 2299773724 Hz D0227 19:00:41.373326 20813 parameters.go:238] Clock(Realtime): error: 274 ns, adjusted frequency from 2299775338 Hz to 2299775347 Hz D0227 19:00:41.373445 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559724656619320 monotonicBaseRef:71001282964 monotonicFrequency:2299773724 realtimeReady:1 realtimeBaseCycles:8559724657705834 realtimeBaseRef:1582830041373304736 realtimeFrequency:2299775347} D0227 19:00:42.372729 20813 parameters.go:238] Clock(Monotonic): error: 54 ns, adjusted frequency from 2299773724 Hz to 2299774850 Hz D0227 19:00:42.372993 20813 parameters.go:238] Clock(Realtime): error: -287 ns, adjusted frequency from 2299775347 Hz to 2299774086 Hz D0227 19:00:42.373134 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559726956109681 monotonicBaseRef:72001159750 monotonicFrequency:2299774850 realtimeReady:1 realtimeBaseCycles:8559726956748259 realtimeBaseRef:1582830042372986043 realtimeFrequency:2299774086} D0227 19:00:43.372853 20813 parameters.go:238] Clock(Monotonic): error: 10 ns, adjusted frequency from 2299774850 Hz to 2299774676 Hz D0227 19:00:43.373111 20813 parameters.go:238] Clock(Realtime): error: 1 ns, adjusted frequency from 2299774086 Hz to 2299774704 Hz D0227 19:00:43.373235 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559729256177312 monotonicBaseRef:73001287058 monotonicFrequency:2299774676 realtimeReady:1 realtimeBaseCycles:8559729256795163 realtimeBaseRef:1582830043373104671 realtimeFrequency:2299774704} D0227 19:00:44.372590 20813 sampler.go:197] Time: Adjusting syscall overhead down to 7000 D0227 19:00:44.372826 20813 parameters.go:238] Clock(Monotonic): error: 49 ns, adjusted frequency from 2299774676 Hz to 2299774839 Hz D0227 19:00:44.372973 20813 parameters.go:238] Clock(Realtime): error: 73 ns, adjusted frequency from 2299774704 Hz to 2299774902 Hz D0227 19:00:44.373097 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559731555332212 monotonicBaseRef:74001017563 monotonicFrequency:2299774839 realtimeReady:1 realtimeBaseCycles:8559731556254799 realtimeBaseRef:1582830044372967671 realtimeFrequency:2299774902} D0227 19:00:45.372944 20813 parameters.go:238] Clock(Monotonic): error: 248 ns, adjusted frequency from 2299774839 Hz to 2299775207 Hz D0227 19:00:45.373213 20813 parameters.go:238] Clock(Realtime): error: -354 ns, adjusted frequency from 2299774902 Hz to 2299774009 Hz D0227 19:00:45.373347 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559733855923088 monotonicBaseRef:75001372396 monotonicFrequency:2299775207 realtimeReady:1 realtimeBaseCycles:8559733856576903 realtimeBaseRef:1582830045373205608 realtimeFrequency:2299774009} D0227 19:00:46.372496 20813 parameters.go:238] Clock(Monotonic): error: -247 ns, adjusted frequency from 2299775207 Hz to 2299774160 Hz D0227 19:00:46.372782 20813 parameters.go:238] Clock(Realtime): error: -30 ns, adjusted frequency from 2299774009 Hz to 2299774695 Hz D0227 19:00:46.372894 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559736154654999 monotonicBaseRef:76000918744 monotonicFrequency:2299774160 realtimeReady:1 realtimeBaseCycles:8559736155359933 realtimeBaseRef:1582830046372774705 realtimeFrequency:2299774695} D0227 19:00:47.371920 20813 parameters.go:238] Clock(Monotonic): error: 834 ns, adjusted frequency from 2299774160 Hz to 2299776733 Hz D0227 19:00:47.372143 20813 parameters.go:238] Clock(Realtime): error: 208 ns, adjusted frequency from 2299774695 Hz to 2299775171 Hz D0227 19:00:47.372255 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559738453127908 monotonicBaseRef:77000352927 monotonicFrequency:2299776733 realtimeReady:1 realtimeBaseCycles:8559738453669532 realtimeBaseRef:1582830047372137644 realtimeFrequency:2299775171} D0227 19:00:48.372923 20813 parameters.go:238] Clock(Monotonic): error: -875 ns, adjusted frequency from 2299776733 Hz to 2299772713 Hz D0227 19:00:48.373140 20813 parameters.go:238] Clock(Realtime): error: 3 ns, adjusted frequency from 2299775171 Hz to 2299774693 Hz D0227 19:00:48.373255 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559740755189893 monotonicBaseRef:78001346611 monotonicFrequency:2299772713 realtimeReady:1 realtimeBaseCycles:8559740755728369 realtimeBaseRef:1582830048373130639 realtimeFrequency:2299774693} D0227 19:00:49.372967 20813 parameters.go:238] Clock(Monotonic): error: -83 ns, adjusted frequency from 2299772713 Hz to 2299774562 Hz D0227 19:00:49.373224 20813 parameters.go:238] Clock(Realtime): error: -212 ns, adjusted frequency from 2299774693 Hz to 2299774279 Hz D0227 19:00:49.373359 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559743055085083 monotonicBaseRef:79001399867 monotonicFrequency:2299774562 realtimeReady:1 realtimeBaseCycles:8559743055703096 realtimeBaseRef:1582830049373217618 realtimeFrequency:2299774279} D0227 19:00:50.372901 20813 parameters.go:238] Clock(Monotonic): error: 43 ns, adjusted frequency from 2299774562 Hz to 2299774824 Hz D0227 19:00:50.373171 20813 parameters.go:238] Clock(Realtime): error: 262 ns, adjusted frequency from 2299774279 Hz to 2299775320 Hz D0227 19:00:50.373307 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559745354696763 monotonicBaseRef:80001329041 monotonicFrequency:2299774824 realtimeReady:1 realtimeBaseCycles:8559745355356431 realtimeBaseRef:1582830050373165028 realtimeFrequency:2299775320} D0227 19:00:51.372916 20813 parameters.go:238] Clock(Monotonic): error: 223 ns, adjusted frequency from 2299774824 Hz to 2299775231 Hz D0227 19:00:51.373260 20813 parameters.go:238] Clock(Realtime): error: 486 ns, adjusted frequency from 2299775320 Hz to 2299775954 Hz D0227 19:00:51.373463 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559747654497509 monotonicBaseRef:81001340312 monotonicFrequency:2299775231 realtimeReady:1 realtimeBaseCycles:8559747655330648 realtimeBaseRef:1582830051373251513 realtimeFrequency:2299775954} D0227 19:00:52.371896 20813 parameters.go:238] Clock(Monotonic): error: -249 ns, adjusted frequency from 2299775231 Hz to 2299774142 Hz D0227 19:00:52.372122 20813 parameters.go:238] Clock(Realtime): error: -493 ns, adjusted frequency from 2299775954 Hz to 2299773591 Hz D0227 19:00:52.372242 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559749951910253 monotonicBaseRef:82000313043 monotonicFrequency:2299774142 realtimeReady:1 realtimeBaseCycles:8559749952492740 realtimeBaseRef:1582830052372114940 realtimeFrequency:2299773591} D0227 19:00:53.372183 20813 parameters.go:238] Clock(Monotonic): error: 220 ns, adjusted frequency from 2299774142 Hz to 2299775140 Hz D0227 19:00:53.372375 20813 parameters.go:238] Clock(Realtime): error: -145 ns, adjusted frequency from 2299773591 Hz to 2299774378 Hz D0227 19:00:53.372532 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559752252387794 monotonicBaseRef:83000618898 monotonicFrequency:2299775140 realtimeReady:1 realtimeBaseCycles:8559752252851263 realtimeBaseRef:1582830053372369283 realtimeFrequency:2299774378} D0227 19:00:54.372524 20813 parameters.go:238] Clock(Monotonic): error: -168 ns, adjusted frequency from 2299775140 Hz to 2299774418 Hz D0227 19:00:54.372763 20813 parameters.go:238] Clock(Realtime): error: 74 ns, adjusted frequency from 2299774378 Hz to 2299774822 Hz D0227 19:00:54.372920 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559754552946568 monotonicBaseRef:84000959641 monotonicFrequency:2299774418 realtimeReady:1 realtimeBaseCycles:8559754553517913 realtimeBaseRef:1582830054372757265 realtimeFrequency:2299774822} D0227 19:00:55.372491 20813 parameters.go:238] Clock(Monotonic): error: -20 ns, adjusted frequency from 2299774418 Hz to 2299774607 Hz D0227 19:00:55.372744 20813 parameters.go:238] Clock(Realtime): error: -248 ns, adjusted frequency from 2299774822 Hz to 2299774096 Hz D0227 19:00:55.372849 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559756852598159 monotonicBaseRef:85000906232 monotonicFrequency:2299774607 realtimeReady:1 realtimeBaseCycles:8559756853247535 realtimeBaseRef:1582830055372737610 realtimeFrequency:2299774096} D0227 19:00:56.373344 20813 parameters.go:238] Clock(Monotonic): error: 396 ns, adjusted frequency from 2299774607 Hz to 2299775515 Hz D0227 19:00:56.373592 20813 parameters.go:238] Clock(Realtime): error: 600 ns, adjusted frequency from 2299774096 Hz to 2299776043 Hz D0227 19:00:56.373696 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559759154311558 monotonicBaseRef:86001749267 monotonicFrequency:2299775515 realtimeReady:1 realtimeBaseCycles:8559759154970441 realtimeBaseRef:1582830056373585001 realtimeFrequency:2299776043} D0227 19:00:57.372560 20813 parameters.go:238] Clock(Monotonic): error: 23 ns, adjusted frequency from 2299775515 Hz to 2299774751 Hz D0227 19:00:57.372841 20813 parameters.go:238] Clock(Realtime): error: -541 ns, adjusted frequency from 2299776043 Hz to 2299773502 Hz D0227 19:00:57.373003 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559761452342020 monotonicBaseRef:87000990474 monotonicFrequency:2299774751 realtimeReady:1 realtimeBaseCycles:8559761453019887 realtimeBaseRef:1582830057372834233 realtimeFrequency:2299773502} D0227 19:00:58.373133 20813 parameters.go:238] Clock(Monotonic): error: -218 ns, adjusted frequency from 2299774751 Hz to 2299774227 Hz D0227 19:00:58.373368 20813 parameters.go:238] Clock(Realtime): error: 95 ns, adjusted frequency from 2299773502 Hz to 2299774941 Hz D0227 19:00:58.373523 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559763753424666 monotonicBaseRef:88001559179 monotonicFrequency:2299774227 realtimeReady:1 realtimeBaseCycles:8559763754005757 realtimeBaseRef:1582830058373361401 realtimeFrequency:2299774941} D0227 19:00:59.372071 20813 parameters.go:238] Clock(Monotonic): error: 196 ns, adjusted frequency from 2299774227 Hz to 2299775099 Hz D0227 19:00:59.372272 20813 parameters.go:238] Clock(Realtime): error: -113 ns, adjusted frequency from 2299774941 Hz to 2299774540 Hz D0227 19:00:59.372417 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559766050772580 monotonicBaseRef:89000504156 monotonicFrequency:2299775099 realtimeReady:1 realtimeBaseCycles:8559766051253704 realtimeBaseRef:1582830059372262600 realtimeFrequency:2299774540} D0227 19:01:00.280757 20813 urpc.go:577] urpc: unmarshal success. D0227 19:01:00.280996 20813 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0227 19:01:00.281231 20813 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 19:01:00.373522 20813 parameters.go:238] Clock(Monotonic): error: -274 ns, adjusted frequency from 2299775099 Hz to 2299774091 Hz D0227 19:01:00.373761 20813 parameters.go:238] Clock(Realtime): error: 242 ns, adjusted frequency from 2299774540 Hz to 2299775150 Hz D0227 19:01:00.373885 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559768353885249 monotonicBaseRef:90001955415 monotonicFrequency:2299774091 realtimeReady:1 realtimeBaseCycles:8559768354457775 realtimeBaseRef:1582830060373753846 realtimeFrequency:2299775150} I0227 19:01:00.521285 20813 watchdog.go:277] Watchdog starting loop, tasks: 12, discount: 0s D0227 19:01:01.372328 20813 parameters.go:238] Clock(Monotonic): error: 288 ns, adjusted frequency from 2299774091 Hz to 2299775288 Hz D0227 19:01:01.372522 20813 parameters.go:238] Clock(Realtime): error: 129 ns, adjusted frequency from 2299775150 Hz to 2299775018 Hz D0227 19:01:01.372673 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559770650891784 monotonicBaseRef:91000752011 monotonicFrequency:2299775288 realtimeReady:1 realtimeBaseCycles:8559770651386845 realtimeBaseRef:1582830061372516298 realtimeFrequency:2299775018} I0227 19:01:01.895353 31084 main.go:296] *************************** I0227 19:01:01.895546 31084 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot exec -user=0:0 -cap CAP_CHOWN -cap CAP_DAC_OVERRIDE -cap CAP_DAC_READ_SEARCH -cap CAP_FOWNER -cap CAP_FSETID -cap CAP_KILL -cap CAP_SETGID -cap CAP_SETUID -cap CAP_SETPCAP -cap CAP_LINUX_IMMUTABLE -cap CAP_NET_BIND_SERVICE -cap CAP_NET_BROADCAST -cap CAP_NET_ADMIN -cap CAP_NET_RAW -cap CAP_IPC_LOCK -cap CAP_IPC_OWNER -cap CAP_SYS_MODULE -cap CAP_SYS_RAWIO -cap CAP_SYS_CHROOT -cap CAP_SYS_PTRACE -cap CAP_SYS_PACCT -cap CAP_SYS_ADMIN -cap CAP_SYS_BOOT -cap CAP_SYS_NICE -cap CAP_SYS_RESOURCE -cap CAP_SYS_TIME -cap CAP_SYS_TTY_CONFIG -cap CAP_MKNOD -cap CAP_LEASE -cap CAP_AUDIT_WRITE -cap CAP_AUDIT_CONTROL -cap CAP_SETFCAP -cap CAP_MAC_OVERRIDE -cap CAP_MAC_ADMIN -cap CAP_SYSLOG -cap CAP_WAKE_ALARM -cap CAP_BLOCK_SUSPEND -cap CAP_AUDIT_READ ci-gvisor-ptrace-proxy-sandbox-race-3 /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller395923682] I0227 19:01:01.896035 31084 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 19:01:01.896141 31084 main.go:299] PID: 31084 I0227 19:01:01.896257 31084 main.go:300] UID: 0, GID: 0 I0227 19:01:01.896371 31084 main.go:301] Configuration: I0227 19:01:01.896469 31084 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 19:01:01.896568 31084 main.go:303] Platform: ptrace I0227 19:01:01.896665 31084 main.go:304] FileAccess: shared, overlay: false I0227 19:01:01.896788 31084 main.go:305] Network: sandbox, logging: false I0227 19:01:01.896907 31084 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 19:01:01.897043 31084 main.go:307] *************************** W0227 19:01:01.897114 31084 main.go:312] Block the TERM signal. This is only safe in tests! D0227 19:01:01.897572 31084 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.904301 31084 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-3": signal 0 D0227 19:01:01.904494 31084 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.904633 31084 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.905547 31084 urpc.go:534] urpc: successfully marshalled 117 bytes. D0227 19:01:01.905826 20813 urpc.go:577] urpc: unmarshal success. D0227 19:01:01.906062 20813 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-3 Signo:0 PID:0 Mode:Process} D0227 19:01:01.906354 20813 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 19:01:01.906538 31084 urpc.go:577] urpc: unmarshal success. D0227 19:01:01.906655 31084 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 /syzkaller395923682 D0227 19:01:01.906766 31084 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0227 19:01:01.906928 31084 container.go:532] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-3", args: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller395923682 D0227 19:01:01.907065 31084 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-3" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.907195 31084 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.908018 31084 urpc.go:534] urpc: successfully marshalled 634 bytes. D0227 19:01:01.908387 20813 urpc.go:577] urpc: unmarshal success. D0227 19:01:01.909656 20813 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 /syzkaller395923682 D0227 19:01:01.909927 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0227 19:01:01.911332 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:01.911527 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 19:01:01.912184 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} I0227 19:01:01.912820 20813 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 /syzkaller395923682] D0227 19:01:01.913620 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0227 19:01:01.914693 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] 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: 1582829971, NanoSec: 468084791}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515338}]} D0227 19:01:01.914891 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0227 19:01:01.915429 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:01.915701 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetattr{FID: 5, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 19:01:01.916884 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515338}, 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: 1582829971, NanoSec: 468084791}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 19:01:01.917047 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalk{FID: 5, NewFID: 6, Names: []} D0227 19:01:01.918920 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rwalk{QIDs: []} D0227 19:01:01.919073 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tlopen{FID: 6, Flags: ReadOnly} D0227 19:01:01.920717 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515338}, IoUnit: 0, File: &{{33}}} D0227 19:01:01.926541 20813 syscalls.go:266] Allocating stack with size of 8388608 bytes D0227 19:01:01.928008 20813 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-3 0}:0xc0002d9b40 {ci-gvisor-ptrace-proxy-sandbox-race-3 18}:0xc0002e8c20] D0227 19:01:01.928364 20813 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 19:01:01.928554 31084 urpc.go:577] urpc: unmarshal success. D0227 19:01:01.928759 31084 container.go:579] Wait on PID 18 in container "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.928897 31084 sandbox.go:743] Waiting for PID 18 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.929015 31084 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:01.929422 31084 urpc.go:534] urpc: successfully marshalled 100 bytes. D0227 19:01:01.930862 20813 urpc.go:577] urpc: unmarshal success. D0227 19:01:01.930963 20813 task_block.go:223] [ 18] Interrupt queued D0227 19:01:01.931162 20813 controller.go:443] containerManager.Wait D0227 19:01:02.153464 20813 task_block.go:223] [ 19] Interrupt queued D0227 19:01:02.156217 20813 task_block.go:223] [ 20] Interrupt queued D0227 19:01:02.162723 20813 task_block.go:223] [ 21] Interrupt queued D0227 19:01:02.165726 20813 task_block.go:223] [ 22] Interrupt queued D0227 19:01:02.184611 20813 task_block.go:223] [ 23] Interrupt queued D0227 19:01:02.198809 20813 task_block.go:223] [ 24] Interrupt queued D0227 19:01:02.229172 20813 task_block.go:223] [ 25] Interrupt queued D0227 19:01:02.239281 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0227 19:01:02.240040 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.240211 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 19:01:02.240807 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.266911 20813 task_block.go:223] [ 26] Interrupt queued D0227 19:01:02.294584 20813 task_block.go:223] [ 27] Interrupt queued D0227 19:01:02.305807 20813 task_block.go:223] [ 28] Interrupt queued D0227 19:01:02.341949 20813 task_block.go:223] [ 29] Interrupt queued D0227 19:01:02.352282 20813 task_block.go:223] [ 30] Interrupt queued D0227 19:01:02.371822 20813 parameters.go:238] Clock(Monotonic): error: 203 ns, adjusted frequency from 2299775288 Hz to 2299775214 Hz D0227 19:01:02.372158 20813 parameters.go:238] Clock(Realtime): error: 40 ns, adjusted frequency from 2299775018 Hz to 2299774839 Hz D0227 19:01:02.372290 20813 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8559772949529949 monotonicBaseRef:92000257561 monotonicFrequency:2299775214 realtimeReady:1 realtimeBaseCycles:8559772950320035 realtimeBaseRef:1582830062372150250 realtimeFrequency:2299774839} D0227 19:01:02.393739 20813 task_block.go:223] [ 31] Interrupt queued D0227 19:01:02.401000 20813 task_block.go:223] [ 32] Interrupt queued D0227 19:01:02.402407 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller395923682]} D0227 19:01:02.403989 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] 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: 307, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582830061, NanoSec: 844937026}, MTime: {Sec: 1582830061, NanoSec: 844937026}, CTime: {Sec: 1582830061, NanoSec: 844937026}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515213}]} D0227 19:01:02.404301 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller395923682, Size: 1} D0227 19:01:02.405131 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.405481 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetattr{FID: 7, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 19:01:02.406447 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] 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: 307, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582830061, NanoSec: 844937026}, MTime: {Sec: 1582830061, NanoSec: 844937026}, CTime: {Sec: 1582830061, NanoSec: 844937026}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 19:01:02.406628 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalk{FID: 7, NewFID: 8, Names: []} D0227 19:01:02.407226 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rwalk{QIDs: []} D0227 19:01:02.407368 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tlopen{FID: 8, Flags: ReadOnly} D0227 19:01:02.408155 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515213}, IoUnit: 0, File: &{{27}}} D0227 19:01:02.409160 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetattr{FID: 8, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 19:01:02.410356 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] 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: 307, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582830061, NanoSec: 844937026}, MTime: {Sec: 1582830061, NanoSec: 844937026}, CTime: {Sec: 1582830061, NanoSec: 844937026}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/27 19:01:02 parsed 1 programs D0227 19:01:02.419975 20813 task_stop.go:118] [ 24] Entering internal stop (*kernel.vforkStop)(nil) D0227 19:01:02.421427 20813 task_block.go:223] [ 33] Interrupt queued D0227 19:01:02.431224 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0227 19:01:02.432596 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] 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: 1582829971, NanoSec: 472085182}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515342}]} D0227 19:01:02.432934 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0227 19:01:02.433374 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.433788 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 19:01:02.434776 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515342}, 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: 1582829971, NanoSec: 472085182}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 19:01:02.434995 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalk{FID: 9, NewFID: 10, Names: []} D0227 19:01:02.435778 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rwalk{QIDs: []} D0227 19:01:02.435969 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tlopen{FID: 10, Flags: ReadOnly} D0227 19:01:02.436990 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515342}, IoUnit: 0, File: &{{28}}} D0227 19:01:02.438085 20813 syscalls.go:266] [ 33] Allocating stack with size of 8388608 bytes D0227 19:01:02.439049 20813 task_stop.go:137] [ 24] Leaving internal stop (*kernel.vforkStop)(nil) D0227 19:01:02.461625 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 19:01:02.462279 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.462482 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 19:01:02.462918 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.464440 20813 task_exit.go:221] [ 33] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 19:01:02.466134 20813 task_exit.go:221] [ 33] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 19:01:02.466287 20813 task_signals.go:446] [ 18] Notified of signal 17 D0227 19:01:02.466399 20813 task_block.go:223] [ 18] Interrupt queued D0227 19:01:02.466453 20813 task_block.go:223] [ 18] Interrupt queued D0227 19:01:02.466812 20813 task_exit.go:221] [ 33] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 19:01:02.466742 20813 task_signals.go:179] [ 18] Restarting syscall 202 after errno 512: interrupted by signal 17 D0227 19:01:02.467071 20813 task_signals.go:220] [ 18] Signal 17: delivering to handler D0227 19:01:02.468734 20813 task_block.go:223] [ 34] Interrupt queued D0227 19:01:02.474221 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 19:01:02.475844 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] 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: 1582829971, NanoSec: 472085182}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515342}]} D0227 19:01:02.476219 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tclunk{FID: 11} D0227 19:01:02.477072 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rclunk{} D0227 19:01:02.477437 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} 2020/02/27 19:01:02 executed programs: 0 D0227 19:01:02.479357 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515342}, 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: 1582829971, NanoSec: 472085182}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 19:01:02.486314 20813 task_stop.go:118] [ 31] Entering internal stop (*kernel.vforkStop)(nil) D0227 19:01:02.487293 20813 task_block.go:223] [ 35] Interrupt queued D0227 19:01:02.492907 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 19:01:02.494019 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] 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: 1582829971, NanoSec: 472085182}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515342}]} D0227 19:01:02.494182 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tclunk{FID: 11} D0227 19:01:02.494687 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rclunk{} D0227 19:01:02.494938 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 19:01:02.495812 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515342}, 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: 1582829971, NanoSec: 472085182}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 19:01:02.497130 20813 syscalls.go:266] [ 35] Allocating stack with size of 8388608 bytes D0227 19:01:02.498094 20813 task_stop.go:137] [ 31] Leaving internal stop (*kernel.vforkStop)(nil) D0227 19:01:02.509123 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 19:01:02.509742 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.509939 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 19:01:02.510590 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.521402 20813 task_block.go:223] [ 36] Interrupt queued D0227 19:01:02.527770 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.528432 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.528643 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.529278 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.529648 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.530213 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.530371 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.530755 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.531275 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.531854 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.532096 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.532672 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.533201 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.533779 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.533900 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.534362 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.534648 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.535081 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.535221 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.535736 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.536304 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.536815 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.536960 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.537564 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.537842 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.538318 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.538449 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.539095 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.539468 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.540036 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.540206 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.540795 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.541368 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.541951 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.542135 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.542524 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.579482 20813 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 19:01:02.579692 20813 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 19:01:02.579777 20813 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 19:01:02.579901 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.580016 20813 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 19:01:02.580589 20813 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 19:01:02.580673 20813 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0227 19:01:02.580775 20813 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0227 19:01:02.580868 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.580971 20813 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 19:01:02.581476 20813 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 19:01:02.581571 20813 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 19:01:02.581639 20813 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 19:01:02.581710 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.581803 20813 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 19:01:02.582274 20813 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 19:01:02.582348 20813 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0227 19:01:02.582413 20813 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0227 19:01:02.582494 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.582566 20813 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 19:01:02.583078 20813 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0227 19:01:02.583170 20813 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 19:01:02.583738 20813 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 19:01:02.583989 20813 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 19:01:02.584107 20813 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 19:01:02.584205 20813 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 19:01:02.584288 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.584401 20813 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 19:01:02.584937 20813 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 19:01:02.585020 20813 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0227 19:01:02.585124 20813 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0227 19:01:02.585206 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.585317 20813 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 19:01:02.585841 20813 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 19:01:02.585954 20813 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 19:01:02.586466 20813 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 19:01:02.586540 20813 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 19:01:02.586617 20813 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0227 19:01:02.586683 20813 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0227 19:01:02.586765 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.586845 20813 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 19:01:02.587345 20813 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 19:01:02.587431 20813 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0227 19:01:02.587514 20813 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0227 19:01:02.587589 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.587706 20813 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 19:01:02.588271 20813 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 19:01:02.588379 20813 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 19:01:02.588468 20813 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 19:01:02.588555 20813 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 19:01:02.588647 20813 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 19:01:02.589168 20813 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 19:01:02.589262 20813 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 19:01:02.589758 20813 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 19:01:02.777670 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.778330 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.778597 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.779114 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.779464 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.780288 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.780475 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.781056 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.781316 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.781760 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.781894 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.782335 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.782547 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.782961 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.783085 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.783510 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.783798 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.784247 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.784375 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.784793 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.785035 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.785463 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.785562 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.785964 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.786181 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.786598 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.786757 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.787250 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.787503 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.787977 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.788118 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.788528 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.788766 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.789219 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.789353 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.789721 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.789917 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 19:01:02.790327 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 19:01:02.790445 20813 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 19:01:02.790825 20813 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 19:01:02.805905 20813 task_block.go:223] [ 37] Interrupt queued D0227 19:01:02.814044 20813 task_block.go:223] [ 38] Interrupt queued I0227 19:01:02.818050 20813 compat.go:122] Unsupported syscall: setsockopt, regs: amd64: D0227 19:01:02.871543 20813 task_block.go:223] [ 39] Interrupt queued ================== WARNING: DATA RACE Read at 0x00c0001526d0 by goroutine 331: 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 DIAGNOSIS: I0227 19:01:02.909596 31349 main.go:296] *************************** I0227 19:01:02.909751 31349 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-3] I0227 19:01:02.909923 31349 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 19:01:02.910008 31349 main.go:299] PID: 31349 I0227 19:01:02.910092 31349 main.go:300] UID: 0, GID: 0 I0227 19:01:02.910184 31349 main.go:301] Configuration: I0227 19:01:02.910253 31349 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 19:01:02.910336 31349 main.go:303] Platform: ptrace I0227 19:01:02.910428 31349 main.go:304] FileAccess: shared, overlay: false I0227 19:01:02.910521 31349 main.go:305] Network: sandbox, logging: false I0227 19:01:02.910610 31349 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 19:01:02.910692 31349 main.go:307] *************************** W0227 19:01:02.910755 31349 main.go:312] Block the TERM signal. This is only safe in tests! D0227 19:01:02.910924 31349 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:02.918086 31349 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-3": signal 0 D0227 19:01:02.918234 31349 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:02.919397 31349 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:02.919895 31349 urpc.go:534] urpc: successfully marshalled 117 bytes. I0227 19:01:03.009133 31349 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3", PID: 20813 I0227 19:01:03.009280 31349 debug.go:131] Retrieving sandbox stacks D0227 19:01:03.009369 31349 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:03.009471 31349 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" W0227 19:01:03.009608 31349 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 20813: connection refused retrieving stacks: connecting to control server at PID 20813: connection refused W0227 19:01:03.009863 31349 main.go:329] Failure to execute command, err: 1 Error collecting stacks: failed to run ["/syzkaller/managers/ptrace-proxy-sandbox-race/current/image" "-root" "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "-watchdog-action=panic" "-network=none" "-debug" "-alsologtostderr" "-platform=ptrace" "-file-access=shared" "-network=sandbox" "-TESTONLY-unsafe-nonroot" "debug" "-stacks" "--ps" "ci-gvisor-ptrace-proxy-sandbox-race-3"]: exit status 128 I0227 19:01:02.909596 31349 main.go:296] *************************** I0227 19:01:02.909751 31349 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-3] I0227 19:01:02.909923 31349 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 19:01:02.910008 31349 main.go:299] PID: 31349 I0227 19:01:02.910092 31349 main.go:300] UID: 0, GID: 0 I0227 19:01:02.910184 31349 main.go:301] Configuration: I0227 19:01:02.910253 31349 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 19:01:02.910336 31349 main.go:303] Platform: ptrace I0227 19:01:02.910428 31349 main.go:304] FileAccess: shared, overlay: false I0227 19:01:02.910521 31349 main.go:305] Network: sandbox, logging: false I0227 19:01:02.910610 31349 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 19:01:02.910692 31349 main.go:307] *************************** W0227 19:01:02.910755 31349 main.go:312] Block the TERM signal. This is only safe in tests! D0227 19:01:02.910924 31349 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:02.918086 31349 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-3": signal 0 D0227 19:01:02.918234 31349 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:02.919397 31349 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:02.919895 31349 urpc.go:534] urpc: successfully marshalled 117 bytes. I0227 19:01:03.009133 31349 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3", PID: 20813 I0227 19:01:03.009280 31349 debug.go:131] Retrieving sandbox stacks D0227 19:01:03.009369 31349 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:03.009471 31349 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" W0227 19:01:03.009608 31349 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 20813: connection refused retrieving stacks: connecting to control server at PID 20813: connection refused W0227 19:01:03.009863 31349 main.go:329] Failure to execute command, err: 1 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous write at 0x00c0001526d0 by goroutine 355: 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 331 (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 355 (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 ================== W0227 19:01:03.000351 31084 error.go:48] FATAL ERROR: waiting on pid 18: waiting on PID 18 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 18: waiting on PID 18 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3": urpc method "containerManager.WaitPID" failed: EOF W0227 19:01:03.001054 31084 main.go:329] Failure to execute command, err: 1 W0227 19:01:03.009062 20800 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-3" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0227 19:01:03.009667 20800 container.go:713] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:03.010670 20800 container.go:800] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:03.010770 20800 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-3" by destroying sandbox D0227 19:01:03.010875 20800 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-3" D0227 19:01:03.010968 20800 container.go:814] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-3", PID: 20810 I0227 19:01:03.111868 20800 main.go:320] Exiting with status: 16896