D0227 11:28:22.197033 50037 parameters.go:238] Clock(Monotonic): error: 299 ns, adjusted frequency from 2299773986 Hz to 2299774966 Hz D0227 11:28:22.197353 50037 parameters.go:238] Clock(Realtime): error: 123 ns, adjusted frequency from 2299774071 Hz to 2299774548 Hz D0227 11:28:22.197493 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497310669399650 monotonicBaseRef:2001437601 monotonicFrequency:2299774966 realtimeReady:1 realtimeBaseCycles:8497310670168478 realtimeBaseRef:1582802902197348333 realtimeFrequency:2299774548} D0227 11:28:23.195859 50037 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 11:28:23.196067 50037 parameters.go:238] Clock(Monotonic): error: 449 ns, adjusted frequency from 2299774966 Hz to 2299775225 Hz D0227 11:28:23.196397 50037 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 11:28:23.196551 50037 parameters.go:238] Clock(Realtime): error: 453 ns, adjusted frequency from 2299774548 Hz to 2299775316 Hz D0227 11:28:23.196757 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497312966976414 monotonicBaseRef:3000481767 monotonicFrequency:2299775225 realtimeReady:1 realtimeBaseCycles:8497312968080311 realtimeBaseRef:1582802903196538377 realtimeFrequency:2299775316} D0227 11:28:24.195976 50037 parameters.go:238] Clock(Monotonic): error: 300 ns, adjusted frequency from 2299775225 Hz to 2299775111 Hz D0227 11:28:24.196224 50037 parameters.go:238] Clock(Realtime): error: 77 ns, adjusted frequency from 2299775316 Hz to 2299774443 Hz D0227 11:28:24.196388 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497315266441310 monotonicBaseRef:4000346828 monotonicFrequency:2299775111 realtimeReady:1 realtimeBaseCycles:8497315267118343 realtimeBaseRef:1582802904196217787 realtimeFrequency:2299774443} D0227 11:28:25.196020 50037 parameters.go:238] Clock(Monotonic): error: -128 ns, adjusted frequency from 2299775111 Hz to 2299773966 Hz D0227 11:28:25.196263 50037 parameters.go:238] Clock(Realtime): error: 201 ns, adjusted frequency from 2299774443 Hz to 2299774799 Hz D0227 11:28:25.196391 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497317566389303 monotonicBaseRef:5000422001 monotonicFrequency:2299773966 realtimeReady:1 realtimeBaseCycles:8497317566984562 realtimeBaseRef:1582802905196257693 realtimeFrequency:2299774799} D0227 11:28:26.196237 50037 parameters.go:238] Clock(Monotonic): error: -207 ns, adjusted frequency from 2299773966 Hz to 2299773978 Hz D0227 11:28:26.196479 50037 parameters.go:238] Clock(Realtime): error: 103 ns, adjusted frequency from 2299774799 Hz to 2299774603 Hz D0227 11:28:26.196607 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497319866661295 monotonicBaseRef:6000638555 monotonicFrequency:2299773978 realtimeReady:1 realtimeBaseCycles:8497319867253431 realtimeBaseRef:1582802906196472527 realtimeFrequency:2299774603} D0227 11:28:27.196889 50037 parameters.go:238] Clock(Monotonic): error: 64 ns, adjusted frequency from 2299773978 Hz to 2299774629 Hz D0227 11:28:27.197139 50037 parameters.go:238] Clock(Realtime): error: 128 ns, adjusted frequency from 2299774603 Hz to 2299774731 Hz D0227 11:28:27.197251 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497322167861993 monotonicBaseRef:7001258929 monotonicFrequency:2299774629 realtimeReady:1 realtimeBaseCycles:8497322168548715 realtimeBaseRef:1582802907197133757 realtimeFrequency:2299774731} D0227 11:28:28.196605 50037 parameters.go:238] Clock(Monotonic): error: 543 ns, adjusted frequency from 2299774629 Hz to 2299775623 Hz D0227 11:28:28.196863 50037 parameters.go:238] Clock(Realtime): error: -223 ns, adjusted frequency from 2299774731 Hz to 2299773983 Hz D0227 11:28:28.197036 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497324466981520 monotonicBaseRef:8000974074 monotonicFrequency:2299775623 realtimeReady:1 realtimeBaseCycles:8497324467677075 realtimeBaseRef:1582802908196852698 realtimeFrequency:2299773983} D0227 11:28:29.196557 50037 parameters.go:238] Clock(Monotonic): error: -431 ns, adjusted frequency from 2299775623 Hz to 2299773505 Hz D0227 11:28:29.196776 50037 parameters.go:238] Clock(Realtime): error: 700 ns, adjusted frequency from 2299773983 Hz to 2299776111 Hz D0227 11:28:29.196949 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497326766698017 monotonicBaseRef:9000948364 monotonicFrequency:2299773505 realtimeReady:1 realtimeBaseCycles:8497326767259080 realtimeBaseRef:1582802909196769221 realtimeFrequency:2299776111} D0227 11:28:30.197092 50037 parameters.go:238] Clock(Monotonic): error: 104 ns, adjusted frequency from 2299773505 Hz to 2299774792 Hz D0227 11:28:30.197302 50037 parameters.go:238] Clock(Realtime): error: -404 ns, adjusted frequency from 2299776111 Hz to 2299773572 Hz D0227 11:28:30.197437 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497329067736915 monotonicBaseRef:10001498589 monotonicFrequency:2299774792 realtimeReady:1 realtimeBaseCycles:8497329068245968 realtimeBaseRef:1582802910197295697 realtimeFrequency:2299773572} D0227 11:28:31.196667 50037 parameters.go:238] Clock(Monotonic): error: 748 ns, adjusted frequency from 2299774792 Hz to 2299776311 Hz D0227 11:28:31.196959 50037 parameters.go:238] Clock(Realtime): error: -193 ns, adjusted frequency from 2299773572 Hz to 2299774114 Hz D0227 11:28:31.197104 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497331366525585 monotonicBaseRef:11001069798 monotonicFrequency:2299776311 realtimeReady:1 realtimeBaseCycles:8497331367229780 realtimeBaseRef:1582802911196952289 realtimeFrequency:2299774114} D0227 11:28:32.196898 50037 parameters.go:238] Clock(Monotonic): error: -795 ns, adjusted frequency from 2299776311 Hz to 2299772794 Hz D0227 11:28:32.197143 50037 parameters.go:238] Clock(Realtime): error: -107 ns, adjusted frequency from 2299774114 Hz to 2299774349 Hz D0227 11:28:32.197282 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497333666823509 monotonicBaseRef:12001296608 monotonicFrequency:2299772794 realtimeReady:1 realtimeBaseCycles:8497333667420250 realtimeBaseRef:1582802912197133331 realtimeFrequency:2299774349} D0227 11:28:33.196631 50037 parameters.go:238] Clock(Monotonic): error: 560 ns, adjusted frequency from 2299772794 Hz to 2299775857 Hz D0227 11:28:33.196852 50037 parameters.go:238] Clock(Realtime): error: 695 ns, adjusted frequency from 2299774349 Hz to 2299776184 Hz D0227 11:28:33.196986 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497335966001190 monotonicBaseRef:13001037837 monotonicFrequency:2299775857 realtimeReady:1 realtimeBaseCycles:8497335966531700 realtimeBaseRef:1582802913196845085 realtimeFrequency:2299776184} D0227 11:28:34.196228 50037 parameters.go:238] Clock(Monotonic): error: -644 ns, adjusted frequency from 2299775857 Hz to 2299773180 Hz D0227 11:28:34.196459 50037 parameters.go:238] Clock(Realtime): error: -471 ns, adjusted frequency from 2299776184 Hz to 2299773484 Hz D0227 11:28:34.196621 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497338264815399 monotonicBaseRef:14000619688 monotonicFrequency:2299773180 realtimeReady:1 realtimeBaseCycles:8497338265394294 realtimeBaseRef:1582802914196447833 realtimeFrequency:2299773484} D0227 11:28:35.197015 50037 parameters.go:238] Clock(Monotonic): error: 8 ns, adjusted frequency from 2299773180 Hz to 2299774550 Hz D0227 11:28:35.197252 50037 parameters.go:238] Clock(Realtime): error: 32 ns, adjusted frequency from 2299773484 Hz to 2299774628 Hz D0227 11:28:35.197377 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497340566411781 monotonicBaseRef:15001412462 monotonicFrequency:2299774550 realtimeReady:1 realtimeBaseCycles:8497340566991340 realtimeBaseRef:1582802915197240764 realtimeFrequency:2299774628} D0227 11:28:36.195962 50037 parameters.go:238] Clock(Monotonic): error: 21 ns, adjusted frequency from 2299774550 Hz to 2299774614 Hz D0227 11:28:36.196184 50037 parameters.go:238] Clock(Realtime): error: 4 ns, adjusted frequency from 2299774628 Hz to 2299774506 Hz D0227 11:28:36.196319 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497342863708621 monotonicBaseRef:16000335091 monotonicFrequency:2299774614 realtimeReady:1 realtimeBaseCycles:8497342864320018 realtimeBaseRef:1582802916196177203 realtimeFrequency:2299774506} D0227 11:28:37.196933 50037 parameters.go:238] Clock(Monotonic): error: 219 ns, adjusted frequency from 2299774614 Hz to 2299775182 Hz D0227 11:28:37.197192 50037 parameters.go:238] Clock(Realtime): error: -253 ns, adjusted frequency from 2299774506 Hz to 2299773976 Hz D0227 11:28:37.197313 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497345165780037 monotonicBaseRef:17001333798 monotonicFrequency:2299775182 realtimeReady:1 realtimeBaseCycles:8497345166414405 realtimeBaseRef:1582802917197185945 realtimeFrequency:2299773976} D0227 11:28:38.196937 50037 parameters.go:238] Clock(Monotonic): error: 51 ns, adjusted frequency from 2299775182 Hz to 2299774583 Hz D0227 11:28:38.197154 50037 parameters.go:238] Clock(Realtime): error: 293 ns, adjusted frequency from 2299773976 Hz to 2299775187 Hz D0227 11:28:38.197283 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497347465540212 monotonicBaseRef:18001327272 monotonicFrequency:2299774583 realtimeReady:1 realtimeBaseCycles:8497347466101329 realtimeBaseRef:1582802918197148092 realtimeFrequency:2299775187} D0227 11:28:39.196889 50037 parameters.go:238] Clock(Monotonic): error: 142 ns, adjusted frequency from 2299774583 Hz to 2299774823 Hz D0227 11:28:39.197111 50037 parameters.go:238] Clock(Realtime): error: 104 ns, adjusted frequency from 2299775187 Hz to 2299774810 Hz D0227 11:28:39.197211 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497349765225435 monotonicBaseRef:19001288416 monotonicFrequency:2299774823 realtimeReady:1 realtimeBaseCycles:8497349765777126 realtimeBaseRef:1582802919197104874 realtimeFrequency:2299774810} D0227 11:28:39.217311 50037 urpc.go:577] urpc: unmarshal success. D0227 11:28:39.217994 50037 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0227 11:28:39.219950 50037 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 11:28:40.197178 50037 parameters.go:238] Clock(Monotonic): error: -106 ns, adjusted frequency from 2299774823 Hz to 2299774201 Hz D0227 11:28:40.197410 50037 parameters.go:238] Clock(Realtime): error: -84 ns, adjusted frequency from 2299774810 Hz to 2299774296 Hz D0227 11:28:40.197520 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497352065681446 monotonicBaseRef:20001584613 monotonicFrequency:2299774201 realtimeReady:1 realtimeBaseCycles:8497352066238722 realtimeBaseRef:1582802920197403505 realtimeFrequency:2299774296} D0227 11:28:41.197801 50037 parameters.go:238] Clock(Monotonic): error: 2 ns, adjusted frequency from 2299774201 Hz to 2299774458 Hz D0227 11:28:41.197983 50037 parameters.go:238] Clock(Realtime): error: -6 ns, adjusted frequency from 2299774296 Hz to 2299774486 Hz D0227 11:28:41.198087 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497354366855798 monotonicBaseRef:21002193434 monotonicFrequency:2299774458 realtimeReady:1 realtimeBaseCycles:8497354367334324 realtimeBaseRef:1582802921197978042 realtimeFrequency:2299774486} D0227 11:28:42.196913 50037 parameters.go:238] Clock(Monotonic): error: -73 ns, adjusted frequency from 2299774458 Hz to 2299774374 Hz D0227 11:28:42.197194 50037 parameters.go:238] Clock(Realtime): error: -186 ns, adjusted frequency from 2299774486 Hz to 2299774167 Hz D0227 11:28:42.197341 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497356664606678 monotonicBaseRef:22001313531 monotonicFrequency:2299774374 realtimeReady:1 realtimeBaseCycles:8497356665274080 realtimeBaseRef:1582802922197180255 realtimeFrequency:2299774167} D0227 11:28:43.196260 50037 parameters.go:238] Clock(Monotonic): error: -100 ns, adjusted frequency from 2299774374 Hz to 2299774313 Hz D0227 11:28:43.196535 50037 parameters.go:238] Clock(Realtime): error: 255 ns, adjusted frequency from 2299774167 Hz to 2299775132 Hz D0227 11:28:43.196717 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497358962871841 monotonicBaseRef:23000657287 monotonicFrequency:2299774313 realtimeReady:1 realtimeBaseCycles:8497358963549403 realtimeBaseRef:1582802923196528519 realtimeFrequency:2299775132} D0227 11:28:44.196935 50037 parameters.go:238] Clock(Monotonic): error: 55 ns, adjusted frequency from 2299774313 Hz to 2299774729 Hz D0227 11:28:44.197198 50037 parameters.go:238] Clock(Realtime): error: 139 ns, adjusted frequency from 2299775132 Hz to 2299774898 Hz D0227 11:28:44.197352 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497361264200848 monotonicBaseRef:24001333307 monotonicFrequency:2299774729 realtimeReady:1 realtimeBaseCycles:8497361264849730 realtimeBaseRef:1582802924197191712 realtimeFrequency:2299774898} D0227 11:28:45.196200 50037 parameters.go:238] Clock(Monotonic): error: 300 ns, adjusted frequency from 2299774729 Hz to 2299775156 Hz D0227 11:28:45.196484 50037 parameters.go:238] Clock(Realtime): error: -341 ns, adjusted frequency from 2299774898 Hz to 2299773879 Hz D0227 11:28:45.196623 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497363562302046 monotonicBaseRef:25000605613 monotonicFrequency:2299775156 realtimeReady:1 realtimeBaseCycles:8497363562980425 realtimeBaseRef:1582802925196476771 realtimeFrequency:2299773879} D0227 11:28:46.195969 50037 parameters.go:238] Clock(Monotonic): error: -362 ns, adjusted frequency from 2299775156 Hz to 2299773715 Hz D0227 11:28:46.196767 50037 parameters.go:238] Clock(Realtime): error: 195 ns, adjusted frequency from 2299773879 Hz to 2299774902 Hz D0227 11:28:46.196881 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497365861498324 monotonicBaseRef:26000353902 monotonicFrequency:2299773715 realtimeReady:1 realtimeBaseCycles:8497365863404057 realtimeBaseRef:1582802926196759300 realtimeFrequency:2299774902} D0227 11:28:47.196574 50037 parameters.go:238] Clock(Monotonic): error: 969 ns, adjusted frequency from 2299773715 Hz to 2299776915 Hz D0227 11:28:47.196817 50037 parameters.go:238] Clock(Realtime): error: 157 ns, adjusted frequency from 2299774902 Hz to 2299774911 Hz D0227 11:28:47.196952 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497368162697371 monotonicBaseRef:27000973672 monotonicFrequency:2299776915 realtimeReady:1 realtimeBaseCycles:8497368163295091 realtimeBaseRef:1582802927196809797 realtimeFrequency:2299774911} D0227 11:28:48.195933 50037 parameters.go:238] Clock(Monotonic): error: -946 ns, adjusted frequency from 2299776915 Hz to 2299772428 Hz D0227 11:28:48.196246 50037 parameters.go:238] Clock(Realtime): error: 22 ns, adjusted frequency from 2299774911 Hz to 2299774607 Hz D0227 11:28:48.196400 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497370461001591 monotonicBaseRef:28000333307 monotonicFrequency:2299772428 realtimeReady:1 realtimeBaseCycles:8497370461757998 realtimeBaseRef:1582802928196239304 realtimeFrequency:2299774607} D0227 11:28:49.197325 50037 parameters.go:238] Clock(Monotonic): error: 291 ns, adjusted frequency from 2299772428 Hz to 2299775191 Hz D0227 11:28:49.197554 50037 parameters.go:238] Clock(Realtime): error: -164 ns, adjusted frequency from 2299774607 Hz to 2299774215 Hz D0227 11:28:49.197691 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497372763986388 monotonicBaseRef:29001730127 monotonicFrequency:2299775191 realtimeReady:1 realtimeBaseCycles:8497372764540893 realtimeBaseRef:1582802929197547383 realtimeFrequency:2299774215} D0227 11:28:50.196389 50037 parameters.go:238] Clock(Monotonic): error: -43 ns, adjusted frequency from 2299775191 Hz to 2299774530 Hz D0227 11:28:50.196615 50037 parameters.go:238] Clock(Realtime): error: 27 ns, adjusted frequency from 2299774215 Hz to 2299774605 Hz D0227 11:28:50.196762 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497375061561519 monotonicBaseRef:30000773485 monotonicFrequency:2299774530 realtimeReady:1 realtimeBaseCycles:8497375062155762 realtimeBaseRef:1582802930196608444 realtimeFrequency:2299774605} D0227 11:28:51.196615 50037 parameters.go:238] Clock(Monotonic): error: -401 ns, adjusted frequency from 2299774530 Hz to 2299773632 Hz D0227 11:28:51.196885 50037 parameters.go:238] Clock(Realtime): error: -51 ns, adjusted frequency from 2299774605 Hz to 2299774398 Hz D0227 11:28:51.197003 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497377361874139 monotonicBaseRef:31001007460 monotonicFrequency:2299773632 realtimeReady:1 realtimeBaseCycles:8497377362541228 realtimeBaseRef:1582802931196874061 realtimeFrequency:2299774398} D0227 11:28:52.196099 50037 parameters.go:238] Clock(Monotonic): error: 400 ns, adjusted frequency from 2299773632 Hz to 2299775420 Hz D0227 11:28:52.196357 50037 parameters.go:238] Clock(Realtime): error: 7 ns, adjusted frequency from 2299774398 Hz to 2299774575 Hz D0227 11:28:52.196491 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497379660480370 monotonicBaseRef:32000499844 monotonicFrequency:2299775420 realtimeReady:1 realtimeBaseCycles:8497379661100451 realtimeBaseRef:1582802932196345672 realtimeFrequency:2299774575} D0227 11:28:53.196796 50037 parameters.go:238] Clock(Monotonic): error: -345 ns, adjusted frequency from 2299775420 Hz to 2299773752 Hz D0227 11:28:53.197026 50037 parameters.go:238] Clock(Realtime): error: 59 ns, adjusted frequency from 2299774575 Hz to 2299774646 Hz D0227 11:28:53.197157 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497381961872952 monotonicBaseRef:33001203026 monotonicFrequency:2299773752 realtimeReady:1 realtimeBaseCycles:8497381962425733 realtimeBaseRef:1582802933197019958 realtimeFrequency:2299774646} D0227 11:28:54.196392 50037 parameters.go:238] Clock(Monotonic): error: 64 ns, adjusted frequency from 2299773752 Hz to 2299774800 Hz D0227 11:28:54.196622 50037 parameters.go:238] Clock(Realtime): error: -13 ns, adjusted frequency from 2299774646 Hz to 2299774435 Hz D0227 11:28:54.196758 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497384260708790 monotonicBaseRef:34000795197 monotonicFrequency:2299774800 realtimeReady:1 realtimeBaseCycles:8497384261270202 realtimeBaseRef:1582802934196615493 realtimeFrequency:2299774435} D0227 11:28:55.196844 50037 parameters.go:238] Clock(Monotonic): error: -100 ns, adjusted frequency from 2299774800 Hz to 2299774328 Hz D0227 11:28:55.197083 50037 parameters.go:238] Clock(Realtime): error: -35 ns, adjusted frequency from 2299774435 Hz to 2299774519 Hz D0227 11:28:55.197214 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497386561499310 monotonicBaseRef:35001236857 monotonicFrequency:2299774328 realtimeReady:1 realtimeBaseCycles:8497386562096122 realtimeBaseRef:1582802935197072705 realtimeFrequency:2299774519} D0227 11:28:56.196514 50037 sampler.go:197] Time: Adjusting syscall overhead down to 7000 D0227 11:28:56.196785 50037 parameters.go:238] Clock(Monotonic): error: -5 ns, adjusted frequency from 2299774328 Hz to 2299774516 Hz D0227 11:28:56.196917 50037 parameters.go:238] Clock(Realtime): error: 78 ns, adjusted frequency from 2299774519 Hz to 2299774707 Hz D0227 11:28:56.197051 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497388860496553 monotonicBaseRef:36000898960 monotonicFrequency:2299774516 realtimeReady:1 realtimeBaseCycles:8497388861497399 realtimeBaseRef:1582802936196910409 realtimeFrequency:2299774707} D0227 11:28:57.196140 50037 parameters.go:238] Clock(Monotonic): error: 420 ns, adjusted frequency from 2299774516 Hz to 2299775483 Hz D0227 11:28:57.196379 50037 parameters.go:238] Clock(Realtime): error: 8 ns, adjusted frequency from 2299774707 Hz to 2299774538 Hz D0227 11:28:57.196520 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497391159458069 monotonicBaseRef:37000545447 monotonicFrequency:2299775483 realtimeReady:1 realtimeBaseCycles:8497391160034963 realtimeBaseRef:1582802937196372468 realtimeFrequency:2299774538} D0227 11:28:58.197897 50037 parameters.go:238] Clock(Monotonic): error: -197 ns, adjusted frequency from 2299775483 Hz to 2299774114 Hz D0227 11:28:58.198077 50037 parameters.go:238] Clock(Realtime): error: -146 ns, adjusted frequency from 2299774538 Hz to 2299774228 Hz D0227 11:28:58.198158 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497393463243852 monotonicBaseRef:38002289225 monotonicFrequency:2299774114 realtimeReady:1 realtimeBaseCycles:8497393463716617 realtimeBaseRef:1582802938198071380 realtimeFrequency:2299774228} D0227 11:28:59.196906 50037 parameters.go:238] Clock(Monotonic): error: -173 ns, adjusted frequency from 2299774114 Hz to 2299774197 Hz D0227 11:28:59.197168 50037 parameters.go:238] Clock(Realtime): error: 94 ns, adjusted frequency from 2299774228 Hz to 2299774802 Hz D0227 11:28:59.197288 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497395760763463 monotonicBaseRef:39001308910 monotonicFrequency:2299774197 realtimeReady:1 realtimeBaseCycles:8497395761397081 realtimeBaseRef:1582802939197160958 realtimeFrequency:2299774802} D0227 11:29:00.196866 50037 parameters.go:238] Clock(Monotonic): error: -14 ns, adjusted frequency from 2299774197 Hz to 2299774542 Hz D0227 11:29:00.197087 50037 parameters.go:238] Clock(Realtime): error: -280 ns, adjusted frequency from 2299774802 Hz to 2299773972 Hz D0227 11:29:00.197222 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497398060447476 monotonicBaseRef:40001269695 monotonicFrequency:2299774542 realtimeReady:1 realtimeBaseCycles:8497398060987951 realtimeBaseRef:1582802940197080979 realtimeFrequency:2299773972} D0227 11:29:01.195941 50037 parameters.go:238] Clock(Monotonic): error: 156 ns, adjusted frequency from 2299774542 Hz to 2299774980 Hz D0227 11:29:01.196145 50037 parameters.go:238] Clock(Realtime): error: 227 ns, adjusted frequency from 2299773972 Hz to 2299775101 Hz D0227 11:29:01.196318 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497400358087378 monotonicBaseRef:41000341499 monotonicFrequency:2299774980 realtimeReady:1 realtimeBaseCycles:8497400358597107 realtimeBaseRef:1582802941196139662 realtimeFrequency:2299775101} D0227 11:29:02.195938 50037 parameters.go:238] Clock(Monotonic): error: -38 ns, adjusted frequency from 2299774980 Hz to 2299774475 Hz D0227 11:29:02.196196 50037 parameters.go:238] Clock(Realtime): error: 136 ns, adjusted frequency from 2299775101 Hz to 2299774940 Hz D0227 11:29:02.196301 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497402657860533 monotonicBaseRef:42000340705 monotonicFrequency:2299774475 realtimeReady:1 realtimeBaseCycles:8497402658486180 realtimeBaseRef:1582802942196189219 realtimeFrequency:2299774940} D0227 11:29:03.197171 50037 parameters.go:238] Clock(Monotonic): error: -126 ns, adjusted frequency from 2299774475 Hz to 2299774268 Hz D0227 11:29:03.197404 50037 parameters.go:238] Clock(Realtime): error: -100 ns, adjusted frequency from 2299774940 Hz to 2299774343 Hz D0227 11:29:03.197577 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497404960480547 monotonicBaseRef:43001578017 monotonicFrequency:2299774268 realtimeReady:1 realtimeBaseCycles:8497404961041643 realtimeBaseRef:1582802943197398260 realtimeFrequency:2299774343} D0227 11:29:04.196367 50037 parameters.go:238] Clock(Monotonic): error: 3 ns, adjusted frequency from 2299774268 Hz to 2299774574 Hz D0227 11:29:04.196593 50037 parameters.go:238] Clock(Realtime): error: -24 ns, adjusted frequency from 2299774343 Hz to 2299774498 Hz D0227 11:29:04.196701 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497407258372541 monotonicBaseRef:44000759556 monotonicFrequency:2299774574 realtimeReady:1 realtimeBaseCycles:8497407258949435 realtimeBaseRef:1582802944196586636 realtimeFrequency:2299774498} D0227 11:29:05.195873 50037 parameters.go:238] Clock(Monotonic): error: 76 ns, adjusted frequency from 2299774574 Hz to 2299774739 Hz D0227 11:29:05.196085 50037 parameters.go:238] Clock(Realtime): error: -367 ns, adjusted frequency from 2299774498 Hz to 2299773799 Hz D0227 11:29:05.196215 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497409557041061 monotonicBaseRef:45000278615 monotonicFrequency:2299774739 realtimeReady:1 realtimeBaseCycles:8497409557556825 realtimeBaseRef:1582802945196079147 realtimeFrequency:2299773799} I0227 11:29:05.458816 50037 watchdog.go:277] Watchdog starting loop, tasks: 15, discount: 0s D0227 11:29:06.196824 50037 parameters.go:238] Clock(Monotonic): error: -71 ns, adjusted frequency from 2299774739 Hz to 2299774478 Hz D0227 11:29:06.197066 50037 parameters.go:238] Clock(Realtime): error: 41 ns, adjusted frequency from 2299773799 Hz to 2299774743 Hz D0227 11:29:06.197196 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497411858983715 monotonicBaseRef:46001221279 monotonicFrequency:2299774478 realtimeReady:1 realtimeBaseCycles:8497411859581165 realtimeBaseRef:1582802946197057739 realtimeFrequency:2299774743} D0227 11:29:07.195948 50037 parameters.go:238] Clock(Monotonic): error: 63 ns, adjusted frequency from 2299774478 Hz to 2299774781 Hz D0227 11:29:07.196162 50037 parameters.go:238] Clock(Realtime): error: 211 ns, adjusted frequency from 2299774743 Hz to 2299775041 Hz D0227 11:29:07.196304 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497414156755264 monotonicBaseRef:47000350354 monotonicFrequency:2299774781 realtimeReady:1 realtimeBaseCycles:8497414157281450 realtimeBaseRef:1582802947196155712 realtimeFrequency:2299775041} D0227 11:29:08.197174 50037 parameters.go:238] Clock(Monotonic): error: -145 ns, adjusted frequency from 2299774781 Hz to 2299774234 Hz D0227 11:29:08.197448 50037 parameters.go:238] Clock(Realtime): error: -247 ns, adjusted frequency from 2299775041 Hz to 2299774047 Hz D0227 11:29:08.197596 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497416459345663 monotonicBaseRef:48001574655 monotonicFrequency:2299774234 realtimeReady:1 realtimeBaseCycles:8497416460005098 realtimeBaseRef:1582802948197437840 realtimeFrequency:2299774047} D0227 11:29:09.196595 50037 parameters.go:238] Clock(Monotonic): error: -17 ns, adjusted frequency from 2299774234 Hz to 2299774510 Hz D0227 11:29:09.196833 50037 parameters.go:238] Clock(Realtime): error: 353 ns, adjusted frequency from 2299774047 Hz to 2299775329 Hz D0227 11:29:09.196982 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497418757788442 monotonicBaseRef:49000995704 monotonicFrequency:2299774510 realtimeReady:1 realtimeBaseCycles:8497418758373638 realtimeBaseRef:1582802949196826689 realtimeFrequency:2299775329} D0227 11:29:10.195914 50037 parameters.go:238] Clock(Monotonic): error: 421 ns, adjusted frequency from 2299774510 Hz to 2299775543 Hz D0227 11:29:10.196140 50037 parameters.go:238] Clock(Realtime): error: -12 ns, adjusted frequency from 2299775329 Hz to 2299774545 Hz D0227 11:29:10.196262 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497421056006556 monotonicBaseRef:50000318943 monotonicFrequency:2299775543 realtimeReady:1 realtimeBaseCycles:8497421056555885 realtimeBaseRef:1582802950196133976 realtimeFrequency:2299774545} D0227 11:29:11.196277 50037 parameters.go:238] Clock(Monotonic): error: -400 ns, adjusted frequency from 2299775543 Hz to 2299773654 Hz D0227 11:29:11.196530 50037 parameters.go:238] Clock(Realtime): error: -348 ns, adjusted frequency from 2299774545 Hz to 2299773800 Hz D0227 11:29:11.196647 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497423356615959 monotonicBaseRef:51000681526 monotonicFrequency:2299773654 realtimeReady:1 realtimeBaseCycles:8497423357227373 realtimeBaseRef:1582802951196523989 realtimeFrequency:2299773800} D0227 11:29:12.196769 50037 parameters.go:238] Clock(Monotonic): error: 155 ns, adjusted frequency from 2299773654 Hz to 2299774931 Hz D0227 11:29:12.196987 50037 parameters.go:238] Clock(Realtime): error: 390 ns, adjusted frequency from 2299773800 Hz to 2299775502 Hz D0227 11:29:12.197152 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497425657518373 monotonicBaseRef:52001172339 monotonicFrequency:2299774931 realtimeReady:1 realtimeBaseCycles:8497425658051578 realtimeBaseRef:1582802952196980731 realtimeFrequency:2299775502} D0227 11:29:13.196836 50037 parameters.go:238] Clock(Monotonic): error: -229 ns, adjusted frequency from 2299774931 Hz to 2299774022 Hz D0227 11:29:13.197105 50037 parameters.go:238] Clock(Realtime): error: -97 ns, adjusted frequency from 2299775502 Hz to 2299774369 Hz D0227 11:29:13.197229 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497427957448354 monotonicBaseRef:53001239758 monotonicFrequency:2299774022 realtimeReady:1 realtimeBaseCycles:8497427958087220 realtimeBaseRef:1582802953197093846 realtimeFrequency:2299774369} D0227 11:29:14.196299 50037 parameters.go:238] Clock(Monotonic): error: 344 ns, adjusted frequency from 2299774022 Hz to 2299775385 Hz D0227 11:29:14.196577 50037 parameters.go:238] Clock(Realtime): error: 31 ns, adjusted frequency from 2299774369 Hz to 2299774594 Hz D0227 11:29:14.196789 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497430255970031 monotonicBaseRef:54000695206 monotonicFrequency:2299775385 realtimeReady:1 realtimeBaseCycles:8497430256655316 realtimeBaseRef:1582802954196569328 realtimeFrequency:2299774594} D0227 11:29:14.674294 50037 urpc.go:577] urpc: unmarshal success. D0227 11:29:14.674590 50037 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0227 11:29:14.674877 50037 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 11:29:15.196313 50037 parameters.go:238] Clock(Monotonic): error: -215 ns, adjusted frequency from 2299775385 Hz to 2299774071 Hz D0227 11:29:15.196551 50037 parameters.go:238] Clock(Realtime): error: 49 ns, adjusted frequency from 2299774594 Hz to 2299774635 Hz D0227 11:29:15.196714 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497432555795768 monotonicBaseRef:55000717100 monotonicFrequency:2299774071 realtimeReady:1 realtimeBaseCycles:8497432556372910 realtimeBaseRef:1582802955196544542 realtimeFrequency:2299774635} D0227 11:29:16.196265 50037 parameters.go:238] Clock(Monotonic): error: -97 ns, adjusted frequency from 2299774071 Hz to 2299774383 Hz D0227 11:29:16.196536 50037 parameters.go:238] Clock(Realtime): error: 37 ns, adjusted frequency from 2299774635 Hz to 2299774638 Hz D0227 11:29:16.196693 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497434855422117 monotonicBaseRef:56000652866 monotonicFrequency:2299774383 realtimeReady:1 realtimeBaseCycles:8497434856108760 realtimeBaseRef:1582802956196527677 realtimeFrequency:2299774638} D0227 11:29:17.196500 50037 parameters.go:238] Clock(Monotonic): error: 173 ns, adjusted frequency from 2299774383 Hz to 2299774950 Hz D0227 11:29:17.196791 50037 parameters.go:238] Clock(Realtime): error: -246 ns, adjusted frequency from 2299774638 Hz to 2299773995 Hz D0227 11:29:17.196951 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497437155777995 monotonicBaseRef:57000905714 monotonicFrequency:2299774950 realtimeReady:1 realtimeBaseCycles:8497437156468583 realtimeBaseRef:1582802957196782130 realtimeFrequency:2299773995} D0227 11:29:18.197015 50037 parameters.go:238] Clock(Monotonic): error: -159 ns, adjusted frequency from 2299774950 Hz to 2299774201 Hz D0227 11:29:18.197236 50037 parameters.go:238] Clock(Realtime): error: 62 ns, adjusted frequency from 2299773995 Hz to 2299774696 Hz D0227 11:29:18.197366 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497439456735762 monotonicBaseRef:58001420032 monotonicFrequency:2299774201 realtimeReady:1 realtimeBaseCycles:8497439457273953 realtimeBaseRef:1582802958197230597 realtimeFrequency:2299774696} D0227 11:29:19.196407 50037 parameters.go:238] Clock(Monotonic): error: -62 ns, adjusted frequency from 2299774201 Hz to 2299774427 Hz D0227 11:29:19.196626 50037 parameters.go:238] Clock(Realtime): error: -237 ns, adjusted frequency from 2299774696 Hz to 2299774062 Hz D0227 11:29:19.196762 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497441755103756 monotonicBaseRef:59000808577 monotonicFrequency:2299774427 realtimeReady:1 realtimeBaseCycles:8497441755643829 realtimeBaseRef:1582802959196619745 realtimeFrequency:2299774062} D0227 11:29:20.196991 50037 parameters.go:238] Clock(Monotonic): error: 24 ns, adjusted frequency from 2299774427 Hz to 2299774613 Hz D0227 11:29:20.197763 50037 parameters.go:238] Clock(Realtime): error: 555 ns, adjusted frequency from 2299774062 Hz to 2299775804 Hz D0227 11:29:20.197894 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497444056229873 monotonicBaseRef:60001396325 monotonicFrequency:2299774613 realtimeReady:1 realtimeBaseCycles:8497444058028720 realtimeBaseRef:1582802960197754999 realtimeFrequency:2299775804} D0227 11:29:21.196163 50037 parameters.go:238] Clock(Monotonic): error: 196 ns, adjusted frequency from 2299774613 Hz to 2299774999 Hz D0227 11:29:21.196410 50037 parameters.go:238] Clock(Realtime): error: 71 ns, adjusted frequency from 2299775804 Hz to 2299774742 Hz D0227 11:29:21.196572 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497446354097237 monotonicBaseRef:61000567005 monotonicFrequency:2299774999 realtimeReady:1 realtimeBaseCycles:8497446354683319 realtimeBaseRef:1582802961196397821 realtimeFrequency:2299774742} D0227 11:29:22.198785 50037 parameters.go:238] Clock(Monotonic): error: -206 ns, adjusted frequency from 2299774999 Hz to 2299774087 Hz D0227 11:29:22.199030 50037 parameters.go:238] Clock(Realtime): error: -283 ns, adjusted frequency from 2299774742 Hz to 2299773891 Hz D0227 11:29:22.199135 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497448659906532 monotonicBaseRef:62003190868 monotonicFrequency:2299774087 realtimeReady:1 realtimeBaseCycles:8497448660496128 realtimeBaseRef:1582802962199023324 realtimeFrequency:2299773891} D0227 11:29:23.196352 50037 parameters.go:238] Clock(Monotonic): error: 37 ns, adjusted frequency from 2299774087 Hz to 2299774623 Hz D0227 11:29:23.196605 50037 parameters.go:238] Clock(Realtime): error: -100 ns, adjusted frequency from 2299773891 Hz to 2299774327 Hz D0227 11:29:23.196754 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497450954026899 monotonicBaseRef:63000732487 monotonicFrequency:2299774623 realtimeReady:1 realtimeBaseCycles:8497450954684158 realtimeBaseRef:1582802963196594450 realtimeFrequency:2299774327} D0227 11:29:24.197001 50037 parameters.go:238] Clock(Monotonic): error: 277 ns, adjusted frequency from 2299774623 Hz to 2299775128 Hz D0227 11:29:24.197222 50037 parameters.go:238] Clock(Realtime): error: 85 ns, adjusted frequency from 2299774327 Hz to 2299774720 Hz D0227 11:29:24.197346 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497453255358926 monotonicBaseRef:64001409685 monotonicFrequency:2299775128 realtimeReady:1 realtimeBaseCycles:8497453255888614 realtimeBaseRef:1582802964197216306 realtimeFrequency:2299774720} D0227 11:29:25.198157 50037 parameters.go:238] Clock(Monotonic): error: 196 ns, adjusted frequency from 2299775128 Hz to 2299774952 Hz D0227 11:29:25.198403 50037 parameters.go:238] Clock(Realtime): error: -33 ns, adjusted frequency from 2299774720 Hz to 2299774463 Hz D0227 11:29:25.198544 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497455557789580 monotonicBaseRef:65002564374 monotonicFrequency:2299774952 realtimeReady:1 realtimeBaseCycles:8497455558371297 realtimeBaseRef:1582802965198393796 realtimeFrequency:2299774463} D0227 11:29:26.195873 50037 parameters.go:238] Clock(Monotonic): error: -419 ns, adjusted frequency from 2299774952 Hz to 2299773605 Hz D0227 11:29:26.196587 50037 parameters.go:238] Clock(Realtime): error: 25 ns, adjusted frequency from 2299774463 Hz to 2299774519 Hz D0227 11:29:26.196746 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497457852278042 monotonicBaseRef:66000265675 monotonicFrequency:2299773605 realtimeReady:1 realtimeBaseCycles:8497457853971387 realtimeBaseRef:1582802966196578673 realtimeFrequency:2299774519} D0227 11:29:27.196648 50037 parameters.go:238] Clock(Monotonic): error: 132 ns, adjusted frequency from 2299773605 Hz to 2299774838 Hz D0227 11:29:27.196948 50037 parameters.go:238] Clock(Realtime): error: -98 ns, adjusted frequency from 2299774519 Hz to 2299774404 Hz D0227 11:29:27.197264 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497460153850264 monotonicBaseRef:67001047759 monotonicFrequency:2299774838 realtimeReady:1 realtimeBaseCycles:8497460154536655 realtimeBaseRef:1582802967196922510 realtimeFrequency:2299774404} D0227 11:29:28.196131 50037 parameters.go:238] Clock(Monotonic): error: 214 ns, adjusted frequency from 2299774838 Hz to 2299775031 Hz D0227 11:29:28.196348 50037 parameters.go:238] Clock(Realtime): error: 159 ns, adjusted frequency from 2299774404 Hz to 2299774876 Hz D0227 11:29:28.196481 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497462452453837 monotonicBaseRef:68000538463 monotonicFrequency:2299775031 realtimeReady:1 realtimeBaseCycles:8497462452977757 realtimeBaseRef:1582802968196342756 realtimeFrequency:2299774876} D0227 11:29:29.197044 50037 parameters.go:238] Clock(Monotonic): error: -118 ns, adjusted frequency from 2299775031 Hz to 2299774282 Hz D0227 11:29:29.197381 50037 parameters.go:238] Clock(Realtime): error: 1105 ns, adjusted frequency from 2299774876 Hz to 2299777292 Hz D0227 11:29:29.197570 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497464754318181 monotonicBaseRef:69001446948 monotonicFrequency:2299774282 realtimeReady:1 realtimeBaseCycles:8497464755119082 realtimeBaseRef:1582802969197371747 realtimeFrequency:2299777292} D0227 11:29:30.197282 50037 parameters.go:238] Clock(Monotonic): error: -198 ns, adjusted frequency from 2299774282 Hz to 2299774106 Hz D0227 11:29:30.197479 50037 parameters.go:238] Clock(Realtime): error: -1066 ns, adjusted frequency from 2299777292 Hz to 2299772087 Hz D0227 11:29:30.197591 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497467054641803 monotonicBaseRef:70001685814 monotonicFrequency:2299774106 realtimeReady:1 realtimeBaseCycles:8497467055125549 realtimeBaseRef:1582802970197471397 realtimeFrequency:2299772087} D0227 11:29:31.196867 50037 parameters.go:238] Clock(Monotonic): error: 854 ns, adjusted frequency from 2299774106 Hz to 2299776591 Hz D0227 11:29:31.197141 50037 parameters.go:238] Clock(Realtime): error: -136 ns, adjusted frequency from 2299772087 Hz to 2299774262 Hz D0227 11:29:31.197294 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497469353460004 monotonicBaseRef:71001270162 monotonicFrequency:2299776591 realtimeReady:1 realtimeBaseCycles:8497469354121090 realtimeBaseRef:1582802971197133734 realtimeFrequency:2299774262} D0227 11:29:32.196696 50037 parameters.go:238] Clock(Monotonic): error: -903 ns, adjusted frequency from 2299776591 Hz to 2299772480 Hz D0227 11:29:32.196916 50037 parameters.go:238] Clock(Realtime): error: -24 ns, adjusted frequency from 2299774262 Hz to 2299774468 Hz D0227 11:29:32.197030 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497471652813409 monotonicBaseRef:72001086150 monotonicFrequency:2299772480 realtimeReady:1 realtimeBaseCycles:8497471653382341 realtimeBaseRef:1582802972196910663 realtimeFrequency:2299774468} D0227 11:29:33.195916 50037 parameters.go:238] Clock(Monotonic): error: 379 ns, adjusted frequency from 2299772480 Hz to 2299775420 Hz D0227 11:29:33.196122 50037 parameters.go:238] Clock(Realtime): error: 22 ns, adjusted frequency from 2299774468 Hz to 2299774617 Hz D0227 11:29:33.196209 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497473950830003 monotonicBaseRef:73000322645 monotonicFrequency:2299775420 realtimeReady:1 realtimeBaseCycles:8497473951329035 realtimeBaseRef:1582802973196115900 realtimeFrequency:2299774617} D0227 11:29:34.196734 50037 parameters.go:238] Clock(Monotonic): error: -332 ns, adjusted frequency from 2299775420 Hz to 2299773862 Hz D0227 11:29:34.196984 50037 parameters.go:238] Clock(Realtime): error: 41 ns, adjusted frequency from 2299774617 Hz to 2299774664 Hz D0227 11:29:34.197143 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497476252480153 monotonicBaseRef:74001137824 monotonicFrequency:2299773862 realtimeReady:1 realtimeBaseCycles:8497476253083954 realtimeBaseRef:1582802974196976985 realtimeFrequency:2299774664} D0227 11:29:35.196680 50037 parameters.go:238] Clock(Monotonic): error: 225 ns, adjusted frequency from 2299773862 Hz to 2299775100 Hz D0227 11:29:35.197307 50037 parameters.go:238] Clock(Realtime): error: -12 ns, adjusted frequency from 2299774664 Hz to 2299774579 Hz D0227 11:29:35.197418 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497478552135605 monotonicBaseRef:75001086336 monotonicFrequency:2299775100 realtimeReady:1 realtimeBaseCycles:8497478553604246 realtimeBaseRef:1582802975197301202 realtimeFrequency:2299774579} D0227 11:29:36.196397 50037 parameters.go:238] Clock(Monotonic): error: -305 ns, adjusted frequency from 2299775100 Hz to 2299773890 Hz D0227 11:29:36.196639 50037 parameters.go:238] Clock(Realtime): error: -285 ns, adjusted frequency from 2299774579 Hz to 2299773891 Hz D0227 11:29:36.196771 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497480851239786 monotonicBaseRef:76000794603 monotonicFrequency:2299773890 realtimeReady:1 realtimeBaseCycles:8497480851838886 realtimeBaseRef:1582802976196631597 realtimeFrequency:2299773891} D0227 11:29:37.196696 50037 parameters.go:238] Clock(Monotonic): error: 200 ns, adjusted frequency from 2299773890 Hz to 2299775062 Hz D0227 11:29:37.196972 50037 parameters.go:238] Clock(Realtime): error: 279 ns, adjusted frequency from 2299773891 Hz to 2299775155 Hz D0227 11:29:37.197118 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497483151706815 monotonicBaseRef:77001095997 monotonicFrequency:2299775062 realtimeReady:1 realtimeBaseCycles:8497483152381320 realtimeBaseRef:1582802977196965778 realtimeFrequency:2299775155} D0227 11:29:38.197149 50037 parameters.go:238] Clock(Monotonic): error: 108 ns, adjusted frequency from 2299775062 Hz to 2299774760 Hz D0227 11:29:38.197365 50037 parameters.go:238] Clock(Realtime): error: 35 ns, adjusted frequency from 2299775155 Hz to 2299774434 Hz D0227 11:29:38.197483 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497485452511191 monotonicBaseRef:78001543568 monotonicFrequency:2299774760 realtimeReady:1 realtimeBaseCycles:8497485453062127 realtimeBaseRef:1582802978197359578 realtimeFrequency:2299774434} D0227 11:29:39.197286 50037 parameters.go:238] Clock(Monotonic): error: -234 ns, adjusted frequency from 2299774760 Hz to 2299774039 Hz D0227 11:29:39.197549 50037 parameters.go:238] Clock(Realtime): error: 42 ns, adjusted frequency from 2299774434 Hz to 2299774653 Hz D0227 11:29:39.197673 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497487751750241 monotonicBaseRef:79001310627 monotonicFrequency:2299774039 realtimeReady:1 realtimeBaseCycles:8497487753255566 realtimeBaseRef:1582802979197541771 realtimeFrequency:2299774653} D0227 11:29:40.197236 50037 parameters.go:238] Clock(Monotonic): error: 659 ns, adjusted frequency from 2299774039 Hz to 2299776053 Hz D0227 11:29:40.197515 50037 parameters.go:238] Clock(Realtime): error: -238 ns, adjusted frequency from 2299774653 Hz to 2299774075 Hz D0227 11:29:40.197678 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497490052259908 monotonicBaseRef:80001630496 monotonicFrequency:2299776053 realtimeReady:1 realtimeBaseCycles:8497490052953327 realtimeBaseRef:1582802980197508336 realtimeFrequency:2299774075} D0227 11:29:41.197226 50037 parameters.go:238] Clock(Monotonic): error: -577 ns, adjusted frequency from 2299776053 Hz to 2299773243 Hz D0227 11:29:41.197483 50037 parameters.go:238] Clock(Realtime): error: 257 ns, adjusted frequency from 2299774075 Hz to 2299775176 Hz D0227 11:29:41.197628 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497492351998097 monotonicBaseRef:81001614031 monotonicFrequency:2299773243 realtimeReady:1 realtimeBaseCycles:8497492352655035 realtimeBaseRef:1582802981197476868 realtimeFrequency:2299775176} D0227 11:29:42.197977 50037 parameters.go:238] Clock(Monotonic): error: -152 ns, adjusted frequency from 2299773243 Hz to 2299774291 Hz D0227 11:29:42.198203 50037 parameters.go:238] Clock(Realtime): error: -286 ns, adjusted frequency from 2299775176 Hz to 2299773989 Hz D0227 11:29:42.198346 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497494653533636 monotonicBaseRef:82002380322 monotonicFrequency:2299774291 realtimeReady:1 realtimeBaseCycles:8497494654085619 realtimeBaseRef:1582802982198196680 realtimeFrequency:2299773989} D0227 11:29:43.196717 50037 parameters.go:238] Clock(Monotonic): error: 7 ns, adjusted frequency from 2299774291 Hz to 2299774580 Hz D0227 11:29:43.196945 50037 parameters.go:238] Clock(Realtime): error: -91 ns, adjusted frequency from 2299773989 Hz to 2299774432 Hz D0227 11:29:43.197078 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497496950406777 monotonicBaseRef:83001118828 monotonicFrequency:2299774580 realtimeReady:1 realtimeBaseCycles:8497496950966970 realtimeBaseRef:1582802983196938887 realtimeFrequency:2299774432} D0227 11:29:44.195962 50037 parameters.go:238] Clock(Monotonic): error: 35 ns, adjusted frequency from 2299774580 Hz to 2299774620 Hz D0227 11:29:44.196212 50037 parameters.go:238] Clock(Realtime): error: 245 ns, adjusted frequency from 2299774432 Hz to 2299775125 Hz D0227 11:29:44.196350 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497499248426759 monotonicBaseRef:84000355884 monotonicFrequency:2299774620 realtimeReady:1 realtimeBaseCycles:8497499249057221 realtimeBaseRef:1582802984196206562 realtimeFrequency:2299775125} D0227 11:29:45.196899 50037 parameters.go:238] Clock(Monotonic): error: -56 ns, adjusted frequency from 2299774620 Hz to 2299774430 Hz D0227 11:29:45.197093 50037 parameters.go:238] Clock(Realtime): error: -16 ns, adjusted frequency from 2299775125 Hz to 2299774460 Hz D0227 11:29:45.197211 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497501550383805 monotonicBaseRef:85001304857 monotonicFrequency:2299774430 realtimeReady:1 realtimeBaseCycles:8497501550847975 realtimeBaseRef:1582802985197083008 realtimeFrequency:2299774460} D0227 11:29:46.196278 50037 parameters.go:238] Clock(Monotonic): error: -56 ns, adjusted frequency from 2299774430 Hz to 2299774401 Hz D0227 11:29:46.196532 50037 parameters.go:238] Clock(Realtime): error: -65 ns, adjusted frequency from 2299774460 Hz to 2299774523 Hz D0227 11:29:46.196723 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497503848712821 monotonicBaseRef:86000676354 monotonicFrequency:2299774401 realtimeReady:1 realtimeBaseCycles:8497503849333675 realtimeBaseRef:1582802986196522622 realtimeFrequency:2299774523} D0227 11:29:47.196882 50037 parameters.go:238] Clock(Monotonic): error: 351 ns, adjusted frequency from 2299774401 Hz to 2299775327 Hz D0227 11:29:47.197105 50037 parameters.go:238] Clock(Realtime): error: 44 ns, adjusted frequency from 2299774523 Hz to 2299774679 Hz D0227 11:29:47.197263 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497506149895756 monotonicBaseRef:87001288820 monotonicFrequency:2299775327 realtimeReady:1 realtimeBaseCycles:8497506150431153 realtimeBaseRef:1582802987197097876 realtimeFrequency:2299774679} D0227 11:29:48.196754 50037 parameters.go:238] Clock(Monotonic): error: 42 ns, adjusted frequency from 2299775327 Hz to 2299774627 Hz D0227 11:29:48.197023 50037 parameters.go:238] Clock(Realtime): error: 137 ns, adjusted frequency from 2299774679 Hz to 2299774892 Hz D0227 11:29:48.197157 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497508449367983 monotonicBaseRef:88001157024 monotonicFrequency:2299774627 realtimeReady:1 realtimeBaseCycles:8497508450021508 realtimeBaseRef:1582802988197017727 realtimeFrequency:2299774892} D0227 11:29:48.252497 50037 urpc.go:577] urpc: unmarshal success. D0227 11:29:48.252774 50037 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0227 11:29:48.253016 50037 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 11:29:49.195907 50037 parameters.go:238] Clock(Monotonic): error: -322 ns, adjusted frequency from 2299774627 Hz to 2299773795 Hz D0227 11:29:49.196162 50037 parameters.go:238] Clock(Realtime): error: -132 ns, adjusted frequency from 2299774892 Hz to 2299774207 Hz D0227 11:29:49.196298 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497510747133616 monotonicBaseRef:89000283462 monotonicFrequency:2299773795 realtimeReady:1 realtimeBaseCycles:8497510747812993 realtimeBaseRef:1582802989196155291 realtimeFrequency:2299774207} I0227 11:29:49.315059 58910 main.go:296] *************************** I0227 11:29:49.315198 58910 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot exec -user=0:0 -cap CAP_CHOWN -cap CAP_DAC_OVERRIDE -cap CAP_DAC_READ_SEARCH -cap CAP_FOWNER -cap CAP_FSETID -cap CAP_KILL -cap CAP_SETGID -cap CAP_SETUID -cap CAP_SETPCAP -cap CAP_LINUX_IMMUTABLE -cap CAP_NET_BIND_SERVICE -cap CAP_NET_BROADCAST -cap CAP_NET_ADMIN -cap CAP_NET_RAW -cap CAP_IPC_LOCK -cap CAP_IPC_OWNER -cap CAP_SYS_MODULE -cap CAP_SYS_RAWIO -cap CAP_SYS_CHROOT -cap CAP_SYS_PTRACE -cap CAP_SYS_PACCT -cap CAP_SYS_ADMIN -cap CAP_SYS_BOOT -cap CAP_SYS_NICE -cap CAP_SYS_RESOURCE -cap CAP_SYS_TIME -cap CAP_SYS_TTY_CONFIG -cap CAP_MKNOD -cap CAP_LEASE -cap CAP_AUDIT_WRITE -cap CAP_AUDIT_CONTROL -cap CAP_SETFCAP -cap CAP_MAC_OVERRIDE -cap CAP_MAC_ADMIN -cap CAP_SYSLOG -cap CAP_WAKE_ALARM -cap CAP_BLOCK_SUSPEND -cap CAP_AUDIT_READ ci-gvisor-ptrace-proxy-sandbox-race-2 /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller448527070] I0227 11:29:49.315578 58910 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 11:29:49.315652 58910 main.go:299] PID: 58910 I0227 11:29:49.315743 58910 main.go:300] UID: 0, GID: 0 I0227 11:29:49.315830 58910 main.go:301] Configuration: I0227 11:29:49.315947 58910 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 11:29:49.316067 58910 main.go:303] Platform: ptrace I0227 11:29:49.316140 58910 main.go:304] FileAccess: shared, overlay: false I0227 11:29:49.316268 58910 main.go:305] Network: sandbox, logging: false I0227 11:29:49.316354 58910 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 11:29:49.316433 58910 main.go:307] *************************** W0227 11:29:49.316550 58910 main.go:312] Block the TERM signal. This is only safe in tests! D0227 11:29:49.317041 58910 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.323693 58910 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0227 11:29:49.323892 58910 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.323989 58910 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.325104 50037 urpc.go:577] urpc: unmarshal success. D0227 11:29:49.325337 50037 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0227 11:29:49.325540 50037 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 11:29:49.325653 58910 urpc.go:534] urpc: successfully marshalled 117 bytes. D0227 11:29:49.325867 58910 urpc.go:577] urpc: unmarshal success. D0227 11:29:49.326066 58910 exec.go:120] Exec arguments: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller448527070 D0227 11:29:49.326185 58910 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0227 11:29:49.326299 58910 container.go:532] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-2", args: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller448527070 D0227 11:29:49.326401 58910 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-2" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.326500 58910 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.327409 58910 urpc.go:534] urpc: successfully marshalled 635 bytes. D0227 11:29:49.327900 50037 urpc.go:577] urpc: unmarshal success. D0227 11:29:49.329495 50037 controller.go:267] containerManager.ExecuteAsync: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller448527070 D0227 11:29:49.329821 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0227 11:29:49.332074 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:49.332247 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 11:29:49.332929 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} I0227 11:29:49.333428 50037 kernel.go:795] EXEC: [/syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=1 -threaded=true -collide=false -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller448527070] D0227 11:29:49.334324 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0227 11:29:49.335443 50037 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: 1582802901, NanoSec: 467220884}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 15206399}]} D0227 11:29:49.335694 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0227 11:29:49.336196 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:49.336577 50037 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 11:29:49.337656 50037 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: 15206399}, 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: 1582802901, NanoSec: 467220884}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 11:29:49.337835 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalk{FID: 5, NewFID: 6, Names: []} D0227 11:29:49.338497 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rwalk{QIDs: []} D0227 11:29:49.338633 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tlopen{FID: 6, Flags: ReadOnly} D0227 11:29:49.340104 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 15206399}, IoUnit: 0, File: &{{33}}} D0227 11:29:49.344690 50037 syscalls.go:266] Allocating stack with size of 8388608 bytes D0227 11:29:49.348753 50037 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-2 0}:0xc000322720 {ci-gvisor-ptrace-proxy-sandbox-race-2 21}:0xc000365780] D0227 11:29:49.349144 50037 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 11:29:49.360758 58910 urpc.go:577] urpc: unmarshal success. D0227 11:29:49.360901 58910 container.go:579] Wait on PID 21 in container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.361031 58910 sandbox.go:743] Waiting for PID 21 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.361150 58910 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:49.361557 58910 urpc.go:534] urpc: successfully marshalled 100 bytes. D0227 11:29:49.361900 50037 urpc.go:577] urpc: unmarshal success. D0227 11:29:49.362185 50037 controller.go:443] containerManager.Wait D0227 11:29:49.366878 50037 task_block.go:223] [ 21] Interrupt queued D0227 11:29:49.630736 50037 task_block.go:223] [ 22] Interrupt queued D0227 11:29:49.656018 50037 task_block.go:223] [ 23] Interrupt queued D0227 11:29:49.662562 50037 task_block.go:223] [ 24] Interrupt queued D0227 11:29:49.664579 50037 task_block.go:223] [ 25] Interrupt queued D0227 11:29:49.681881 50037 task_block.go:223] [ 26] Interrupt queued D0227 11:29:49.736278 50037 task_block.go:223] [ 27] Interrupt queued D0227 11:29:49.779184 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0227 11:29:49.779789 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:49.779998 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 11:29:49.780404 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:49.813153 50037 task_block.go:223] [ 28] Interrupt queued D0227 11:29:49.824818 50037 task_block.go:223] [ 29] Interrupt queued D0227 11:29:49.840111 50037 task_block.go:223] [ 30] Interrupt queued D0227 11:29:49.852831 50037 task_block.go:223] [ 31] Interrupt queued D0227 11:29:49.853635 50037 task_block.go:223] [ 32] Interrupt queued D0227 11:29:49.898421 50037 task_block.go:223] [ 33] Interrupt queued D0227 11:29:49.903767 50037 task_block.go:223] [ 34] Interrupt queued D0227 11:29:49.979232 50037 task_block.go:223] [ 35] Interrupt queued D0227 11:29:49.986957 50037 task_block.go:223] [ 36] Interrupt queued D0227 11:29:49.987122 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller448527070]} D0227 11:29:49.988867 50037 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: 199, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582802989, NanoSec: 279827926}, MTime: {Sec: 1582802989, NanoSec: 279827926}, CTime: {Sec: 1582802989, NanoSec: 279827926}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 15204387}]} D0227 11:29:49.989154 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller448527070, Size: 1} D0227 11:29:49.989729 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:49.990013 50037 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 11:29:49.990941 50037 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: 15204387}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 199, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582802989, NanoSec: 279827926}, MTime: {Sec: 1582802989, NanoSec: 279827926}, CTime: {Sec: 1582802989, NanoSec: 279827926}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 11:29:49.998080 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalk{FID: 7, NewFID: 8, Names: []} D0227 11:29:49.998697 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rwalk{QIDs: []} D0227 11:29:49.998895 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tlopen{FID: 8, Flags: ReadOnly} D0227 11:29:49.999728 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 15204387}, IoUnit: 0, File: &{{27}}} D0227 11:29:50.007395 50037 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 11:29:50.008862 50037 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: 15204387}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 199, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582802989, NanoSec: 279827926}, MTime: {Sec: 1582802989, NanoSec: 279827926}, CTime: {Sec: 1582802989, NanoSec: 279827926}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/27 11:29:50 parsed 1 programs D0227 11:29:50.022615 50037 task_stop.go:118] [ 25] Entering internal stop (*kernel.vforkStop)(nil) D0227 11:29:50.023391 50037 task_block.go:223] [ 37] Interrupt queued D0227 11:29:50.029007 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0227 11:29:50.030466 50037 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: 1582802901, NanoSec: 471221276}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 15206401}]} D0227 11:29:50.030666 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0227 11:29:50.031140 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.031407 50037 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 11:29:50.032668 50037 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: 15206401}, 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: 1582802901, NanoSec: 471221276}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 11:29:50.032881 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalk{FID: 9, NewFID: 10, Names: []} D0227 11:29:50.033470 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rwalk{QIDs: []} D0227 11:29:50.033601 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tlopen{FID: 10, Flags: ReadOnly} D0227 11:29:50.036940 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 15206401}, IoUnit: 0, File: &{{28}}} D0227 11:29:50.038082 50037 syscalls.go:266] [ 37] Allocating stack with size of 8388608 bytes D0227 11:29:50.038963 50037 task_stop.go:137] [ 25] Leaving internal stop (*kernel.vforkStop)(nil) D0227 11:29:50.059768 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 11:29:50.060555 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.060964 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 11:29:50.061521 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.062805 50037 task_exit.go:221] [ 37] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 11:29:50.063997 50037 task_exit.go:221] [ 37] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 11:29:50.064159 50037 task_signals.go:446] [ 21] Notified of signal 17 D0227 11:29:50.064246 50037 task_block.go:223] [ 21] Interrupt queued D0227 11:29:50.064416 50037 task_block.go:223] [ 21] Interrupt queued D0227 11:29:50.064595 50037 task_signals.go:179] [ 21] Restarting syscall 202 after errno 512: interrupted by signal 17 D0227 11:29:50.064678 50037 task_exit.go:221] [ 37] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 11:29:50.064737 50037 task_signals.go:220] [ 21] Signal 17: delivering to handler D0227 11:29:50.066582 50037 task_block.go:223] [ 38] Interrupt queued D0227 11:29:50.073239 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 11:29:50.074644 50037 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: 1582802901, NanoSec: 471221276}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 15206401}]} D0227 11:29:50.074806 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tclunk{FID: 11} D0227 11:29:50.075251 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rclunk{} D0227 11:29:50.075554 50037 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 11:29:50.076545 50037 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: 15206401}, 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: 1582802901, NanoSec: 471221276}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/27 11:29:50 executed programs: 0 D0227 11:29:50.085877 50037 task_stop.go:118] [ 36] Entering internal stop (*kernel.vforkStop)(nil) D0227 11:29:50.087524 50037 task_block.go:223] [ 39] Interrupt queued D0227 11:29:50.094113 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 11:29:50.096993 50037 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: 1582802901, NanoSec: 471221276}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 15206401}]} D0227 11:29:50.097178 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tclunk{FID: 11} D0227 11:29:50.097676 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rclunk{} D0227 11:29:50.098014 50037 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 11:29:50.099289 50037 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: 15206401}, 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: 1582802901, NanoSec: 471221276}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 11:29:50.100352 50037 syscalls.go:266] [ 39] Allocating stack with size of 8388608 bytes D0227 11:29:50.101478 50037 task_stop.go:137] [ 36] Leaving internal stop (*kernel.vforkStop)(nil) D0227 11:29:50.118362 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 11:29:50.118935 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.119122 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 11:29:50.119575 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.147252 50037 task_block.go:223] [ 40] Interrupt queued D0227 11:29:50.165345 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.165958 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.166116 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.166654 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.167010 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.167505 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.167633 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.168072 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.168999 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.169610 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.169789 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.170539 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.170962 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.171434 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.171606 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.172123 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.172620 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.173242 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.173478 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.174011 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.181343 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.181900 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.182105 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.182994 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.183339 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.183866 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.184006 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.184473 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.184770 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.185258 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.185391 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.185702 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.186234 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.186917 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.187210 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.187831 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.196193 50037 parameters.go:238] Clock(Monotonic): error: 406 ns, adjusted frequency from 2299773795 Hz to 2299775436 Hz D0227 11:29:50.196398 50037 parameters.go:238] Clock(Realtime): error: -230 ns, adjusted frequency from 2299774207 Hz to 2299774107 Hz D0227 11:29:50.196615 50037 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8497513047643991 monotonicBaseRef:90000603745 monotonicFrequency:2299775436 realtimeReady:1 realtimeBaseCycles:8497513048130996 realtimeBaseRef:1582802990196391747 realtimeFrequency:2299774107} D0227 11:29:50.214241 50037 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 11:29:50.214402 50037 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 11:29:50.214520 50037 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 11:29:50.214604 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.214702 50037 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 11:29:50.215334 50037 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 11:29:50.215508 50037 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0227 11:29:50.215647 50037 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0227 11:29:50.215988 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.216130 50037 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 11:29:50.216944 50037 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 11:29:50.217116 50037 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 11:29:50.217288 50037 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 11:29:50.217480 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.217655 50037 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 11:29:50.218242 50037 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 11:29:50.218323 50037 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0227 11:29:50.218391 50037 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0227 11:29:50.218465 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.218548 50037 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 11:29:50.219105 50037 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0227 11:29:50.219192 50037 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 11:29:50.219778 50037 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 11:29:50.219910 50037 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 11:29:50.219995 50037 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 11:29:50.220089 50037 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 11:29:50.220175 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.220249 50037 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 11:29:50.220805 50037 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 11:29:50.220875 50037 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0227 11:29:50.220954 50037 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0227 11:29:50.221050 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.221126 50037 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 11:29:50.221643 50037 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 11:29:50.221746 50037 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 11:29:50.222254 50037 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 11:29:50.222384 50037 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 11:29:50.222485 50037 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0227 11:29:50.222610 50037 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0227 11:29:50.222715 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.222802 50037 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 11:29:50.223284 50037 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 11:29:50.223378 50037 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0227 11:29:50.223485 50037 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0227 11:29:50.223553 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.223618 50037 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 11:29:50.224121 50037 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 11:29:50.224225 50037 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 11:29:50.224323 50037 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 11:29:50.224422 50037 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 11:29:50.224514 50037 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 11:29:50.225016 50037 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 11:29:50.225120 50037 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 11:29:50.225683 50037 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 11:29:50.397442 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.398065 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.398295 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.398669 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.398950 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.399413 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.399548 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.399920 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.400155 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.400483 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.400593 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.400957 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.401248 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.403954 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.404147 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.404574 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.404856 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.408129 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.408347 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.408887 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.409145 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.409512 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.409650 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.409974 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.414621 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.415281 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.419157 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.424897 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.425231 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.425743 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.425904 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.426374 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.426815 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.438138 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.438384 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.440477 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} D0227 11:29:50.441007 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 11:29:50.441677 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 2} D0227 11:29:50.441862 50037 transport_flipcall.go:127] send [channel @0xc0003a43c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 11:29:50.442319 50037 transport_flipcall.go:234] recv [channel @0xc0003a43c0] Rlerror{Error: 95} I0227 11:29:50.460416 50037 watchdog.go:277] Watchdog starting loop, tasks: 34, discount: 0s D0227 11:29:50.488384 50037 task_block.go:223] [ 41] Interrupt queued D0227 11:29:50.512729 50037 task_block.go:223] [ 42] Interrupt queued D0227 11:29:50.569629 50037 task_block.go:223] [ 43] Interrupt queued ================== WARNING: DATA RACE Read at 0x00c000760470 by goroutine 180: gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).windowCrossedACKThreshold() pkg/tcpip/transport/tcp/endpoint.go:1312 +0x9e gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).SetSockOptInt() pkg/tcpip/transport/tcp/endpoint.go:1394 +0x408 gvisor.dev/gvisor/pkg/sentry/socket/netstack.setSockOptSocket() pkg/sentry/socket/netstack/netstack.go:1549 +0x84c gvisor.dev/gvisor/pkg/sentry/socket/netstack.SetSockOpt() pkg/sentry/socket/netstack/netstack.go:1509 +0x1ad gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).SetSockOpt() pkg/sentry/socket/netstack/netstack.go:1501 +0x69d gvisor.dev/gvisor/pkg/sentry/syscalls/linux.SetSockOpt() pkg/sentry/syscalls/linux/sys_socket.go:541 +0x303 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous write at 0x00c000760470 by goroutine 353: gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*handshake).execute() pkg/tcpip/transport/tcp/connect.go:533 +0x631 gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).protocolMainLoop() pkg/tcpip/transport/tcp/connect.go:1280 +0xfc6 Goroutine 180 (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 353 (running) created at: gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).connect() pkg/tcpip/transport/tcp/endpoint.go:2044 +0xf2d gvisor.dev/gvisor/pkg/tcpip/transport/tcp.(*endpoint).Connect() pkg/tcpip/transport/tcp/endpoint.go:1873 +0x8c gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Connect() pkg/sentry/socket/netstack/netstack.go:698 +0x4c5 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Connect() pkg/sentry/syscalls/linux/sys_socket.go:280 +0x251 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 DIAGNOSIS: I0227 11:29:50.606689 59032 main.go:296] *************************** I0227 11:29:50.606968 59032 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-2] I0227 11:29:50.607245 59032 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 11:29:50.607419 59032 main.go:299] PID: 59032 I0227 11:29:50.607575 59032 main.go:300] UID: 0, GID: 0 I0227 11:29:50.607726 59032 main.go:301] Configuration: I0227 11:29:50.607820 59032 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 11:29:50.607944 59032 main.go:303] Platform: ptrace I0227 11:29:50.608033 59032 main.go:304] FileAccess: shared, overlay: false I0227 11:29:50.608142 59032 main.go:305] Network: sandbox, logging: false I0227 11:29:50.608336 59032 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 11:29:50.608526 59032 main.go:307] *************************** W0227 11:29:50.608670 59032 main.go:312] Block the TERM signal. This is only safe in tests! D0227 11:29:50.609022 59032 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.620197 59032 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0227 11:29:50.620492 59032 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.620724 59032 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.621321 59032 urpc.go:534] urpc: successfully marshalled 117 bytes. W0227 11:29:50.769113 59032 error.go:48] FATAL ERROR: container sandbox is not running container sandbox is not running W0227 11:29:50.769463 59032 main.go:329] Failure to execute command, err: 1 Error collecting stacks: failed to run ["/syzkaller/managers/ptrace-proxy-sandbox-race/current/image" "-root" "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "-watchdog-action=panic" "-network=none" "-debug" "-alsologtostderr" "-platform=ptrace" "-file-access=shared" "-network=sandbox" "-TESTONLY-unsafe-nonroot" "debug" "-stacks" "--ps" "ci-gvisor-ptrace-proxy-sandbox-race-2"]: exit status 128 I0227 11:29:50.606689 59032 main.go:296] *************************** I0227 11:29:50.606968 59032 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-2] I0227 11:29:50.607245 59032 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 11:29:50.607419 59032 main.go:299] PID: 59032 I0227 11:29:50.607575 59032 main.go:300] UID: 0, GID: 0 I0227 11:29:50.607726 59032 main.go:301] Configuration: I0227 11:29:50.607820 59032 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 11:29:50.607944 59032 main.go:303] Platform: ptrace I0227 11:29:50.608033 59032 main.go:304] FileAccess: shared, overlay: false I0227 11:29:50.608142 59032 main.go:305] Network: sandbox, logging: false I0227 11:29:50.608336 59032 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 11:29:50.608526 59032 main.go:307] *************************** W0227 11:29:50.608670 59032 main.go:312] Block the TERM signal. This is only safe in tests! D0227 11:29:50.609022 59032 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.620197 59032 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0227 11:29:50.620492 59032 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.620724 59032 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.621321 59032 urpc.go:534] urpc: successfully marshalled 117 bytes. W0227 11:29:50.769113 59032 error.go:48] FATAL ERROR: container sandbox is not running container sandbox is not running W0227 11:29:50.769463 59032 main.go:329] Failure to execute command, err: 1 ================== W0227 11:29:50.757503 58910 error.go:48] FATAL ERROR: waiting on pid 21: waiting on PID 21 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 21: waiting on PID 21 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2": urpc method "containerManager.WaitPID" failed: EOF W0227 11:29:50.757948 58910 main.go:329] Failure to execute command, err: 1 W0227 11:29:50.766726 50028 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-2" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0227 11:29:50.767295 50028 container.go:713] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.767469 50028 container.go:800] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.767570 50028 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-2" by destroying sandbox D0227 11:29:50.767670 50028 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0227 11:29:50.767771 50028 container.go:814] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-2", PID: 50036 I0227 11:29:50.970225 50028 main.go:320] Exiting with status: 16896