D0228 18:01:37.229088 36382 parameters.go:238] Clock(Monotonic): error: 284 ns, adjusted frequency from 2299774179 Hz to 2299775053 Hz D0228 18:01:37.229341 36382 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0228 18:01:37.229461 36382 parameters.go:238] Clock(Realtime): error: 443 ns, adjusted frequency from 2299774245 Hz to 2299775454 Hz D0228 18:01:37.229637 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750274452805368 monotonicBaseRef:2000532830 monotonicFrequency:2299775053 realtimeReady:1 realtimeBaseCycles:8750274453705447 realtimeBaseRef:1582912897229455991 realtimeFrequency:2299775454} D0228 18:01:38.229425 36382 parameters.go:238] Clock(Monotonic): error: 115 ns, adjusted frequency from 2299775053 Hz to 2299774791 Hz D0228 18:01:38.229697 36382 parameters.go:238] Clock(Realtime): error: 149 ns, adjusted frequency from 2299775454 Hz to 2299774858 Hz D0228 18:01:38.229830 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750276753364553 monotonicBaseRef:3000873790 monotonicFrequency:2299774791 realtimeReady:1 realtimeBaseCycles:8750276754005841 realtimeBaseRef:1582912898229684248 realtimeFrequency:2299774858} D0228 18:01:39.229020 36382 parameters.go:238] Clock(Monotonic): error: -68 ns, adjusted frequency from 2299774791 Hz to 2299774371 Hz D0228 18:01:39.229222 36382 parameters.go:238] Clock(Realtime): error: 6 ns, adjusted frequency from 2299774858 Hz to 2299774492 Hz D0228 18:01:39.229355 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750279052189430 monotonicBaseRef:4000460743 monotonicFrequency:2299774371 realtimeReady:1 realtimeBaseCycles:8750279052706926 realtimeBaseRef:1582912899229217344 realtimeFrequency:2299774492} D0228 18:01:40.228878 36382 parameters.go:238] Clock(Monotonic): error: 77 ns, adjusted frequency from 2299774371 Hz to 2299774732 Hz D0228 18:01:40.229108 36382 parameters.go:238] Clock(Realtime): error: 60 ns, adjusted frequency from 2299774492 Hz to 2299774662 Hz D0228 18:01:40.229203 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750281351664272 monotonicBaseRef:5000330500 monotonicFrequency:2299774732 realtimeReady:1 realtimeBaseCycles:8750281352205920 realtimeBaseRef:1582912900229097550 realtimeFrequency:2299774662} D0228 18:01:41.228868 36382 parameters.go:238] Clock(Monotonic): error: 20 ns, adjusted frequency from 2299774732 Hz to 2299774605 Hz D0228 18:01:41.229039 36382 parameters.go:238] Clock(Realtime): error: -24 ns, adjusted frequency from 2299774662 Hz to 2299774464 Hz D0228 18:01:41.229121 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750283651406750 monotonicBaseRef:6000316475 monotonicFrequency:2299774605 realtimeReady:1 realtimeBaseCycles:8750283651834911 realtimeBaseRef:1582912901229034208 realtimeFrequency:2299774464} D0228 18:01:42.228849 36382 parameters.go:238] Clock(Monotonic): error: 38 ns, adjusted frequency from 2299774605 Hz to 2299774664 Hz D0228 18:01:42.229064 36382 parameters.go:238] Clock(Realtime): error: -149 ns, adjusted frequency from 2299774464 Hz to 2299774227 Hz D0228 18:01:42.229202 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750285951146952 monotonicBaseRef:7000301515 monotonicFrequency:2299774664 realtimeReady:1 realtimeBaseCycles:8750285951667294 realtimeBaseRef:1582912902229059392 realtimeFrequency:2299774227} D0228 18:01:43.229173 36382 parameters.go:238] Clock(Monotonic): error: 22 ns, adjusted frequency from 2299774664 Hz to 2299774628 Hz D0228 18:01:43.229442 36382 parameters.go:238] Clock(Realtime): error: 126 ns, adjusted frequency from 2299774227 Hz to 2299774892 Hz D0228 18:01:43.229562 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750288251576198 monotonicBaseRef:8000586143 monotonicFrequency:2299774628 realtimeReady:1 realtimeBaseCycles:8750288252294836 realtimeBaseRef:1582912903229430434 realtimeFrequency:2299774892} D0228 18:01:44.228832 36382 parameters.go:238] Clock(Monotonic): error: 52 ns, adjusted frequency from 2299774628 Hz to 2299774713 Hz D0228 18:01:44.229025 36382 parameters.go:238] Clock(Realtime): error: 143 ns, adjusted frequency from 2299774892 Hz to 2299774877 Hz D0228 18:01:44.229193 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750290550662136 monotonicBaseRef:9000286683 monotonicFrequency:2299774713 realtimeReady:1 realtimeBaseCycles:8750290551127730 realtimeBaseRef:1582912904229020829 realtimeFrequency:2299774877} D0228 18:01:45.228879 36382 parameters.go:238] Clock(Monotonic): error: -3 ns, adjusted frequency from 2299774713 Hz to 2299774621 Hz D0228 18:01:45.229066 36382 parameters.go:238] Clock(Realtime): error: 27 ns, adjusted frequency from 2299774877 Hz to 2299774658 Hz D0228 18:01:45.229148 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750292850546271 monotonicBaseRef:10000334262 monotonicFrequency:2299774621 realtimeReady:1 realtimeBaseCycles:8750292850994891 realtimeBaseRef:1582912905229060956 realtimeFrequency:2299774658} D0228 18:01:46.228766 36382 parameters.go:238] Clock(Monotonic): error: -17 ns, adjusted frequency from 2299774621 Hz to 2299774599 Hz D0228 18:01:46.228953 36382 parameters.go:238] Clock(Realtime): error: -4 ns, adjusted frequency from 2299774658 Hz to 2299774606 Hz D0228 18:01:46.229078 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750295150061688 monotonicBaseRef:11000221553 monotonicFrequency:2299774599 realtimeReady:1 realtimeBaseCycles:8750295150509873 realtimeBaseRef:1582912906228948042 realtimeFrequency:2299774606} D0228 18:01:47.228828 36382 parameters.go:238] Clock(Monotonic): error: 48 ns, adjusted frequency from 2299774599 Hz to 2299774740 Hz D0228 18:01:47.229009 36382 parameters.go:238] Clock(Realtime): error: 11 ns, adjusted frequency from 2299774606 Hz to 2299774610 Hz D0228 18:01:47.229115 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750297449936463 monotonicBaseRef:12000265112 monotonicFrequency:2299774740 realtimeReady:1 realtimeBaseCycles:8750297450413462 realtimeBaseRef:1582912907229004127 realtimeFrequency:2299774610} D0228 18:01:48.228833 36382 parameters.go:238] Clock(Monotonic): error: -26 ns, adjusted frequency from 2299774740 Hz to 2299774580 Hz D0228 18:01:48.229028 36382 parameters.go:238] Clock(Realtime): error: 69 ns, adjusted frequency from 2299774610 Hz to 2299774741 Hz D0228 18:01:48.229115 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750299749763725 monotonicBaseRef:13000287949 monotonicFrequency:2299774580 realtimeReady:1 realtimeBaseCycles:8750299750231722 realtimeBaseRef:1582912908229023107 realtimeFrequency:2299774741} D0228 18:01:49.228874 36382 parameters.go:238] Clock(Monotonic): error: -9 ns, adjusted frequency from 2299774580 Hz to 2299774616 Hz D0228 18:01:49.229069 36382 parameters.go:238] Clock(Realtime): error: 30 ns, adjusted frequency from 2299774741 Hz to 2299774683 Hz D0228 18:01:49.229189 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750302049632272 monotonicBaseRef:14000328808 monotonicFrequency:2299774616 realtimeReady:1 realtimeBaseCycles:8750302050098710 realtimeBaseRef:1582912909229063218 realtimeFrequency:2299774683} D0228 18:01:50.229326 36382 parameters.go:238] Clock(Monotonic): error: 32 ns, adjusted frequency from 2299774616 Hz to 2299774706 Hz D0228 18:01:50.229565 36382 parameters.go:238] Clock(Realtime): error: 27 ns, adjusted frequency from 2299774683 Hz to 2299774685 Hz D0228 18:01:50.229700 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750304350425752 monotonicBaseRef:15000771835 monotonicFrequency:2299774706 realtimeReady:1 realtimeBaseCycles:8750304351015715 realtimeBaseRef:1582912910229559928 realtimeFrequency:2299774685} D0228 18:01:51.229162 36382 parameters.go:238] Clock(Monotonic): error: -8 ns, adjusted frequency from 2299774706 Hz to 2299774617 Hz D0228 18:01:51.229412 36382 parameters.go:238] Clock(Realtime): error: 41 ns, adjusted frequency from 2299774685 Hz to 2299774672 Hz D0228 18:01:51.229516 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750306649737130 monotonicBaseRef:16000570368 monotonicFrequency:2299774617 realtimeReady:1 realtimeBaseCycles:8750306650433879 realtimeBaseRef:1582912911229404903 realtimeFrequency:2299774672} D0228 18:01:52.228876 36382 parameters.go:238] Clock(Monotonic): error: 93 ns, adjusted frequency from 2299774617 Hz to 2299774854 Hz D0228 18:01:52.229090 36382 parameters.go:238] Clock(Realtime): error: 85 ns, adjusted frequency from 2299774672 Hz to 2299774803 Hz D0228 18:01:52.229213 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750308948956366 monotonicBaseRef:17000328874 monotonicFrequency:2299774854 realtimeReady:1 realtimeBaseCycles:8750308949470269 realtimeBaseRef:1582912912229083879 realtimeFrequency:2299774803} D0228 18:01:53.228924 36382 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0228 18:01:53.229178 36382 parameters.go:238] Clock(Monotonic): error: 358 ns, adjusted frequency from 2299774854 Hz to 2299775436 Hz D0228 18:01:53.229392 36382 parameters.go:238] Clock(Realtime): error: 155 ns, adjusted frequency from 2299774803 Hz to 2299774973 Hz D0228 18:01:53.229557 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750311249431918 monotonicBaseRef:18000633555 monotonicFrequency:2299775436 realtimeReady:1 realtimeBaseCycles:8750311249937894 realtimeBaseRef:1582912913229385135 realtimeFrequency:2299774973} D0228 18:01:54.228955 36382 parameters.go:238] Clock(Monotonic): error: 76 ns, adjusted frequency from 2299775436 Hz to 2299774872 Hz D0228 18:01:54.229195 36382 parameters.go:238] Clock(Realtime): error: -259 ns, adjusted frequency from 2299774973 Hz to 2299774032 Hz D0228 18:01:54.229287 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750313548646812 monotonicBaseRef:19000389817 monotonicFrequency:2299774872 realtimeReady:1 realtimeBaseCycles:8750313549230175 realtimeBaseRef:1582912914229175248 realtimeFrequency:2299774032} D0228 18:01:55.229265 36382 parameters.go:238] Clock(Monotonic): error: -544 ns, adjusted frequency from 2299774872 Hz to 2299773380 Hz D0228 18:01:55.229437 36382 parameters.go:238] Clock(Realtime): error: 27 ns, adjusted frequency from 2299774032 Hz to 2299774660 Hz D0228 18:01:55.229543 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750315849160485 monotonicBaseRef:20000711066 monotonicFrequency:2299773380 realtimeReady:1 realtimeBaseCycles:8750315849595322 realtimeBaseRef:1582912915229432279 realtimeFrequency:2299774660} D0228 18:01:56.228792 36382 parameters.go:238] Clock(Monotonic): error: 280 ns, adjusted frequency from 2299773380 Hz to 2299775215 Hz D0228 18:01:56.228957 36382 parameters.go:238] Clock(Realtime): error: -61 ns, adjusted frequency from 2299774660 Hz to 2299774486 Hz D0228 18:01:56.229073 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750318147872383 monotonicBaseRef:21000249506 monotonicFrequency:2299775215 realtimeReady:1 realtimeBaseCycles:8750318148266551 realtimeBaseRef:1582912916228952479 realtimeFrequency:2299774486} D0228 18:01:57.228901 36382 parameters.go:238] Clock(Monotonic): error: -255 ns, adjusted frequency from 2299775215 Hz to 2299774049 Hz D0228 18:01:57.229129 36382 parameters.go:238] Clock(Realtime): error: 150 ns, adjusted frequency from 2299774486 Hz to 2299775019 Hz D0228 18:01:57.229236 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750320447889434 monotonicBaseRef:22000354662 monotonicFrequency:2299774049 realtimeReady:1 realtimeBaseCycles:8750320448435350 realtimeBaseRef:1582912917229123936 realtimeFrequency:2299775019} D0228 18:01:58.228899 36382 parameters.go:238] Clock(Monotonic): error: 164 ns, adjusted frequency from 2299774049 Hz to 2299775020 Hz D0228 18:01:58.229109 36382 parameters.go:238] Clock(Realtime): error: 69 ns, adjusted frequency from 2299775019 Hz to 2299774794 Hz D0228 18:01:58.229242 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750322747652380 monotonicBaseRef:23000349834 monotonicFrequency:2299775020 realtimeReady:1 realtimeBaseCycles:8750322748164018 realtimeBaseRef:1582912918229103781 realtimeFrequency:2299774794} D0228 18:01:59.228938 36382 parameters.go:238] Clock(Monotonic): error: -144 ns, adjusted frequency from 2299775020 Hz to 2299774309 Hz D0228 18:01:59.229115 36382 parameters.go:238] Clock(Realtime): error: -125 ns, adjusted frequency from 2299774794 Hz to 2299774351 Hz D0228 18:01:59.229437 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750325047525333 monotonicBaseRef:24000392417 monotonicFrequency:2299774309 realtimeReady:1 realtimeBaseCycles:8750325047953404 realtimeBaseRef:1582912919229110125 realtimeFrequency:2299774351} D0228 18:02:00.228909 36382 parameters.go:238] Clock(Monotonic): error: 191 ns, adjusted frequency from 2299774309 Hz to 2299775091 Hz D0228 18:02:00.229123 36382 parameters.go:238] Clock(Realtime): error: 233 ns, adjusted frequency from 2299774351 Hz to 2299775210 Hz D0228 18:02:00.229264 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750327347221747 monotonicBaseRef:25000358546 monotonicFrequency:2299775091 realtimeReady:1 realtimeBaseCycles:8750327347740031 realtimeBaseRef:1582912920229115462 realtimeFrequency:2299775210} D0228 18:02:01.228952 36382 parameters.go:238] Clock(Monotonic): error: 2 ns, adjusted frequency from 2299775091 Hz to 2299774653 Hz D0228 18:02:01.229240 36382 parameters.go:238] Clock(Realtime): error: -380 ns, adjusted frequency from 2299775210 Hz to 2299773779 Hz D0228 18:02:01.229426 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750329647037531 monotonicBaseRef:26000376240 monotonicFrequency:2299774653 realtimeReady:1 realtimeBaseCycles:8750329647779026 realtimeBaseRef:1582912921229230162 realtimeFrequency:2299773779} D0228 18:02:02.229052 36382 parameters.go:238] Clock(Monotonic): error: -245 ns, adjusted frequency from 2299774653 Hz to 2299774090 Hz D0228 18:02:02.229253 36382 parameters.go:238] Clock(Realtime): error: 39 ns, adjusted frequency from 2299773779 Hz to 2299774740 Hz D0228 18:02:02.229334 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750331947100673 monotonicBaseRef:27000501682 monotonicFrequency:2299774090 realtimeReady:1 realtimeBaseCycles:8750331947594046 realtimeBaseRef:1582912922229248094 realtimeFrequency:2299774740} D0228 18:02:03.228916 36382 parameters.go:238] Clock(Monotonic): error: 409 ns, adjusted frequency from 2299774090 Hz to 2299775463 Hz D0228 18:02:03.229091 36382 parameters.go:238] Clock(Realtime): error: 24 ns, adjusted frequency from 2299774740 Hz to 2299774704 Hz D0228 18:02:03.229243 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750334246566854 monotonicBaseRef:28000367795 monotonicFrequency:2299775463 realtimeReady:1 realtimeBaseCycles:8750334246998538 realtimeBaseRef:1582912923229087100 realtimeFrequency:2299774704} D0228 18:02:04.229415 36382 parameters.go:238] Clock(Monotonic): error: 656 ns, adjusted frequency from 2299775463 Hz to 2299776183 Hz D0228 18:02:04.229615 36382 parameters.go:238] Clock(Realtime): error: -18 ns, adjusted frequency from 2299774704 Hz to 2299774595 Hz D0228 18:02:04.229843 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750336547489386 monotonicBaseRef:29000866569 monotonicFrequency:2299776183 realtimeReady:1 realtimeBaseCycles:8750336547975413 realtimeBaseRef:1582912924229609834 realtimeFrequency:2299774595} D0228 18:02:05.228838 36382 parameters.go:238] Clock(Monotonic): error: -733 ns, adjusted frequency from 2299776183 Hz to 2299773029 Hz D0228 18:02:05.229039 36382 parameters.go:238] Clock(Realtime): error: -202 ns, adjusted frequency from 2299774595 Hz to 2299774236 Hz D0228 18:02:05.229157 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750338845940469 monotonicBaseRef:30000290382 monotonicFrequency:2299773029 realtimeReady:1 realtimeBaseCycles:8750338846424339 realtimeBaseRef:1582912925229033399 realtimeFrequency:2299774236} D0228 18:02:06.228779 36382 parameters.go:238] Clock(Monotonic): error: 207 ns, adjusted frequency from 2299773029 Hz to 2299775009 Hz D0228 18:02:06.229006 36382 parameters.go:238] Clock(Realtime): error: 162 ns, adjusted frequency from 2299774236 Hz to 2299775068 Hz D0228 18:02:06.229145 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750341145578671 monotonicBaseRef:31000231755 monotonicFrequency:2299775009 realtimeReady:1 realtimeBaseCycles:8750341146121195 realtimeBaseRef:1582912926228999752 realtimeFrequency:2299775068} D0228 18:02:07.228886 36382 parameters.go:238] Clock(Monotonic): error: -295 ns, adjusted frequency from 2299775009 Hz to 2299773954 Hz D0228 18:02:07.229111 36382 parameters.go:238] Clock(Realtime): error: 451 ns, adjusted frequency from 2299775068 Hz to 2299775651 Hz D0228 18:02:07.229282 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750343445587824 monotonicBaseRef:32000333566 monotonicFrequency:2299773954 realtimeReady:1 realtimeBaseCycles:8750343446137203 realtimeBaseRef:1582912927229104518 realtimeFrequency:2299775651} D0228 18:02:08.228789 36382 parameters.go:238] Clock(Monotonic): error: 785 ns, adjusted frequency from 2299773954 Hz to 2299776508 Hz D0228 18:02:08.228976 36382 parameters.go:238] Clock(Realtime): error: -464 ns, adjusted frequency from 2299775651 Hz to 2299773570 Hz D0228 18:02:08.229078 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750345745155965 monotonicBaseRef:33000244073 monotonicFrequency:2299776508 realtimeReady:1 realtimeBaseCycles:8750345745603253 realtimeBaseRef:1582912928228969895 realtimeFrequency:2299773570} D0228 18:02:09.228878 36382 parameters.go:238] Clock(Monotonic): error: -984 ns, adjusted frequency from 2299776508 Hz to 2299772363 Hz D0228 18:02:09.229071 36382 parameters.go:238] Clock(Realtime): error: -5 ns, adjusted frequency from 2299773570 Hz to 2299774625 Hz D0228 18:02:09.229203 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750348045125926 monotonicBaseRef:34000328191 monotonicFrequency:2299772363 realtimeReady:1 realtimeBaseCycles:8750348045599309 realtimeBaseRef:1582912929229066637 realtimeFrequency:2299774625} D0228 18:02:09.512659 36382 urpc.go:577] urpc: unmarshal success. D0228 18:02:09.512880 36382 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 18:02:09.513195 36382 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 18:02:10.228873 36382 parameters.go:238] Clock(Monotonic): error: -10 ns, adjusted frequency from 2299772363 Hz to 2299774605 Hz D0228 18:02:10.229036 36382 parameters.go:238] Clock(Realtime): error: 64 ns, adjusted frequency from 2299774625 Hz to 2299774764 Hz D0228 18:02:10.229169 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750350344899738 monotonicBaseRef:35000328821 monotonicFrequency:2299774605 realtimeReady:1 realtimeBaseCycles:8750350345292602 realtimeBaseRef:1582912930229031271 realtimeFrequency:2299774764} D0228 18:02:11.228927 36382 parameters.go:238] Clock(Monotonic): error: 520 ns, adjusted frequency from 2299774605 Hz to 2299775786 Hz D0228 18:02:11.229093 36382 parameters.go:238] Clock(Realtime): error: 7 ns, adjusted frequency from 2299774764 Hz to 2299774670 Hz D0228 18:02:11.229252 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750352644670414 monotonicBaseRef:36000327112 monotonicFrequency:2299775786 realtimeReady:1 realtimeBaseCycles:8750352645195995 realtimeBaseRef:1582912931229087202 realtimeFrequency:2299774670} D0228 18:02:12.228814 36382 parameters.go:238] Clock(Monotonic): error: -43 ns, adjusted frequency from 2299775786 Hz to 2299774546 Hz D0228 18:02:12.229033 36382 parameters.go:238] Clock(Realtime): error: 64 ns, adjusted frequency from 2299774670 Hz to 2299774798 Hz D0228 18:02:12.229144 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750354944248030 monotonicBaseRef:37000240942 monotonicFrequency:2299774546 realtimeReady:1 realtimeBaseCycles:8750354944835191 realtimeBaseRef:1582912932229028294 realtimeFrequency:2299774798} D0228 18:02:13.228795 36382 parameters.go:238] Clock(Monotonic): error: -135 ns, adjusted frequency from 2299774546 Hz to 2299774218 Hz D0228 18:02:13.229000 36382 parameters.go:238] Clock(Realtime): error: -32 ns, adjusted frequency from 2299774798 Hz to 2299774561 Hz D0228 18:02:13.229112 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750357244042449 monotonicBaseRef:38000249583 monotonicFrequency:2299774218 realtimeReady:1 realtimeBaseCycles:8750357244533120 realtimeBaseRef:1582912933228994869 realtimeFrequency:2299774561} D0228 18:02:14.228818 36382 parameters.go:238] Clock(Monotonic): error: -86 ns, adjusted frequency from 2299774218 Hz to 2299774410 Hz D0228 18:02:14.228997 36382 parameters.go:238] Clock(Realtime): error: -67 ns, adjusted frequency from 2299774561 Hz to 2299774432 Hz D0228 18:02:14.229083 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750359543872132 monotonicBaseRef:39000273700 monotonicFrequency:2299774410 realtimeReady:1 realtimeBaseCycles:8750359544301597 realtimeBaseRef:1582912934228992223 realtimeFrequency:2299774432} D0228 18:02:15.228801 36382 parameters.go:238] Clock(Monotonic): error: -173 ns, adjusted frequency from 2299774410 Hz to 2299774308 Hz D0228 18:02:15.228984 36382 parameters.go:238] Clock(Realtime): error: 27 ns, adjusted frequency from 2299774432 Hz to 2299774608 Hz D0228 18:02:15.229105 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750361843603530 monotonicBaseRef:40000254997 monotonicFrequency:2299774308 realtimeReady:1 realtimeBaseCycles:8750361844045696 realtimeBaseRef:1582912935228979033 realtimeFrequency:2299774608} D0228 18:02:16.229077 36382 parameters.go:238] Clock(Monotonic): error: 297 ns, adjusted frequency from 2299774308 Hz to 2299775268 Hz D0228 18:02:16.229263 36382 parameters.go:238] Clock(Realtime): error: 137 ns, adjusted frequency from 2299774608 Hz to 2299774981 Hz D0228 18:02:16.229379 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750364144017478 monotonicBaseRef:41000533128 monotonicFrequency:2299775268 realtimeReady:1 realtimeBaseCycles:8750364144461778 realtimeBaseRef:1582912936229257962 realtimeFrequency:2299774981} D0228 18:02:17.228845 36382 parameters.go:238] Clock(Monotonic): error: -33 ns, adjusted frequency from 2299775268 Hz to 2299774524 Hz D0228 18:02:17.229041 36382 parameters.go:238] Clock(Realtime): error: 56 ns, adjusted frequency from 2299774981 Hz to 2299774772 Hz D0228 18:02:17.229180 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750366443244239 monotonicBaseRef:42000294623 monotonicFrequency:2299774524 realtimeReady:1 realtimeBaseCycles:8750366443724698 realtimeBaseRef:1582912937229035304 realtimeFrequency:2299774772} D0228 18:02:18.228857 36382 parameters.go:238] Clock(Monotonic): error: 289 ns, adjusted frequency from 2299774524 Hz to 2299775265 Hz D0228 18:02:18.229043 36382 parameters.go:238] Clock(Realtime): error: -408 ns, adjusted frequency from 2299774772 Hz to 2299773731 Hz D0228 18:02:18.229146 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750368743052557 monotonicBaseRef:43000309317 monotonicFrequency:2299775265 realtimeReady:1 realtimeBaseCycles:8750368743502963 realtimeBaseRef:1582912938229036822 realtimeFrequency:2299773731} D0228 18:02:19.228829 36382 parameters.go:238] Clock(Monotonic): error: -152 ns, adjusted frequency from 2299775265 Hz to 2299774251 Hz D0228 18:02:19.228983 36382 parameters.go:238] Clock(Realtime): error: -17 ns, adjusted frequency from 2299773731 Hz to 2299774620 Hz D0228 18:02:19.229116 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750371042769425 monotonicBaseRef:44000283924 monotonicFrequency:2299774251 realtimeReady:1 realtimeBaseCycles:8750371043141167 realtimeBaseRef:1582912939228977891 realtimeFrequency:2299774620} D0228 18:02:20.229779 36382 parameters.go:238] Clock(Monotonic): error: 269 ns, adjusted frequency from 2299774251 Hz to 2299775218 Hz D0228 18:02:20.229985 36382 parameters.go:238] Clock(Realtime): error: -11 ns, adjusted frequency from 2299774620 Hz to 2299774650 Hz D0228 18:02:20.230103 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750373344725024 monotonicBaseRef:45001232429 monotonicFrequency:2299775218 realtimeReady:1 realtimeBaseCycles:8750373345220187 realtimeBaseRef:1582912940229979902 realtimeFrequency:2299774650} I0228 18:02:20.365063 36382 watchdog.go:277] Watchdog starting loop, tasks: 16, discount: 0s D0228 18:02:21.229492 36382 parameters.go:238] Clock(Monotonic): error: -265 ns, adjusted frequency from 2299775218 Hz to 2299774049 Hz D0228 18:02:21.229643 36382 parameters.go:238] Clock(Realtime): error: 190 ns, adjusted frequency from 2299774650 Hz to 2299775061 Hz D0228 18:02:21.229737 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750375643807840 monotonicBaseRef:46000931355 monotonicFrequency:2299774049 realtimeReady:1 realtimeBaseCycles:8750375644209640 realtimeBaseRef:1582912941229638478 realtimeFrequency:2299775061} D0228 18:02:22.228846 36382 parameters.go:238] Clock(Monotonic): error: 66 ns, adjusted frequency from 2299774049 Hz to 2299774800 Hz D0228 18:02:22.229003 36382 parameters.go:238] Clock(Realtime): error: 42 ns, adjusted frequency from 2299775061 Hz to 2299774756 Hz D0228 18:02:22.229144 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750377942103169 monotonicBaseRef:47000288370 monotonicFrequency:2299774800 realtimeReady:1 realtimeBaseCycles:8750377942512775 realtimeBaseRef:1582912942228998447 realtimeFrequency:2299774756} D0228 18:02:23.228873 36382 parameters.go:238] Clock(Monotonic): error: -179 ns, adjusted frequency from 2299774800 Hz to 2299774257 Hz D0228 18:02:23.229106 36382 parameters.go:238] Clock(Realtime): error: 223 ns, adjusted frequency from 2299774756 Hz to 2299775160 Hz D0228 18:02:23.229239 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750380241961797 monotonicBaseRef:48000324820 monotonicFrequency:2299774257 realtimeReady:1 realtimeBaseCycles:8750380242521624 realtimeBaseRef:1582912943229100236 realtimeFrequency:2299775160} D0228 18:02:24.228839 36382 parameters.go:238] Clock(Monotonic): error: -33 ns, adjusted frequency from 2299774257 Hz to 2299774606 Hz D0228 18:02:24.228994 36382 parameters.go:238] Clock(Realtime): error: -20 ns, adjusted frequency from 2299775160 Hz to 2299774647 Hz D0228 18:02:24.229135 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750382541660055 monotonicBaseRef:49000291773 monotonicFrequency:2299774606 realtimeReady:1 realtimeBaseCycles:8750382542041624 realtimeBaseRef:1582912944228989286 realtimeFrequency:2299774647} D0228 18:02:25.228810 36382 parameters.go:238] Clock(Monotonic): error: 155 ns, adjusted frequency from 2299774606 Hz to 2299775013 Hz D0228 18:02:25.228950 36382 parameters.go:238] Clock(Realtime): error: -282 ns, adjusted frequency from 2299774647 Hz to 2299773996 Hz D0228 18:02:25.229032 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750384841374207 monotonicBaseRef:50000265486 monotonicFrequency:2299775013 realtimeReady:1 realtimeBaseCycles:8750384841714882 realtimeBaseRef:1582912945228945199 realtimeFrequency:2299773996} D0228 18:02:26.229310 36382 parameters.go:238] Clock(Monotonic): error: -68 ns, adjusted frequency from 2299775013 Hz to 2299774349 Hz D0228 18:02:26.229514 36382 parameters.go:238] Clock(Realtime): error: 136 ns, adjusted frequency from 2299773996 Hz to 2299774921 Hz D0228 18:02:26.229641 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750387142300850 monotonicBaseRef:51000766243 monotonicFrequency:2299774349 realtimeReady:1 realtimeBaseCycles:8750387142786061 realtimeBaseRef:1582912946229509247 realtimeFrequency:2299774921} D0228 18:02:27.228821 36382 parameters.go:238] Clock(Monotonic): error: -87 ns, adjusted frequency from 2299774349 Hz to 2299774486 Hz D0228 18:02:27.229045 36382 parameters.go:238] Clock(Realtime): error: 128 ns, adjusted frequency from 2299774921 Hz to 2299774878 Hz D0228 18:02:27.229216 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750389440929844 monotonicBaseRef:52000268213 monotonicFrequency:2299774486 realtimeReady:1 realtimeBaseCycles:8750389441478223 realtimeBaseRef:1582912947229038436 realtimeFrequency:2299774878} D0228 18:02:28.228831 36382 parameters.go:238] Clock(Monotonic): error: 80 ns, adjusted frequency from 2299774486 Hz to 2299774751 Hz D0228 18:02:28.228986 36382 parameters.go:238] Clock(Realtime): error: 256 ns, adjusted frequency from 2299774878 Hz to 2299775209 Hz D0228 18:02:28.229134 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750391740746486 monotonicBaseRef:53000286543 monotonicFrequency:2299774751 realtimeReady:1 realtimeBaseCycles:8750391741118723 realtimeBaseRef:1582912948228980005 realtimeFrequency:2299775209} D0228 18:02:29.228855 36382 parameters.go:238] Clock(Monotonic): error: 764 ns, adjusted frequency from 2299774751 Hz to 2299776599 Hz D0228 18:02:29.229109 36382 parameters.go:238] Clock(Realtime): error: 250 ns, adjusted frequency from 2299775209 Hz to 2299775323 Hz D0228 18:02:29.229260 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750394040569000 monotonicBaseRef:54000307311 monotonicFrequency:2299776599 realtimeReady:1 realtimeBaseCycles:8750394041173126 realtimeBaseRef:1582912949229101405 realtimeFrequency:2299775323} D0228 18:02:30.228796 36382 parameters.go:238] Clock(Monotonic): error: -316 ns, adjusted frequency from 2299776599 Hz to 2299774043 Hz D0228 18:02:30.229019 36382 parameters.go:238] Clock(Realtime): error: -781 ns, adjusted frequency from 2299775323 Hz to 2299772854 Hz D0228 18:02:30.229121 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750396340173389 monotonicBaseRef:55000232429 monotonicFrequency:2299774043 realtimeReady:1 realtimeBaseCycles:8750396340746973 realtimeBaseRef:1582912950229013798 realtimeFrequency:2299772854} D0228 18:02:31.228866 36382 parameters.go:238] Clock(Monotonic): error: -538 ns, adjusted frequency from 2299774043 Hz to 2299773419 Hz D0228 18:02:31.229067 36382 parameters.go:238] Clock(Realtime): error: -183 ns, adjusted frequency from 2299772854 Hz to 2299774265 Hz D0228 18:02:31.229185 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750398640091445 monotonicBaseRef:56000295049 monotonicFrequency:2299773419 realtimeReady:1 realtimeBaseCycles:8750398640627610 realtimeBaseRef:1582912951229060664 realtimeFrequency:2299774265} D0228 18:02:32.228868 36382 parameters.go:238] Clock(Monotonic): error: -219 ns, adjusted frequency from 2299773419 Hz to 2299774107 Hz D0228 18:02:32.229107 36382 parameters.go:238] Clock(Realtime): error: 475 ns, adjusted frequency from 2299774265 Hz to 2299775700 Hz D0228 18:02:32.229295 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750400939922115 monotonicBaseRef:57000319943 monotonicFrequency:2299774107 realtimeReady:1 realtimeBaseCycles:8750400940483210 realtimeBaseRef:1582912952229096030 realtimeFrequency:2299775700} D0228 18:02:33.229415 36382 parameters.go:238] Clock(Monotonic): error: 427 ns, adjusted frequency from 2299774107 Hz to 2299775574 Hz D0228 18:02:33.229599 36382 parameters.go:238] Clock(Realtime): error: -96 ns, adjusted frequency from 2299775700 Hz to 2299774405 Hz D0228 18:02:33.229720 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750403240955618 monotonicBaseRef:58000867560 monotonicFrequency:2299775574 realtimeReady:1 realtimeBaseCycles:8750403241401783 realtimeBaseRef:1582912953229592979 realtimeFrequency:2299774405} D0228 18:02:34.228880 36382 parameters.go:238] Clock(Monotonic): error: 63 ns, adjusted frequency from 2299775574 Hz to 2299774740 Hz D0228 18:02:34.229137 36382 parameters.go:238] Clock(Realtime): error: -12 ns, adjusted frequency from 2299774405 Hz to 2299774620 Hz D0228 18:02:34.229242 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750405539495344 monotonicBaseRef:59000330182 monotonicFrequency:2299774740 realtimeReady:1 realtimeBaseCycles:8750405540113505 realtimeBaseRef:1582912954229130897 realtimeFrequency:2299774620} D0228 18:02:35.228911 36382 parameters.go:238] Clock(Monotonic): error: -459 ns, adjusted frequency from 2299774740 Hz to 2299773692 Hz D0228 18:02:35.229126 36382 parameters.go:238] Clock(Realtime): error: -165 ns, adjusted frequency from 2299774620 Hz to 2299774284 Hz D0228 18:02:35.229260 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750407839336475 monotonicBaseRef:60000359050 monotonicFrequency:2299773692 realtimeReady:1 realtimeBaseCycles:8750407839863310 realtimeBaseRef:1582912955229120106 realtimeFrequency:2299774284} D0228 18:02:36.228817 36382 parameters.go:238] Clock(Monotonic): error: 221 ns, adjusted frequency from 2299773692 Hz to 2299775089 Hz D0228 18:02:36.228987 36382 parameters.go:238] Clock(Realtime): error: -2 ns, adjusted frequency from 2299774284 Hz to 2299774602 Hz D0228 18:02:36.229068 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750410138912843 monotonicBaseRef:61000273248 monotonicFrequency:2299775089 realtimeReady:1 realtimeBaseCycles:8750410139320483 realtimeBaseRef:1582912956228982218 realtimeFrequency:2299774602} D0228 18:02:37.229484 36382 parameters.go:238] Clock(Monotonic): error: 53 ns, adjusted frequency from 2299775089 Hz to 2299774735 Hz D0228 18:02:37.229716 36382 parameters.go:238] Clock(Realtime): error: 33 ns, adjusted frequency from 2299774602 Hz to 2299774686 Hz D0228 18:02:37.229929 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750412440203254 monotonicBaseRef:62000932148 monotonicFrequency:2299774735 realtimeReady:1 realtimeBaseCycles:8750412440770463 realtimeBaseRef:1582912957229710714 realtimeFrequency:2299774686} D0228 18:02:38.229145 36382 parameters.go:238] Clock(Monotonic): error: -92 ns, adjusted frequency from 2299774735 Hz to 2299774324 Hz D0228 18:02:38.229371 36382 parameters.go:238] Clock(Realtime): error: -15 ns, adjusted frequency from 2299774686 Hz to 2299774416 Hz D0228 18:02:38.229519 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750414739166745 monotonicBaseRef:63000579398 monotonicFrequency:2299774324 realtimeReady:1 realtimeBaseCycles:8750414739752132 realtimeBaseRef:1582912958229365890 realtimeFrequency:2299774416} D0228 18:02:39.228880 36382 parameters.go:238] Clock(Monotonic): error: -232 ns, adjusted frequency from 2299774324 Hz to 2299774013 Hz D0228 18:02:39.229133 36382 parameters.go:238] Clock(Realtime): error: -157 ns, adjusted frequency from 2299774416 Hz to 2299774301 Hz D0228 18:02:39.229258 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750417038367870 monotonicBaseRef:64000330156 monotonicFrequency:2299774013 realtimeReady:1 realtimeBaseCycles:8750417038978175 realtimeBaseRef:1582912959229127443 realtimeFrequency:2299774301} D0228 18:02:40.228989 36382 parameters.go:238] Clock(Monotonic): error: 702 ns, adjusted frequency from 2299774013 Hz to 2299776370 Hz D0228 18:02:40.229284 36382 parameters.go:238] Clock(Realtime): error: 270 ns, adjusted frequency from 2299774301 Hz to 2299775236 Hz D0228 18:02:40.229500 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750419338383456 monotonicBaseRef:65000435198 monotonicFrequency:2299776370 realtimeReady:1 realtimeBaseCycles:8750419339079492 realtimeBaseRef:1582912960229269637 realtimeFrequency:2299775236} D0228 18:02:41.228878 36382 parameters.go:238] Clock(Monotonic): error: -373 ns, adjusted frequency from 2299776370 Hz to 2299773677 Hz D0228 18:02:41.229264 36382 parameters.go:238] Clock(Realtime): error: 49 ns, adjusted frequency from 2299775236 Hz to 2299774768 Hz D0228 18:02:41.229378 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750421637906616 monotonicBaseRef:66000325095 monotonicFrequency:2299773677 realtimeReady:1 realtimeBaseCycles:8750421638814668 realtimeBaseRef:1582912961229252217 realtimeFrequency:2299774768} D0228 18:02:42.228944 36382 parameters.go:238] Clock(Monotonic): error: -316 ns, adjusted frequency from 2299773677 Hz to 2299773944 Hz D0228 18:02:42.229142 36382 parameters.go:238] Clock(Realtime): error: -91 ns, adjusted frequency from 2299774768 Hz to 2299774450 Hz D0228 18:02:42.229241 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750423937847289 monotonicBaseRef:67000397709 monotonicFrequency:2299773944 realtimeReady:1 realtimeBaseCycles:8750423938325430 realtimeBaseRef:1582912962229137420 realtimeFrequency:2299774450} D0228 18:02:42.433869 36382 urpc.go:577] urpc: unmarshal success. D0228 18:02:42.434209 36382 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 18:02:42.434421 36382 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 18:02:43.228833 36382 parameters.go:238] Clock(Monotonic): error: 425 ns, adjusted frequency from 2299773944 Hz to 2299775569 Hz D0228 18:02:43.229004 36382 parameters.go:238] Clock(Realtime): error: -56 ns, adjusted frequency from 2299774450 Hz to 2299774499 Hz D0228 18:02:43.229104 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750426237370766 monotonicBaseRef:68000288799 monotonicFrequency:2299775569 realtimeReady:1 realtimeBaseCycles:8750426237783463 realtimeBaseRef:1582912963228999833 realtimeFrequency:2299774499} D0228 18:02:44.228833 36382 parameters.go:238] Clock(Monotonic): error: -206 ns, adjusted frequency from 2299775569 Hz to 2299774171 Hz D0228 18:02:44.229054 36382 parameters.go:238] Clock(Realtime): error: 318 ns, adjusted frequency from 2299774499 Hz to 2299775390 Hz D0228 18:02:44.229179 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750428537131875 monotonicBaseRef:69000282511 monotonicFrequency:2299774171 realtimeReady:1 realtimeBaseCycles:8750428537668571 realtimeBaseRef:1582912964229047928 realtimeFrequency:2299775390} D0228 18:02:45.228922 36382 parameters.go:238] Clock(Monotonic): error: 197 ns, adjusted frequency from 2299774171 Hz to 2299775137 Hz D0228 18:02:45.229148 36382 parameters.go:238] Clock(Realtime): error: -175 ns, adjusted frequency from 2299775390 Hz to 2299774297 Hz D0228 18:02:45.229292 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750430837114031 monotonicBaseRef:70000372948 monotonicFrequency:2299775137 realtimeReady:1 realtimeBaseCycles:8750430837657304 realtimeBaseRef:1582912965229140694 realtimeFrequency:2299774297} D0228 18:02:46.228806 36382 parameters.go:238] Clock(Monotonic): error: -177 ns, adjusted frequency from 2299775137 Hz to 2299774304 Hz D0228 18:02:46.229021 36382 parameters.go:238] Clock(Realtime): error: -133 ns, adjusted frequency from 2299774297 Hz to 2299774328 Hz D0228 18:02:46.229130 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750433136623739 monotonicBaseRef:71000257532 monotonicFrequency:2299774304 realtimeReady:1 realtimeBaseCycles:8750433137143488 realtimeBaseRef:1582912966229015415 realtimeFrequency:2299774328} D0228 18:02:47.228860 36382 parameters.go:238] Clock(Monotonic): error: 72 ns, adjusted frequency from 2299774304 Hz to 2299774809 Hz D0228 18:02:47.229133 36382 parameters.go:238] Clock(Realtime): error: -10 ns, adjusted frequency from 2299774328 Hz to 2299774638 Hz D0228 18:02:47.229281 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750435436503756 monotonicBaseRef:72000303498 monotonicFrequency:2299774809 realtimeReady:1 realtimeBaseCycles:8750435437173931 realtimeBaseRef:1582912967229126780 realtimeFrequency:2299774638} D0228 18:02:48.229051 36382 parameters.go:238] Clock(Monotonic): error: -26 ns, adjusted frequency from 2299774809 Hz to 2299774514 Hz D0228 18:02:48.229240 36382 parameters.go:238] Clock(Realtime): error: 13 ns, adjusted frequency from 2299774638 Hz to 2299774616 Hz D0228 18:02:48.229325 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750437736730010 monotonicBaseRef:73000499797 monotonicFrequency:2299774514 realtimeReady:1 realtimeBaseCycles:8750437737198012 realtimeBaseRef:1582912968229235244 realtimeFrequency:2299774616} D0228 18:02:49.229120 36382 parameters.go:238] Clock(Monotonic): error: 133 ns, adjusted frequency from 2299774514 Hz to 2299774809 Hz D0228 18:02:49.229347 36382 parameters.go:238] Clock(Realtime): error: 107 ns, adjusted frequency from 2299774616 Hz to 2299774862 Hz D0228 18:02:49.229472 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750440036667918 monotonicBaseRef:74000570844 monotonicFrequency:2299774809 realtimeReady:1 realtimeBaseCycles:8750440037218008 realtimeBaseRef:1582912969229341941 realtimeFrequency:2299774862} D0228 18:02:50.228863 36382 parameters.go:238] Clock(Monotonic): error: -45 ns, adjusted frequency from 2299774809 Hz to 2299774542 Hz D0228 18:02:50.229072 36382 parameters.go:238] Clock(Realtime): error: 65 ns, adjusted frequency from 2299774862 Hz to 2299774863 Hz D0228 18:02:50.229231 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750442335850199 monotonicBaseRef:75000313197 monotonicFrequency:2299774542 realtimeReady:1 realtimeBaseCycles:8750442336354820 realtimeBaseRef:1582912970229064500 realtimeFrequency:2299774863} D0228 18:02:51.228819 36382 parameters.go:238] Clock(Monotonic): error: -361 ns, adjusted frequency from 2299774542 Hz to 2299773808 Hz D0228 18:02:51.229039 36382 parameters.go:238] Clock(Realtime): error: -425 ns, adjusted frequency from 2299774863 Hz to 2299773672 Hz D0228 18:02:51.229137 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750444635524311 monotonicBaseRef:76000269527 monotonicFrequency:2299773808 realtimeReady:1 realtimeBaseCycles:8750444636036409 realtimeBaseRef:1582912971229023942 realtimeFrequency:2299773672} D0228 18:02:52.228805 36382 parameters.go:238] Clock(Monotonic): error: 429 ns, adjusted frequency from 2299773808 Hz to 2299775697 Hz D0228 18:02:52.229037 36382 parameters.go:238] Clock(Realtime): error: 321 ns, adjusted frequency from 2299773672 Hz to 2299775377 Hz D0228 18:02:52.229186 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750446935268795 monotonicBaseRef:77000256776 monotonicFrequency:2299775697 realtimeReady:1 realtimeBaseCycles:8750446935827263 realtimeBaseRef:1582912972229031413 realtimeFrequency:2299775377} D0228 18:02:53.228882 36382 parameters.go:238] Clock(Monotonic): error: 52 ns, adjusted frequency from 2299775697 Hz to 2299774700 Hz D0228 18:02:53.229063 36382 parameters.go:238] Clock(Realtime): error: -161 ns, adjusted frequency from 2299775377 Hz to 2299774256 Hz D0228 18:02:53.229170 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750449235223466 monotonicBaseRef:78000334598 monotonicFrequency:2299774700 realtimeReady:1 realtimeBaseCycles:8750449235667298 realtimeBaseRef:1582912973229059527 realtimeFrequency:2299774256} D0228 18:02:54.228885 36382 parameters.go:238] Clock(Monotonic): error: -113 ns, adjusted frequency from 2299774700 Hz to 2299774277 Hz D0228 18:02:54.229061 36382 parameters.go:238] Clock(Realtime): error: 200 ns, adjusted frequency from 2299774256 Hz to 2299775107 Hz D0228 18:02:54.229158 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750451535005593 monotonicBaseRef:79000337827 monotonicFrequency:2299774277 realtimeReady:1 realtimeBaseCycles:8750451535437201 realtimeBaseRef:1582912974229057634 realtimeFrequency:2299775107} D0228 18:02:55.228906 36382 parameters.go:238] Clock(Monotonic): error: -292 ns, adjusted frequency from 2299774277 Hz to 2299774023 Hz D0228 18:02:55.229167 36382 parameters.go:238] Clock(Realtime): error: 22 ns, adjusted frequency from 2299775107 Hz to 2299774674 Hz D0228 18:02:55.229336 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750453834820948 monotonicBaseRef:80000355688 monotonicFrequency:2299774023 realtimeReady:1 realtimeBaseCycles:8750453835447076 realtimeBaseRef:1582912975229159717 realtimeFrequency:2299774674} D0228 18:02:56.228805 36382 parameters.go:238] Clock(Monotonic): error: 254 ns, adjusted frequency from 2299774023 Hz to 2299775135 Hz D0228 18:02:56.228989 36382 parameters.go:238] Clock(Realtime): error: -129 ns, adjusted frequency from 2299774674 Hz to 2299774341 Hz D0228 18:02:56.229108 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750456134374712 monotonicBaseRef:81000259913 monotonicFrequency:2299775135 realtimeReady:1 realtimeBaseCycles:8750456134816540 realtimeBaseRef:1582912976228983521 realtimeFrequency:2299774341} D0228 18:02:57.228791 36382 parameters.go:238] Clock(Monotonic): error: 44 ns, adjusted frequency from 2299775135 Hz to 2299774742 Hz D0228 18:02:57.228991 36382 parameters.go:238] Clock(Realtime): error: -226 ns, adjusted frequency from 2299774341 Hz to 2299774171 Hz D0228 18:02:57.229121 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750458434093693 monotonicBaseRef:82000235495 monotonicFrequency:2299774742 realtimeReady:1 realtimeBaseCycles:8750458434595777 realtimeBaseRef:1582912977228985649 realtimeFrequency:2299774171} D0228 18:02:58.228901 36382 parameters.go:238] Clock(Monotonic): error: -78 ns, adjusted frequency from 2299774742 Hz to 2299774538 Hz D0228 18:02:58.229166 36382 parameters.go:238] Clock(Realtime): error: 443 ns, adjusted frequency from 2299774171 Hz to 2299775653 Hz D0228 18:02:58.229323 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750460734136998 monotonicBaseRef:83000352272 monotonicFrequency:2299774538 realtimeReady:1 realtimeBaseCycles:8750460734770167 realtimeBaseRef:1582912978229159674 realtimeFrequency:2299775653} D0228 18:02:59.228872 36382 parameters.go:238] Clock(Monotonic): error: -257 ns, adjusted frequency from 2299774538 Hz to 2299774148 Hz D0228 18:02:59.229156 36382 parameters.go:238] Clock(Realtime): error: -379 ns, adjusted frequency from 2299775653 Hz to 2299773706 Hz D0228 18:02:59.229273 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750463033825116 monotonicBaseRef:84000314694 monotonicFrequency:2299774148 realtimeReady:1 realtimeBaseCycles:8750463034520952 realtimeBaseRef:1582912979229148860 realtimeFrequency:2299773706} D0228 18:03:00.228852 36382 parameters.go:238] Clock(Monotonic): error: 291 ns, adjusted frequency from 2299774148 Hz to 2299775331 Hz D0228 18:03:00.229115 36382 parameters.go:238] Clock(Realtime): error: 311 ns, adjusted frequency from 2299773706 Hz to 2299775262 Hz D0228 18:03:00.229250 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750465333555686 monotonicBaseRef:85000295745 monotonicFrequency:2299775331 realtimeReady:1 realtimeBaseCycles:8750465334185691 realtimeBaseRef:1582912980229101478 realtimeFrequency:2299775262} D0228 18:03:01.228821 36382 parameters.go:238] Clock(Monotonic): error: -350 ns, adjusted frequency from 2299775331 Hz to 2299773871 Hz D0228 18:03:01.229028 36382 parameters.go:238] Clock(Realtime): error: -112 ns, adjusted frequency from 2299775262 Hz to 2299774367 Hz D0228 18:03:01.229143 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750467633257782 monotonicBaseRef:86000263900 monotonicFrequency:2299773871 realtimeReady:1 realtimeBaseCycles:8750467633778932 realtimeBaseRef:1582912981229022330 realtimeFrequency:2299774367} D0228 18:03:02.228906 36382 parameters.go:238] Clock(Monotonic): error: 341 ns, adjusted frequency from 2299773871 Hz to 2299775495 Hz D0228 18:03:02.229148 36382 parameters.go:238] Clock(Realtime): error: 55 ns, adjusted frequency from 2299774367 Hz to 2299774733 Hz D0228 18:03:02.229271 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750469933236585 monotonicBaseRef:87000353009 monotonicFrequency:2299775495 realtimeReady:1 realtimeBaseCycles:8750469933829361 realtimeBaseRef:1582912982229142368 realtimeFrequency:2299774733} D0228 18:03:03.228914 36382 parameters.go:238] Clock(Monotonic): error: -283 ns, adjusted frequency from 2299775495 Hz to 2299774090 Hz D0228 18:03:03.229197 36382 parameters.go:238] Clock(Realtime): error: 366 ns, adjusted frequency from 2299774733 Hz to 2299775422 Hz D0228 18:03:03.229352 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750472233039003 monotonicBaseRef:88000364715 monotonicFrequency:2299774090 realtimeReady:1 realtimeBaseCycles:8750472233709932 realtimeBaseRef:1582912983229188389 realtimeFrequency:2299775422} D0228 18:03:04.228948 36382 parameters.go:238] Clock(Monotonic): error: 167 ns, adjusted frequency from 2299774090 Hz to 2299775036 Hz D0228 18:03:04.229214 36382 parameters.go:238] Clock(Realtime): error: -148 ns, adjusted frequency from 2299775422 Hz to 2299774267 Hz D0228 18:03:04.229429 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750474532882181 monotonicBaseRef:89000394756 monotonicFrequency:2299775036 realtimeReady:1 realtimeBaseCycles:8750474533525600 realtimeBaseRef:1582912984229205888 realtimeFrequency:2299774267} D0228 18:03:04.606863 36382 urpc.go:577] urpc: unmarshal success. D0228 18:03:04.607098 36382 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 18:03:04.607354 36382 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 18:03:05.228861 36382 parameters.go:238] Clock(Monotonic): error: 173 ns, adjusted frequency from 2299775036 Hz to 2299775066 Hz D0228 18:03:05.229105 36382 parameters.go:238] Clock(Realtime): error: -19 ns, adjusted frequency from 2299774267 Hz to 2299774581 Hz D0228 18:03:05.229229 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750476832464553 monotonicBaseRef:90000310980 monotonicFrequency:2299775066 realtimeReady:1 realtimeBaseCycles:8750476833053050 realtimeBaseRef:1582912985229098565 realtimeFrequency:2299774581} I0228 18:03:05.365903 36382 watchdog.go:277] Watchdog starting loop, tasks: 16, discount: 0s D0228 18:03:06.228788 36382 parameters.go:238] Clock(Monotonic): error: -165 ns, adjusted frequency from 2299775066 Hz to 2299774264 Hz D0228 18:03:06.229027 36382 parameters.go:238] Clock(Realtime): error: -6 ns, adjusted frequency from 2299774581 Hz to 2299774571 Hz D0228 18:03:06.229143 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750479132081560 monotonicBaseRef:91000242251 monotonicFrequency:2299774264 realtimeReady:1 realtimeBaseCycles:8750479132648834 realtimeBaseRef:1582912986229020819 realtimeFrequency:2299774571} I0228 18:03:06.324986 48884 main.go:296] *************************** I0228 18:03:06.325147 48884 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=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller869146371] I0228 18:03:06.325499 48884 main.go:298] Version release-20200219.0-63-gc96bb4d2ebc6 I0228 18:03:06.325590 48884 main.go:299] PID: 48884 I0228 18:03:06.325680 48884 main.go:300] UID: 0, GID: 0 I0228 18:03:06.325746 48884 main.go:301] Configuration: I0228 18:03:06.325812 48884 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 18:03:06.325879 48884 main.go:303] Platform: ptrace I0228 18:03:06.325937 48884 main.go:304] FileAccess: shared, overlay: false I0228 18:03:06.326011 48884 main.go:305] Network: sandbox, logging: false I0228 18:03:06.326100 48884 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 18:03:06.326184 48884 main.go:307] *************************** W0228 18:03:06.326236 48884 main.go:312] Block the TERM signal. This is only safe in tests! D0228 18:03:06.326595 48884 container.go:159] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.332192 48884 container.go:592] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0228 18:03:06.332350 48884 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.332419 48884 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.332862 48884 urpc.go:534] urpc: successfully marshalled 117 bytes. D0228 18:03:06.333083 36382 urpc.go:577] urpc: unmarshal success. D0228 18:03:06.333283 36382 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-2 Signo:0 PID:0 Mode:Process} D0228 18:03:06.333501 36382 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 18:03:06.333677 48884 urpc.go:577] urpc: unmarshal success. D0228 18:03:06.333786 48884 exec.go:120] Exec arguments: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller869146371 D0228 18:03:06.333890 48884 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0228 18:03:06.333996 48884 container.go:533] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-2", args: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller869146371 D0228 18:03:06.334124 48884 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-2" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.334266 48884 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.335040 48884 urpc.go:534] urpc: successfully marshalled 634 bytes. D0228 18:03:06.335374 36382 urpc.go:577] urpc: unmarshal success. D0228 18:03:06.336438 36382 controller.go:267] containerManager.ExecuteAsync: /syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller869146371 D0228 18:03:06.336655 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0228 18:03:06.338153 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.338306 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 18:03:06.338785 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} I0228 18:03:06.339256 36382 kernel.go:795] EXEC: [/syz-execprog -executor=/syz-executor -arch=amd64 -sandbox=none -procs=1 -repeat=0 -threaded=true -collide=true -cover=0 -fault_call=-1 -fault_nth=-1 /syzkaller869146371] D0228 18:03:06.340102 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0228 18:03:06.341547 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582836029, NanoSec: 349298839}, MTime: {Sec: 1582836029, NanoSec: 349298839}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18612277}]} D0228 18:03:06.341732 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0228 18:03:06.342168 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.342390 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetattr{FID: 5, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 18:03:06.343247 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18612277}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582836029, NanoSec: 349298839}, MTime: {Sec: 1582836029, NanoSec: 349298839}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 18:03:06.343396 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalk{FID: 5, NewFID: 6, Names: []} D0228 18:03:06.344044 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rwalk{QIDs: []} D0228 18:03:06.344185 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tlopen{FID: 6, Flags: ReadOnly} D0228 18:03:06.345130 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18612277}, IoUnit: 0, File: &{{33}}} D0228 18:03:06.350528 36382 syscalls.go:266] Allocating stack with size of 8388608 bytes D0228 18:03:06.351616 36382 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-2 0}:0xc000358840 {ci-gvisor-ptrace-proxy-sandbox-race-2 22}:0xc0005dd160] D0228 18:03:06.351857 36382 urpc.go:534] urpc: successfully marshalled 37 bytes. D0228 18:03:06.352001 48884 urpc.go:577] urpc: unmarshal success. D0228 18:03:06.352146 48884 container.go:580] Wait on PID 22 in container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.352280 48884 sandbox.go:743] Waiting for PID 22 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.352371 48884 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:06.352652 48884 urpc.go:534] urpc: successfully marshalled 100 bytes. D0228 18:03:06.353253 36382 urpc.go:577] urpc: unmarshal success. D0228 18:03:06.353480 36382 controller.go:443] containerManager.Wait D0228 18:03:06.355042 36382 task_block.go:223] [ 22] Interrupt queued D0228 18:03:06.557194 36382 task_block.go:223] [ 23] Interrupt queued D0228 18:03:06.557904 36382 task_block.go:223] [ 24] Interrupt queued D0228 18:03:06.561089 36382 task_block.go:223] [ 25] Interrupt queued D0228 18:03:06.564781 36382 task_block.go:223] [ 26] Interrupt queued D0228 18:03:06.575186 36382 task_block.go:223] [ 27] Interrupt queued D0228 18:03:06.584622 36382 task_block.go:223] [ 28] Interrupt queued D0228 18:03:06.624901 36382 task_block.go:223] [ 29] Interrupt queued D0228 18:03:06.633080 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0228 18:03:06.633755 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.633920 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 18:03:06.634378 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.663156 36382 task_block.go:223] [ 30] Interrupt queued D0228 18:03:06.691007 36382 task_block.go:223] [ 31] Interrupt queued D0228 18:03:06.691455 36382 task_block.go:223] [ 32] Interrupt queued D0228 18:03:06.699060 36382 task_block.go:223] [ 33] Interrupt queued D0228 18:03:06.724363 36382 task_block.go:223] [ 34] Interrupt queued D0228 18:03:06.731871 36382 task_block.go:223] [ 35] Interrupt queued D0228 18:03:06.759985 36382 task_block.go:223] [ 36] Interrupt queued D0228 18:03:06.763427 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller869146371]} D0228 18:03:06.764770 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] 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: 454, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582912986, NanoSec: 290427589}, MTime: {Sec: 1582912986, NanoSec: 290427589}, CTime: {Sec: 1582912986, NanoSec: 290427589}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18612228}]} D0228 18:03:06.765072 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller869146371, Size: 1} D0228 18:03:06.765641 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.765986 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetattr{FID: 7, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 18:03:06.766866 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18612228}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 454, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582912986, NanoSec: 290427589}, MTime: {Sec: 1582912986, NanoSec: 290427589}, CTime: {Sec: 1582912986, NanoSec: 290427589}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 18:03:06.767038 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalk{FID: 7, NewFID: 8, Names: []} D0228 18:03:06.767653 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rwalk{QIDs: []} D0228 18:03:06.768065 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tlopen{FID: 8, Flags: ReadOnly} D0228 18:03:06.768353 36382 task_block.go:223] [ 37] Interrupt queued D0228 18:03:06.769074 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18612228}, IoUnit: 0, File: &{{27}}} D0228 18:03:06.772584 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetattr{FID: 8, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 18:03:06.773437 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18612228}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 454, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582912986, NanoSec: 290427589}, MTime: {Sec: 1582912986, NanoSec: 290427589}, CTime: {Sec: 1582912986, NanoSec: 290427589}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 18:03:06 parsed 1 programs D0228 18:03:06.784626 36382 task_stop.go:118] [ 32] Entering internal stop (*kernel.vforkStop)(nil) D0228 18:03:06.785375 36382 task_block.go:223] [ 38] Interrupt queued D0228 18:03:06.797016 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0228 18:03:06.798588 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18612278}]} D0228 18:03:06.798829 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0228 18:03:06.799316 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.799604 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 18:03:06.800549 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18612278}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 18:03:06.800710 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalk{FID: 9, NewFID: 10, Names: []} D0228 18:03:06.801453 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rwalk{QIDs: []} D0228 18:03:06.801632 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tlopen{FID: 10, Flags: ReadOnly} D0228 18:03:06.802561 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlopen{QID: QID{Type: 0, Version: 0, Path: 18612278}, IoUnit: 0, File: &{{28}}} D0228 18:03:06.803762 36382 syscalls.go:266] [ 38] Allocating stack with size of 8388608 bytes D0228 18:03:06.804522 36382 task_stop.go:137] [ 32] Leaving internal stop (*kernel.vforkStop)(nil) D0228 18:03:06.830115 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 18:03:06.830772 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.830973 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 18:03:06.831441 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.832952 36382 task_exit.go:221] [ 38] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 18:03:06.834226 36382 task_exit.go:221] [ 38] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 18:03:06.834412 36382 task_signals.go:446] [ 22] Notified of signal 17 D0228 18:03:06.834553 36382 task_block.go:223] [ 22] Interrupt queued D0228 18:03:06.834712 36382 task_block.go:223] [ 22] Interrupt queued D0228 18:03:06.834937 36382 task_signals.go:179] [ 22] Restarting syscall 202 after errno 512: interrupted by signal 17 D0228 18:03:06.835004 36382 task_exit.go:221] [ 38] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 18:03:06.835077 36382 task_signals.go:220] [ 22] Signal 17: delivering to handler D0228 18:03:06.837372 36382 task_block.go:223] [ 39] Interrupt queued D0228 18:03:06.842189 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 18:03:06.868557 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18612278}]} D0228 18:03:06.868815 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tclunk{FID: 11} D0228 18:03:06.870019 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rclunk{} D0228 18:03:06.870269 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 18:03:06.871510 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18612278}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/28 18:03:06 executed programs: 0 D0228 18:03:06.880077 36382 task_stop.go:118] [ 22] Entering internal stop (*kernel.vforkStop)(nil) D0228 18:03:06.880734 36382 task_block.go:223] [ 40] Interrupt queued D0228 18:03:06.887191 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0228 18:03:06.888476 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 18612278}]} D0228 18:03:06.888637 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tclunk{FID: 11} D0228 18:03:06.889105 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rclunk{} D0228 18:03:06.889371 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0228 18:03:06.890307 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 18612278}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582836029, NanoSec: 449308645}, MTime: {Sec: 1582836029, NanoSec: 449308645}, CTime: {Sec: 1582912896, NanoSec: 261606252}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0228 18:03:06.891462 36382 syscalls.go:266] [ 40] Allocating stack with size of 8388608 bytes D0228 18:03:06.892558 36382 task_stop.go:137] [ 22] Leaving internal stop (*kernel.vforkStop)(nil) D0228 18:03:06.899602 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0228 18:03:06.900162 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.900360 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0228 18:03:06.900804 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.911545 36382 task_block.go:223] [ 41] Interrupt queued D0228 18:03:06.917510 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.918086 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.918329 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.919036 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.920222 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.921043 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.921217 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.921810 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.922388 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.923034 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.923218 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.923708 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.924291 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.924933 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.925102 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.925589 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.925973 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.926414 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.926581 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.926928 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.927416 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.927853 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.928017 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.928387 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.928658 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.929245 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.929434 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.929959 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.930472 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.931088 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.931256 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.931768 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.932629 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:06.933041 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:06.933179 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:06.933583 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:06.961648 36382 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 18:03:06.961808 36382 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 18:03:06.961894 36382 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 18:03:06.961969 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.962050 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.962540 36382 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 18:03:06.962613 36382 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0228 18:03:06.962680 36382 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0228 18:03:06.962737 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.962819 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.963249 36382 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 18:03:06.963346 36382 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 18:03:06.963408 36382 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 18:03:06.963481 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.963537 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.964017 36382 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 18:03:06.964086 36382 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0228 18:03:06.964166 36382 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0228 18:03:06.964244 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.964336 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.964727 36382 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0228 18:03:06.964815 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0228 18:03:06.965333 36382 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 18:03:06.965398 36382 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 18:03:06.965481 36382 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0228 18:03:06.965571 36382 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0228 18:03:06.965675 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.965754 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.966268 36382 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 18:03:06.966338 36382 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0228 18:03:06.966415 36382 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0228 18:03:06.966500 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.966571 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.967115 36382 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 18:03:06.967243 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0228 18:03:06.967767 36382 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 18:03:06.967864 36382 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0228 18:03:06.968019 36382 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0228 18:03:06.968146 36382 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0228 18:03:06.968251 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.968340 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.968844 36382 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0228 18:03:06.968908 36382 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0228 18:03:06.969000 36382 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0228 18:03:06.969081 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.969181 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.969837 36382 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0228 18:03:06.969966 36382 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0228 18:03:06.970132 36382 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0228 18:03:06.970224 36382 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0228 18:03:06.970322 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0228 18:03:06.970897 36382 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0228 18:03:06.971068 36382 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0228 18:03:06.971694 36382 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0228 18:03:07.192292 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.193050 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.193175 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.193911 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.194342 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.194952 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.195098 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.195508 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.195821 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.196354 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.196489 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.196909 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.197184 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.197743 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.197889 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.198265 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.198477 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.198922 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.199145 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.199618 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.199903 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.200316 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.200460 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.200874 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.201081 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.201596 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.201738 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.202199 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.202676 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.203185 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.203351 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.203865 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.204350 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.205288 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.205420 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.205940 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.206210 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.206717 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.206895 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.207393 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.227138 36382 task_block.go:223] [ 42] Interrupt queued D0228 18:03:07.228836 36382 parameters.go:238] Clock(Monotonic): error: 41 ns, adjusted frequency from 2299774264 Hz to 2299774572 Hz D0228 18:03:07.229223 36382 parameters.go:238] Clock(Realtime): error: 335 ns, adjusted frequency from 2299774571 Hz to 2299775415 Hz D0228 18:03:07.229405 36382 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8750481431910489 monotonicBaseRef:92000266020 monotonicFrequency:2299774572 realtimeReady:1 realtimeBaseCycles:8750481432867561 realtimeBaseRef:1582912987229213949 realtimeFrequency:2299775415} D0228 18:03:07.238022 36382 task_block.go:223] [ 43] Interrupt queued D0228 18:03:07.261713 36382 task_block.go:223] [ 44] Interrupt queued D0228 18:03:07.275690 36382 task_block.go:223] [ 43] Interrupt queued D0228 18:03:07.275735 36382 task_block.go:223] [ 43] Interrupt queued D0228 18:03:07.275844 36382 task_block.go:223] [ 44] Interrupt queued D0228 18:03:07.275921 36382 task_block.go:223] [ 44] Interrupt queued D0228 18:03:07.275991 36382 task_exit.go:221] [ 42] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 18:03:07.276163 36382 task_signals.go:189] [ 44] Signal 9: terminating thread group D0228 18:03:07.276230 36382 task_exit.go:221] [ 42] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 18:03:07.276264 36382 task_signals.go:189] [ 43] Signal 9: terminating thread group I0228 18:03:07.276535 36382 compat.go:129] Uncaught signal: "killed" (9), PID: 42, TID: 43, fault addr: 0x0 D0228 18:03:07.276751 36382 task_exit.go:221] [ 43] Transitioning from exit state TaskExitNone to TaskExitInitiated I0228 18:03:07.276758 36382 compat.go:129] Uncaught signal: "killed" (9), PID: 42, TID: 44, fault addr: 0x0 D0228 18:03:07.276917 36382 task_exit.go:221] [ 44] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 18:03:07.277178 36382 task_exit.go:221] [ 43] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 18:03:07.277283 36382 task_exit.go:221] [ 43] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 18:03:07.279476 36382 task_exit.go:221] [ 44] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 18:03:07.279629 36382 task_exit.go:221] [ 44] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 18:03:07.279818 36382 task_signals.go:419] [ 41] Discarding ignored signal 17 D0228 18:03:07.280013 36382 task_exit.go:221] [ 42] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 18:03:07.283109 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.283741 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.283941 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.284379 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.285035 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.285869 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.286002 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.286416 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.286999 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.287439 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.287550 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.287950 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.296039 36382 task_block.go:223] [ 45] Interrupt queued D0228 18:03:07.311204 36382 task_block.go:223] [ 46] Interrupt queued D0228 18:03:07.334358 36382 task_block.go:223] [ 47] Interrupt queued D0228 18:03:07.343964 36382 task_block.go:223] [ 46] Interrupt queued D0228 18:03:07.344038 36382 task_block.go:223] [ 46] Interrupt queued D0228 18:03:07.344152 36382 task_block.go:223] [ 47] Interrupt queued D0228 18:03:07.344272 36382 task_exit.go:221] [ 45] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 18:03:07.344277 36382 task_block.go:223] [ 47] Interrupt queued D0228 18:03:07.344539 36382 task_exit.go:221] [ 45] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 18:03:07.344593 36382 task_signals.go:189] [ 46] Signal 9: terminating thread group D0228 18:03:07.344626 36382 task_signals.go:189] [ 47] Signal 9: terminating thread group I0228 18:03:07.344785 36382 compat.go:129] Uncaught signal: "killed" (9), PID: 45, TID: 46, fault addr: 0x0 D0228 18:03:07.344926 36382 task_exit.go:221] [ 46] Transitioning from exit state TaskExitNone to TaskExitInitiated I0228 18:03:07.344924 36382 compat.go:129] Uncaught signal: "killed" (9), PID: 45, TID: 47, fault addr: 0x0 D0228 18:03:07.345098 36382 task_exit.go:221] [ 47] Transitioning from exit state TaskExitNone to TaskExitInitiated D0228 18:03:07.345290 36382 task_exit.go:221] [ 46] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 18:03:07.345447 36382 task_exit.go:221] [ 46] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 18:03:07.346947 36382 task_exit.go:221] [ 47] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0228 18:03:07.347114 36382 task_exit.go:221] [ 47] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 18:03:07.347345 36382 task_signals.go:419] [ 41] Discarding ignored signal 17 D0228 18:03:07.347614 36382 task_exit.go:221] [ 45] Transitioning from exit state TaskExitZombie to TaskExitDead D0228 18:03:07.350463 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.351115 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.351268 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.351817 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.352694 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.353263 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.353477 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.353960 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.354998 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0228 18:03:07.355481 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 2} D0228 18:03:07.355635 36382 transport_flipcall.go:127] send [channel @0xc0003a6240] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0228 18:03:07.356217 36382 transport_flipcall.go:234] recv [channel @0xc0003a6240] Rlerror{Error: 95} D0228 18:03:07.364615 36382 task_block.go:223] [ 48] Interrupt queued D0228 18:03:07.373119 36382 task_block.go:223] [ 49] Interrupt queued D0228 18:03:07.389073 36382 task_block.go:223] [ 50] Interrupt queued ================== WARNING: DATA RACE Write at 0x00c0002b3210 by goroutine 346: gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Connect() pkg/tcpip/transport/udp/endpoint.go:1053 +0x46a gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Connect() pkg/sentry/socket/netstack/netstack.go:698 +0x4c5 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Connect() pkg/sentry/syscalls/linux/sys_socket.go:280 +0x251 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous read at 0x00c0002b3210 by goroutine 218: gvisor.dev/gvisor/pkg/tcpip/stack.(*TransportEndpointInfo).AddrNetProto() pkg/tcpip/stack/stack.go:573 +0x79 gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).checkV4Mapped() pkg/tcpip/transport/udp/endpoint.go:931 +0xee gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Connect() pkg/tcpip/transport/udp/endpoint.go:984 +0x6c gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Connect() pkg/sentry/socket/netstack/netstack.go:698 +0x4c5 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Connect() pkg/sentry/syscalls/linux/sys_socket.go:280 +0x251 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Goroutine 346 (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 218 (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() DIAGNOSIS: I0228 18:03:07.430884 49184 main.go:296] *************************** I0228 18:03:07.431022 49184 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-2] I0228 18:03:07.431164 49184 main.go:298] Version release-20200219.0-63-gc96bb4d2ebc6 I0228 18:03:07.431250 49184 main.go:299] PID: 49184 I0228 18:03:07.431320 49184 main.go:300] UID: 0, GID: 0 I0228 18:03:07.431386 49184 main.go:301] Configuration: I0228 18:03:07.431463 49184 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 18:03:07.431532 49184 main.go:303] Platform: ptrace I0228 18:03:07.431606 49184 main.go:304] FileAccess: shared, overlay: false I0228 18:03:07.431793 49184 main.go:305] Network: sandbox, logging: false I0228 18:03:07.431892 49184 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 18:03:07.432026 49184 main.go:307] *************************** W0228 18:03:07.432120 49184 main.go:312] Block the TERM signal. This is only safe in tests! D0228 18:03:07.432308 49184 container.go:159] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.438352 49184 container.go:592] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0228 18:03:07.438550 49184 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.438662 49184 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.439144 49184 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 18:03:07.532929 49184 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2", PID: 36382 I0228 18:03:07.533283 49184 debug.go:131] Retrieving sandbox stacks D0228 18:03:07.533457 49184 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.533612 49184 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" W0228 18:03:07.533844 49184 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 36382: connection refused retrieving stacks: connecting to control server at PID 36382: connection refused W0228 18:03:07.534231 49184 main.go:329] Failure to execute command, err: 1 Error collecting stacks: failed to run ["/syzkaller/managers/ptrace-proxy-sandbox-race/current/image" "-root" "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "-watchdog-action=panic" "-network=none" "-debug" "-alsologtostderr" "-platform=ptrace" "-file-access=shared" "-network=sandbox" "-TESTONLY-unsafe-nonroot" "debug" "-stacks" "--ps" "ci-gvisor-ptrace-proxy-sandbox-race-2"]: exit status 128 I0228 18:03:07.430884 49184 main.go:296] *************************** I0228 18:03:07.431022 49184 main.go:297] Args: [/syzkaller/managers/ptrace-proxy-sandbox-race/current/image -root /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root -watchdog-action=panic -network=none -debug -alsologtostderr -platform=ptrace -file-access=shared -network=sandbox -TESTONLY-unsafe-nonroot debug -stacks --ps ci-gvisor-ptrace-proxy-sandbox-race-2] I0228 18:03:07.431164 49184 main.go:298] Version release-20200219.0-63-gc96bb4d2ebc6 I0228 18:03:07.431250 49184 main.go:299] PID: 49184 I0228 18:03:07.431320 49184 main.go:300] UID: 0, GID: 0 I0228 18:03:07.431386 49184 main.go:301] Configuration: I0228 18:03:07.431463 49184 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0228 18:03:07.431532 49184 main.go:303] Platform: ptrace I0228 18:03:07.431606 49184 main.go:304] FileAccess: shared, overlay: false I0228 18:03:07.431793 49184 main.go:305] Network: sandbox, logging: false I0228 18:03:07.431892 49184 main.go:306] Strace: false, max size: 1024, syscalls: [] I0228 18:03:07.432026 49184 main.go:307] *************************** W0228 18:03:07.432120 49184 main.go:312] Block the TERM signal. This is only safe in tests! D0228 18:03:07.432308 49184 container.go:159] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.438352 49184 container.go:592] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-2": signal 0 D0228 18:03:07.438550 49184 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.438662 49184 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.439144 49184 urpc.go:534] urpc: successfully marshalled 117 bytes. I0228 18:03:07.532929 49184 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2", PID: 36382 I0228 18:03:07.533283 49184 debug.go:131] Retrieving sandbox stacks D0228 18:03:07.533457 49184 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.533612 49184 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" W0228 18:03:07.533844 49184 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 36382: connection refused retrieving stacks: connecting to control server at PID 36382: connection refused W0228 18:03:07.534231 49184 main.go:329] Failure to execute command, err: 1 pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 ================== W0228 18:03:07.524222 48884 error.go:48] FATAL ERROR: waiting on pid 22: waiting on PID 22 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 22: waiting on PID 22 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2": urpc method "containerManager.WaitPID" failed: EOF W0228 18:03:07.524629 48884 main.go:329] Failure to execute command, err: 1 W0228 18:03:07.532866 36371 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-2" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0228 18:03:07.533606 36371 container.go:714] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.533897 36371 container.go:801] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.534012 36371 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-2" by destroying sandbox D0228 18:03:07.534127 36371 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-2" D0228 18:03:07.534227 36371 container.go:815] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-2", PID: 36381 I0228 18:03:07.736435 36371 main.go:320] Exiting with status: 16896