D0227 12:14:07.641087 6245 parameters.go:238] Clock(Monotonic): error: 212 ns, adjusted frequency from 2299774070 Hz to 2299774791 Hz D0227 12:14:07.641412 6245 parameters.go:238] Clock(Realtime): error: 215 ns, adjusted frequency from 2299774029 Hz to 2299774776 Hz D0227 12:14:07.641523 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503624571845479 monotonicBaseRef:2000267740 monotonicFrequency:2299774791 realtimeReady:1 realtimeBaseCycles:8503624572646713 realtimeBaseRef:1582805647641406769 realtimeFrequency:2299774776} D0227 12:14:08.641775 6245 parameters.go:238] Clock(Monotonic): error: 80 ns, adjusted frequency from 2299774791 Hz to 2299774556 Hz D0227 12:14:08.641972 6245 parameters.go:238] Clock(Realtime): error: 141 ns, adjusted frequency from 2299774776 Hz to 2299774693 Hz D0227 12:14:08.642102 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503626873198443 monotonicBaseRef:3000953969 monotonicFrequency:2299774556 realtimeReady:1 realtimeBaseCycles:8503626873712008 realtimeBaseRef:1582805648641967919 realtimeFrequency:2299774693} D0227 12:14:09.641902 6245 parameters.go:238] Clock(Monotonic): error: 126 ns, adjusted frequency from 2299774556 Hz to 2299774725 Hz D0227 12:14:09.642113 6245 parameters.go:238] Clock(Realtime): error: 75 ns, adjusted frequency from 2299774693 Hz to 2299774599 Hz D0227 12:14:09.642238 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503629173260999 monotonicBaseRef:4001079198 monotonicFrequency:2299774725 realtimeReady:1 realtimeBaseCycles:8503629173809716 realtimeBaseRef:1582805649642108374 realtimeFrequency:2299774599} D0227 12:14:10.642022 6245 parameters.go:238] Clock(Monotonic): error: 25 ns, adjusted frequency from 2299774725 Hz to 2299774507 Hz D0227 12:14:10.642239 6245 parameters.go:238] Clock(Realtime): error: 63 ns, adjusted frequency from 2299774599 Hz to 2299774600 Hz D0227 12:14:10.642359 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503631473349515 monotonicBaseRef:5001215642 monotonicFrequency:2299774507 realtimeReady:1 realtimeBaseCycles:8503631473873510 realtimeBaseRef:1582805650642234123 realtimeFrequency:2299774600} D0227 12:14:11.643185 6245 parameters.go:238] Clock(Monotonic): error: 57 ns, adjusted frequency from 2299774507 Hz to 2299774602 Hz D0227 12:14:11.643385 6245 parameters.go:238] Clock(Realtime): error: 54 ns, adjusted frequency from 2299774600 Hz to 2299774598 Hz D0227 12:14:11.643504 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503633775766160 monotonicBaseRef:6002364510 monotonicFrequency:2299774602 realtimeReady:1 realtimeBaseCycles:8503633776284911 realtimeBaseRef:1582805651643380670 realtimeFrequency:2299774598} D0227 12:14:12.643239 6245 parameters.go:238] Clock(Monotonic): error: 33 ns, adjusted frequency from 2299774602 Hz to 2299774558 Hz D0227 12:14:12.643472 6245 parameters.go:238] Clock(Realtime): error: 12 ns, adjusted frequency from 2299774598 Hz to 2299774510 Hz D0227 12:14:12.643574 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503636075673677 monotonicBaseRef:7002422304 monotonicFrequency:2299774558 realtimeReady:1 realtimeBaseCycles:8503636076259519 realtimeBaseRef:1582805652643467639 realtimeFrequency:2299774510} D0227 12:14:13.641258 6245 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 12:14:13.641491 6245 parameters.go:238] Clock(Monotonic): error: 292 ns, adjusted frequency from 2299774558 Hz to 2299775172 Hz D0227 12:14:13.641658 6245 sampler.go:168] Time: Adjusting syscall overhead up to 8000 D0227 12:14:13.641771 6245 parameters.go:238] Clock(Realtime): error: 233 ns, adjusted frequency from 2299774510 Hz to 2299775024 Hz D0227 12:14:13.641894 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503638371416097 monotonicBaseRef:8000669028 monotonicFrequency:2299775172 realtimeReady:1 realtimeBaseCycles:8503638372112319 realtimeBaseRef:1582805653641762380 realtimeFrequency:2299775024} D0227 12:14:14.642748 6245 parameters.go:238] Clock(Monotonic): error: 233 ns, adjusted frequency from 2299775172 Hz to 2299774921 Hz D0227 12:14:14.642972 6245 parameters.go:238] Clock(Realtime): error: 145 ns, adjusted frequency from 2299775024 Hz to 2299774782 Hz D0227 12:14:14.643086 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503640674100815 monotonicBaseRef:9001934171 monotonicFrequency:2299774921 realtimeReady:1 realtimeBaseCycles:8503640674654026 realtimeBaseRef:1582805654642965403 realtimeFrequency:2299774782} D0227 12:14:15.641123 6245 parameters.go:238] Clock(Monotonic): error: -370 ns, adjusted frequency from 2299774921 Hz to 2299773705 Hz D0227 12:14:15.641363 6245 parameters.go:238] Clock(Realtime): error: -246 ns, adjusted frequency from 2299774782 Hz to 2299773981 Hz D0227 12:14:15.641463 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503642970146962 monotonicBaseRef:10000312806 monotonicFrequency:2299773705 realtimeReady:1 realtimeBaseCycles:8503642970729168 realtimeBaseRef:1582805655641356706 realtimeFrequency:2299773981} D0227 12:14:16.643352 6245 parameters.go:238] Clock(Monotonic): error: 47 ns, adjusted frequency from 2299773705 Hz to 2299774665 Hz D0227 12:14:16.643553 6245 parameters.go:238] Clock(Realtime): error: 246 ns, adjusted frequency from 2299773981 Hz to 2299775082 Hz D0227 12:14:16.643698 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503645275026624 monotonicBaseRef:11002533005 monotonicFrequency:2299774665 realtimeReady:1 realtimeBaseCycles:8503645275543871 realtimeBaseRef:1582805656643548539 realtimeFrequency:2299775082} D0227 12:14:17.643868 6245 parameters.go:238] Clock(Monotonic): error: -3 ns, adjusted frequency from 2299774665 Hz to 2299774549 Hz D0227 12:14:17.644112 6245 parameters.go:238] Clock(Realtime): error: 72 ns, adjusted frequency from 2299775082 Hz to 2299774673 Hz D0227 12:14:17.644252 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503647575985287 monotonicBaseRef:12003047837 monotonicFrequency:2299774549 realtimeReady:1 realtimeBaseCycles:8503647576599812 realtimeBaseRef:1582805657644105488 realtimeFrequency:2299774673} D0227 12:14:18.642090 6245 parameters.go:238] Clock(Monotonic): error: -41 ns, adjusted frequency from 2299774549 Hz to 2299774454 Hz D0227 12:14:18.642306 6245 parameters.go:238] Clock(Realtime): error: -60 ns, adjusted frequency from 2299774673 Hz to 2299774388 Hz D0227 12:14:18.642397 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503649871698774 monotonicBaseRef:13001281984 monotonicFrequency:2299774454 realtimeReady:1 realtimeBaseCycles:8503649872222773 realtimeBaseRef:1582805658642300218 realtimeFrequency:2299774388} D0227 12:14:19.641242 6245 parameters.go:238] Clock(Monotonic): error: 307 ns, adjusted frequency from 2299774454 Hz to 2299775199 Hz D0227 12:14:19.641454 6245 parameters.go:238] Clock(Realtime): error: 51 ns, adjusted frequency from 2299774388 Hz to 2299774618 Hz D0227 12:14:19.641574 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503652169522580 monotonicBaseRef:14000433792 monotonicFrequency:2299775199 realtimeReady:1 realtimeBaseCycles:8503652170037748 realtimeBaseRef:1582805659641448215 realtimeFrequency:2299774618} D0227 12:14:20.642901 6245 parameters.go:238] Clock(Monotonic): error: 18 ns, adjusted frequency from 2299775199 Hz to 2299774494 Hz D0227 12:14:20.643090 6245 parameters.go:238] Clock(Realtime): error: -31 ns, adjusted frequency from 2299774618 Hz to 2299774452 Hz D0227 12:14:20.643203 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503654473117659 monotonicBaseRef:15002094771 monotonicFrequency:2299774494 realtimeReady:1 realtimeBaseCycles:8503654473577503 realtimeBaseRef:1582805660643085391 realtimeFrequency:2299774452} D0227 12:14:21.643117 6245 parameters.go:238] Clock(Monotonic): error: -186 ns, adjusted frequency from 2299774494 Hz to 2299774131 Hz D0227 12:14:21.643313 6245 parameters.go:238] Clock(Realtime): error: 100 ns, adjusted frequency from 2299774452 Hz to 2299774763 Hz D0227 12:14:21.643438 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503656773334045 monotonicBaseRef:16002286916 monotonicFrequency:2299774131 realtimeReady:1 realtimeBaseCycles:8503656773862814 realtimeBaseRef:1582805661643307525 realtimeFrequency:2299774763} D0227 12:14:22.643786 6245 parameters.go:238] Clock(Monotonic): error: 326 ns, adjusted frequency from 2299774131 Hz to 2299775188 Hz D0227 12:14:22.644011 6245 parameters.go:238] Clock(Realtime): error: -50 ns, adjusted frequency from 2299774763 Hz to 2299774425 Hz D0227 12:14:22.644120 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503659074690654 monotonicBaseRef:17002975017 monotonicFrequency:2299775188 realtimeReady:1 realtimeBaseCycles:8503659075244493 realtimeBaseRef:1582805662644006252 realtimeFrequency:2299774425} D0227 12:14:23.642419 6245 parameters.go:238] Clock(Monotonic): error: 135 ns, adjusted frequency from 2299775188 Hz to 2299774875 Hz D0227 12:14:23.642694 6245 parameters.go:238] Clock(Realtime): error: 249 ns, adjusted frequency from 2299774425 Hz to 2299775130 Hz D0227 12:14:23.642852 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503661371280114 monotonicBaseRef:18001589782 monotonicFrequency:2299774875 realtimeReady:1 realtimeBaseCycles:8503661371984569 realtimeBaseRef:1582805663642686840 realtimeFrequency:2299775130} D0227 12:14:24.641639 6245 parameters.go:238] Clock(Monotonic): error: -430 ns, adjusted frequency from 2299774875 Hz to 2299773580 Hz D0227 12:14:24.641861 6245 parameters.go:238] Clock(Realtime): error: -199 ns, adjusted frequency from 2299775130 Hz to 2299774065 Hz D0227 12:14:24.641960 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503663669277222 monotonicBaseRef:19000816764 monotonicFrequency:2299773580 realtimeReady:1 realtimeBaseCycles:8503663669847156 realtimeBaseRef:1582805664641855218 realtimeFrequency:2299774065} D0227 12:14:25.641776 6245 parameters.go:238] Clock(Monotonic): error: -23 ns, adjusted frequency from 2299773580 Hz to 2299774500 Hz D0227 12:14:25.642011 6245 parameters.go:238] Clock(Realtime): error: 30 ns, adjusted frequency from 2299774065 Hz to 2299774580 Hz D0227 12:14:25.642126 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503665969397107 monotonicBaseRef:20000967346 monotonicFrequency:2299774500 realtimeReady:1 realtimeBaseCycles:8503665969966524 realtimeBaseRef:1582805665642005364 realtimeFrequency:2299774580} D0227 12:14:26.641679 6245 parameters.go:238] Clock(Monotonic): error: 252 ns, adjusted frequency from 2299774500 Hz to 2299775049 Hz D0227 12:14:26.641920 6245 parameters.go:238] Clock(Realtime): error: 63 ns, adjusted frequency from 2299774580 Hz to 2299774688 Hz D0227 12:14:26.642019 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503668268955881 monotonicBaseRef:21000873542 monotonicFrequency:2299775049 realtimeReady:1 realtimeBaseCycles:8503668269530208 realtimeBaseRef:1582805666641913661 realtimeFrequency:2299774688} D0227 12:14:27.643064 6245 parameters.go:238] Clock(Monotonic): error: -96 ns, adjusted frequency from 2299775049 Hz to 2299774339 Hz D0227 12:14:27.643484 6245 parameters.go:238] Clock(Realtime): error: -97 ns, adjusted frequency from 2299774688 Hz to 2299774383 Hz D0227 12:14:27.643661 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503670571897642 monotonicBaseRef:22002250507 monotonicFrequency:2299774339 realtimeReady:1 realtimeBaseCycles:8503670572889319 realtimeBaseRef:1582805667643472258 realtimeFrequency:2299774383} D0227 12:14:28.643476 6245 parameters.go:238] Clock(Monotonic): error: 230 ns, adjusted frequency from 2299774339 Hz to 2299775126 Hz D0227 12:14:28.643670 6245 parameters.go:238] Clock(Realtime): error: 20 ns, adjusted frequency from 2299774383 Hz to 2299774637 Hz D0227 12:14:28.643784 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503672872631075 monotonicBaseRef:23002667545 monotonicFrequency:2299775126 realtimeReady:1 realtimeBaseCycles:8503672873107022 realtimeBaseRef:1582805668643665024 realtimeFrequency:2299774637} D0227 12:14:29.642054 6245 parameters.go:238] Clock(Monotonic): error: -369 ns, adjusted frequency from 2299775126 Hz to 2299773810 Hz D0227 12:14:29.642286 6245 parameters.go:238] Clock(Realtime): error: 16 ns, adjusted frequency from 2299774637 Hz to 2299774593 Hz D0227 12:14:29.642383 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503675169127104 monotonicBaseRef:24001241711 monotonicFrequency:2299773810 realtimeReady:1 realtimeBaseCycles:8503675169695718 realtimeBaseRef:1582805669642279696 realtimeFrequency:2299774593} D0227 12:14:30.641146 6245 parameters.go:238] Clock(Monotonic): error: 345 ns, adjusted frequency from 2299773810 Hz to 2299775277 Hz D0227 12:14:30.641359 6245 parameters.go:238] Clock(Realtime): error: 26 ns, adjusted frequency from 2299774593 Hz to 2299774602 Hz D0227 12:14:30.641482 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503677466820538 monotonicBaseRef:25000337110 monotonicFrequency:2299775277 realtimeReady:1 realtimeBaseCycles:8503677467339261 realtimeBaseRef:1582805670641353061 realtimeFrequency:2299774602} D0227 12:14:31.641889 6245 parameters.go:238] Clock(Monotonic): error: -46 ns, adjusted frequency from 2299775277 Hz to 2299774480 Hz D0227 12:14:31.642100 6245 parameters.go:238] Clock(Realtime): error: -36 ns, adjusted frequency from 2299774602 Hz to 2299774474 Hz D0227 12:14:31.642211 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503679768191413 monotonicBaseRef:26001030916 monotonicFrequency:2299774480 realtimeReady:1 realtimeBaseCycles:8503679768817996 realtimeBaseRef:1582805671642094061 realtimeFrequency:2299774474} D0227 12:14:32.641733 6245 parameters.go:238] Clock(Monotonic): error: -288 ns, adjusted frequency from 2299774480 Hz to 2299774017 Hz D0227 12:14:32.641961 6245 parameters.go:238] Clock(Realtime): error: 59 ns, adjusted frequency from 2299774474 Hz to 2299774729 Hz D0227 12:14:32.642100 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503682067702453 monotonicBaseRef:27000916365 monotonicFrequency:2299774017 realtimeReady:1 realtimeBaseCycles:8503682068272595 realtimeBaseRef:1582805672641954971 realtimeFrequency:2299774729} D0227 12:14:33.641186 6245 parameters.go:238] Clock(Monotonic): error: -14 ns, adjusted frequency from 2299774017 Hz to 2299774530 Hz D0227 12:14:33.641411 6245 parameters.go:238] Clock(Realtime): error: -63 ns, adjusted frequency from 2299774729 Hz to 2299774422 Hz D0227 12:14:33.641505 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503684366238989 monotonicBaseRef:28000378276 monotonicFrequency:2299774530 realtimeReady:1 realtimeBaseCycles:8503684366781750 realtimeBaseRef:1582805673641404667 realtimeFrequency:2299774422} D0227 12:14:34.641848 6245 parameters.go:238] Clock(Monotonic): error: 227 ns, adjusted frequency from 2299774530 Hz to 2299774997 Hz D0227 12:14:34.642068 6245 parameters.go:238] Clock(Realtime): error: 35 ns, adjusted frequency from 2299774422 Hz to 2299774705 Hz D0227 12:14:34.642176 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503686667490704 monotonicBaseRef:29001020593 monotonicFrequency:2299774997 realtimeReady:1 realtimeBaseCycles:8503686668067062 realtimeBaseRef:1582805674642061640 realtimeFrequency:2299774705} D0227 12:14:35.642215 6245 parameters.go:238] Clock(Monotonic): error: 45 ns, adjusted frequency from 2299774997 Hz to 2299774663 Hz D0227 12:14:35.642447 6245 parameters.go:238] Clock(Realtime): error: -281 ns, adjusted frequency from 2299774705 Hz to 2299773993 Hz D0227 12:14:35.642580 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503688968120364 monotonicBaseRef:30001392221 monotonicFrequency:2299774663 realtimeReady:1 realtimeBaseCycles:8503688968713448 realtimeBaseRef:1582805675642440668 realtimeFrequency:2299773993} D0227 12:14:36.641878 6245 parameters.go:238] Clock(Monotonic): error: -152 ns, adjusted frequency from 2299774663 Hz to 2299774233 Hz D0227 12:14:36.642101 6245 parameters.go:238] Clock(Realtime): error: 273 ns, adjusted frequency from 2299773993 Hz to 2299775108 Hz D0227 12:14:36.642239 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503691267152917 monotonicBaseRef:31001069532 monotonicFrequency:2299774233 realtimeReady:1 realtimeBaseCycles:8503691267693408 realtimeBaseRef:1582805676642095402 realtimeFrequency:2299775108} D0227 12:14:37.641218 6245 parameters.go:238] Clock(Monotonic): error: 750 ns, adjusted frequency from 2299774233 Hz to 2299776378 Hz D0227 12:14:37.641442 6245 parameters.go:238] Clock(Realtime): error: 5 ns, adjusted frequency from 2299775108 Hz to 2299774552 Hz D0227 12:14:37.641575 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503693565399036 monotonicBaseRef:32000405069 monotonicFrequency:2299776378 realtimeReady:1 realtimeBaseCycles:8503693565944147 realtimeBaseRef:1582805677641432568 realtimeFrequency:2299774552} D0227 12:14:38.642049 6245 parameters.go:238] Clock(Monotonic): error: -810 ns, adjusted frequency from 2299776378 Hz to 2299772718 Hz D0227 12:14:38.642305 6245 parameters.go:238] Clock(Realtime): error: 59 ns, adjusted frequency from 2299774552 Hz to 2299774686 Hz D0227 12:14:38.642434 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503695867073223 monotonicBaseRef:33001230283 monotonicFrequency:2299772718 realtimeReady:1 realtimeBaseCycles:8503695867710429 realtimeBaseRef:1582805678642298622 realtimeFrequency:2299774686} D0227 12:14:39.643746 6245 parameters.go:238] Clock(Monotonic): error: 5 ns, adjusted frequency from 2299772718 Hz to 2299774540 Hz D0227 12:14:39.643986 6245 parameters.go:238] Clock(Realtime): error: -86 ns, adjusted frequency from 2299774686 Hz to 2299774378 Hz D0227 12:14:39.644102 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503698170762697 monotonicBaseRef:34002933388 monotonicFrequency:2299774540 realtimeReady:1 realtimeBaseCycles:8503698171352635 realtimeBaseRef:1582805679643980317 realtimeFrequency:2299774378} D0227 12:14:40.643182 6245 parameters.go:238] Clock(Monotonic): error: 141 ns, adjusted frequency from 2299774540 Hz to 2299774833 Hz D0227 12:14:40.643424 6245 parameters.go:238] Clock(Realtime): error: 11 ns, adjusted frequency from 2299774378 Hz to 2299774549 Hz D0227 12:14:40.643534 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503700469221907 monotonicBaseRef:35002361449 monotonicFrequency:2299774833 realtimeReady:1 realtimeBaseCycles:8503700469835345 realtimeBaseRef:1582805680643418667 realtimeFrequency:2299774549} D0227 12:14:41.641074 6245 parameters.go:238] Clock(Monotonic): error: 27 ns, adjusted frequency from 2299774833 Hz to 2299774582 Hz D0227 12:14:41.641281 6245 parameters.go:238] Clock(Realtime): error: 8 ns, adjusted frequency from 2299774549 Hz to 2299774570 Hz D0227 12:14:41.641416 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503702764168321 monotonicBaseRef:36000261930 monotonicFrequency:2299774582 realtimeReady:1 realtimeBaseCycles:8503702764678654 realtimeBaseRef:1582805681641274439 realtimeFrequency:2299774570} D0227 12:14:42.034823 6245 urpc.go:577] urpc: unmarshal success. D0227 12:14:42.035047 6245 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-0 Signo:0 PID:0 Mode:Process} D0227 12:14:42.035262 6245 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 12:14:42.641894 6245 parameters.go:238] Clock(Monotonic): error: 89 ns, adjusted frequency from 2299774582 Hz to 2299774729 Hz D0227 12:14:42.642125 6245 parameters.go:238] Clock(Realtime): error: 740 ns, adjusted frequency from 2299774570 Hz to 2299776351 Hz D0227 12:14:42.642238 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503705065838444 monotonicBaseRef:37001086159 monotonicFrequency:2299774729 realtimeReady:1 realtimeBaseCycles:8503705066395084 realtimeBaseRef:1582805682642118808 realtimeFrequency:2299776351} D0227 12:14:43.641103 6245 parameters.go:238] Clock(Monotonic): error: -168 ns, adjusted frequency from 2299774729 Hz to 2299774284 Hz D0227 12:14:43.641315 6245 parameters.go:238] Clock(Realtime): error: -796 ns, adjusted frequency from 2299776351 Hz to 2299772718 Hz D0227 12:14:43.641427 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503707363801640 monotonicBaseRef:38000298458 monotonicFrequency:2299774284 realtimeReady:1 realtimeBaseCycles:8503707364307298 realtimeBaseRef:1582805683641308234 realtimeFrequency:2299772718} D0227 12:14:44.642642 6245 parameters.go:238] Clock(Monotonic): error: 148 ns, adjusted frequency from 2299774284 Hz to 2299774970 Hz D0227 12:14:44.642815 6245 parameters.go:238] Clock(Realtime): error: -35 ns, adjusted frequency from 2299772718 Hz to 2299774438 Hz D0227 12:14:44.642930 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503709667112062 monotonicBaseRef:39001836060 monotonicFrequency:2299774970 realtimeReady:1 realtimeBaseCycles:8503709667534471 realtimeBaseRef:1582805684642810319 realtimeFrequency:2299774438} D0227 12:14:45.642815 6245 parameters.go:238] Clock(Monotonic): error: 19 ns, adjusted frequency from 2299774970 Hz to 2299774560 Hz D0227 12:14:45.643012 6245 parameters.go:238] Clock(Realtime): error: 5 ns, adjusted frequency from 2299774438 Hz to 2299774588 Hz D0227 12:14:45.643122 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503711967287408 monotonicBaseRef:40002010153 monotonicFrequency:2299774560 realtimeReady:1 realtimeBaseCycles:8503711967762001 realtimeBaseRef:1582805685643007334 realtimeFrequency:2299774588} D0227 12:14:46.642273 6245 parameters.go:238] Clock(Monotonic): error: -109 ns, adjusted frequency from 2299774560 Hz to 2299774195 Hz D0227 12:14:46.642465 6245 parameters.go:238] Clock(Realtime): error: 26 ns, adjusted frequency from 2299774588 Hz to 2299774628 Hz D0227 12:14:46.642577 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503714265812250 monotonicBaseRef:41001466744 monotonicFrequency:2299774195 realtimeReady:1 realtimeBaseCycles:8503714266276763 realtimeBaseRef:1582805686642459529 realtimeFrequency:2299774628} D0227 12:14:47.641107 6245 parameters.go:238] Clock(Monotonic): error: 88 ns, adjusted frequency from 2299774195 Hz to 2299774710 Hz D0227 12:14:47.641265 6245 parameters.go:238] Clock(Realtime): error: 56 ns, adjusted frequency from 2299774628 Hz to 2299774716 Hz D0227 12:14:47.641385 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503716562904408 monotonicBaseRef:42000300526 monotonicFrequency:2299774710 realtimeReady:1 realtimeBaseCycles:8503716563292969 realtimeBaseRef:1582805687641260097 realtimeFrequency:2299774716} D0227 12:14:48.641882 6245 parameters.go:238] Clock(Monotonic): error: 94 ns, adjusted frequency from 2299774710 Hz to 2299774856 Hz D0227 12:14:48.642089 6245 parameters.go:238] Clock(Realtime): error: -80 ns, adjusted frequency from 2299774716 Hz to 2299774336 Hz D0227 12:14:48.642195 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503718864437716 monotonicBaseRef:43001065208 monotonicFrequency:2299774856 realtimeReady:1 realtimeBaseCycles:8503718864960128 realtimeBaseRef:1582805688642082978 realtimeFrequency:2299774336} D0227 12:14:49.642376 6245 parameters.go:238] Clock(Monotonic): error: -69 ns, adjusted frequency from 2299774856 Hz to 2299774507 Hz D0227 12:14:49.642554 6245 parameters.go:238] Clock(Realtime): error: 160 ns, adjusted frequency from 2299774336 Hz to 2299774913 Hz D0227 12:14:49.642687 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503721165330463 monotonicBaseRef:44001551295 monotonicFrequency:2299774507 realtimeReady:1 realtimeBaseCycles:8503721165804468 realtimeBaseRef:1582805689642548242 realtimeFrequency:2299774913} D0227 12:14:50.642537 6245 parameters.go:238] Clock(Monotonic): error: -404 ns, adjusted frequency from 2299774507 Hz to 2299773672 Hz D0227 12:14:50.642713 6245 parameters.go:238] Clock(Realtime): error: -116 ns, adjusted frequency from 2299774913 Hz to 2299774292 Hz D0227 12:14:50.642848 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503723465520374 monotonicBaseRef:45001731923 monotonicFrequency:2299773672 realtimeReady:1 realtimeBaseCycles:8503723465924440 realtimeBaseRef:1582805690642698282 realtimeFrequency:2299774292} I0227 12:14:50.848121 6245 watchdog.go:277] Watchdog starting loop, tasks: 13, discount: 0s D0227 12:14:51.641712 6245 parameters.go:238] Clock(Monotonic): error: -58 ns, adjusted frequency from 2299773672 Hz to 2299774453 Hz D0227 12:14:51.641875 6245 parameters.go:238] Clock(Realtime): error: 53 ns, adjusted frequency from 2299774292 Hz to 2299774594 Hz D0227 12:14:51.641987 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503725763321468 monotonicBaseRef:46000874195 monotonicFrequency:2299774453 realtimeReady:1 realtimeBaseCycles:8503725763790704 realtimeBaseRef:1582805691641868623 realtimeFrequency:2299774594} D0227 12:14:52.641631 6245 parameters.go:238] Clock(Monotonic): error: -2 ns, adjusted frequency from 2299774453 Hz to 2299774532 Hz D0227 12:14:52.641859 6245 parameters.go:238] Clock(Realtime): error: 47 ns, adjusted frequency from 2299774594 Hz to 2299774648 Hz D0227 12:14:52.641988 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503728062978210 monotonicBaseRef:47000823011 monotonicFrequency:2299774532 realtimeReady:1 realtimeBaseCycles:8503728063529340 realtimeBaseRef:1582805692641852987 realtimeFrequency:2299774648} D0227 12:14:53.641890 6245 sampler.go:197] Time: Adjusting syscall overhead down to 7000 D0227 12:14:53.642024 6245 parameters.go:238] Clock(Monotonic): error: 61 ns, adjusted frequency from 2299774532 Hz to 2299774742 Hz D0227 12:14:53.642158 6245 parameters.go:238] Clock(Realtime): error: -112 ns, adjusted frequency from 2299774648 Hz to 2299774307 Hz D0227 12:14:53.642262 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503730363334020 monotonicBaseRef:48001075765 monotonicFrequency:2299774742 realtimeReady:1 realtimeBaseCycles:8503730363994087 realtimeBaseRef:1582805693642153059 realtimeFrequency:2299774307} D0227 12:14:54.642112 6245 parameters.go:238] Clock(Monotonic): error: 197 ns, adjusted frequency from 2299774742 Hz to 2299775075 Hz D0227 12:14:54.642326 6245 parameters.go:238] Clock(Realtime): error: 295 ns, adjusted frequency from 2299774307 Hz to 2299775203 Hz D0227 12:14:54.642513 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503732663624994 monotonicBaseRef:49001300235 monotonicFrequency:2299775075 realtimeReady:1 realtimeBaseCycles:8503732664147303 realtimeBaseRef:1582805694642317818 realtimeFrequency:2299775203} D0227 12:14:55.642739 6245 parameters.go:238] Clock(Monotonic): error: -244 ns, adjusted frequency from 2299775075 Hz to 2299774053 Hz D0227 12:14:55.642952 6245 parameters.go:238] Clock(Realtime): error: -170 ns, adjusted frequency from 2299775203 Hz to 2299774165 Hz D0227 12:14:55.643051 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503734964852487 monotonicBaseRef:50001931782 monotonicFrequency:2299774053 realtimeReady:1 realtimeBaseCycles:8503734965368161 realtimeBaseRef:1582805695642946425 realtimeFrequency:2299774165} D0227 12:14:56.641082 6245 parameters.go:238] Clock(Monotonic): error: 174 ns, adjusted frequency from 2299774053 Hz to 2299775022 Hz D0227 12:14:56.641290 6245 parameters.go:238] Clock(Realtime): error: 23 ns, adjusted frequency from 2299774165 Hz to 2299774581 Hz D0227 12:14:56.641403 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503737260819018 monotonicBaseRef:51000276175 monotonicFrequency:2299775022 realtimeReady:1 realtimeBaseCycles:8503737261318852 realtimeBaseRef:1582805696641283881 realtimeFrequency:2299774581} D0227 12:14:57.641161 6245 parameters.go:238] Clock(Monotonic): error: -255 ns, adjusted frequency from 2299775022 Hz to 2299774014 Hz D0227 12:14:57.641369 6245 parameters.go:238] Clock(Realtime): error: -4 ns, adjusted frequency from 2299774581 Hz to 2299774551 Hz D0227 12:14:57.641495 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503739560728295 monotonicBaseRef:52000334552 monotonicFrequency:2299774014 realtimeReady:1 realtimeBaseCycles:8503739561274682 realtimeBaseRef:1582805697641362692 realtimeFrequency:2299774551} D0227 12:14:58.641187 6245 parameters.go:238] Clock(Monotonic): error: 46 ns, adjusted frequency from 2299774014 Hz to 2299774717 Hz D0227 12:14:58.641356 6245 parameters.go:238] Clock(Realtime): error: 53 ns, adjusted frequency from 2299774551 Hz to 2299774748 Hz D0227 12:14:58.641462 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503741860598981 monotonicBaseRef:53000376587 monotonicFrequency:2299774717 realtimeReady:1 realtimeBaseCycles:8503741861020670 realtimeBaseRef:1582805698641350272 realtimeFrequency:2299774748} D0227 12:14:59.641535 6245 parameters.go:238] Clock(Monotonic): error: -10 ns, adjusted frequency from 2299774717 Hz to 2299774539 Hz D0227 12:14:59.641725 6245 parameters.go:238] Clock(Realtime): error: -25 ns, adjusted frequency from 2299774748 Hz to 2299774503 Hz D0227 12:14:59.641875 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503744161150954 monotonicBaseRef:54000714557 monotonicFrequency:2299774539 realtimeReady:1 realtimeBaseCycles:8503744161642135 realtimeBaseRef:1582805699641718445 realtimeFrequency:2299774503} D0227 12:15:00.641287 6245 parameters.go:238] Clock(Monotonic): error: -121 ns, adjusted frequency from 2299774539 Hz to 2299774286 Hz D0227 12:15:00.641487 6245 parameters.go:238] Clock(Realtime): error: -15 ns, adjusted frequency from 2299774503 Hz to 2299774544 Hz D0227 12:15:00.641616 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503746460389818 monotonicBaseRef:55000481631 monotonicFrequency:2299774286 realtimeReady:1 realtimeBaseCycles:8503746460870087 realtimeBaseRef:1582805700641480790 realtimeFrequency:2299774544} D0227 12:15:01.641232 6245 parameters.go:238] Clock(Monotonic): error: 85 ns, adjusted frequency from 2299774286 Hz to 2299774777 Hz D0227 12:15:01.641416 6245 parameters.go:238] Clock(Realtime): error: -84 ns, adjusted frequency from 2299774544 Hz to 2299774385 Hz D0227 12:15:01.641552 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503748759970862 monotonicBaseRef:56000397604 monotonicFrequency:2299774777 realtimeReady:1 realtimeBaseCycles:8503748760473100 realtimeBaseRef:1582805701641406203 realtimeFrequency:2299774385} D0227 12:15:02.643469 6245 parameters.go:238] Clock(Monotonic): error: -22 ns, adjusted frequency from 2299774777 Hz to 2299774512 Hz D0227 12:15:02.643629 6245 parameters.go:238] Clock(Realtime): error: -15 ns, adjusted frequency from 2299774385 Hz to 2299774467 Hz D0227 12:15:02.643739 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503751064922396 monotonicBaseRef:57002648588 monotonicFrequency:2299774512 realtimeReady:1 realtimeBaseCycles:8503751065348655 realtimeBaseRef:1582805702643624320 realtimeFrequency:2299774467} D0227 12:15:03.642725 6245 parameters.go:238] Clock(Monotonic): error: 295 ns, adjusted frequency from 2299774512 Hz to 2299775184 Hz D0227 12:15:03.642878 6245 parameters.go:238] Clock(Realtime): error: -16 ns, adjusted frequency from 2299774467 Hz to 2299774564 Hz D0227 12:15:03.643005 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503753362993971 monotonicBaseRef:58001908108 monotonicFrequency:2299775184 realtimeReady:1 realtimeBaseCycles:8503753363395562 realtimeBaseRef:1582805703642873133 realtimeFrequency:2299774564} D0227 12:15:04.641533 6245 parameters.go:238] Clock(Monotonic): error: -56 ns, adjusted frequency from 2299775184 Hz to 2299774389 Hz D0227 12:15:04.641706 6245 parameters.go:238] Clock(Realtime): error: 19 ns, adjusted frequency from 2299774564 Hz to 2299774623 Hz D0227 12:15:04.641800 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503755660056335 monotonicBaseRef:59000728505 monotonicFrequency:2299774389 realtimeReady:1 realtimeBaseCycles:8503755660473827 realtimeBaseRef:1582805704641700714 realtimeFrequency:2299774623} D0227 12:15:05.643972 6245 parameters.go:238] Clock(Monotonic): error: 148 ns, adjusted frequency from 2299774389 Hz to 2299774835 Hz D0227 12:15:05.644165 6245 parameters.go:238] Clock(Realtime): error: -25 ns, adjusted frequency from 2299774623 Hz to 2299774531 Hz D0227 12:15:05.644271 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503757965432005 monotonicBaseRef:60003164083 monotonicFrequency:2299774835 realtimeReady:1 realtimeBaseCycles:8503757965904117 realtimeBaseRef:1582805705644159940 realtimeFrequency:2299774531} D0227 12:15:06.641123 6245 parameters.go:238] Clock(Monotonic): error: -212 ns, adjusted frequency from 2299774835 Hz to 2299774092 Hz D0227 12:15:06.641404 6245 parameters.go:238] Clock(Realtime): error: -191 ns, adjusted frequency from 2299774531 Hz to 2299774206 Hz D0227 12:15:06.641520 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503760258636236 monotonicBaseRef:61000307018 monotonicFrequency:2299774092 realtimeReady:1 realtimeBaseCycles:8503760259326623 realtimeBaseRef:1582805706641397919 realtimeFrequency:2299774206} D0227 12:15:07.642183 6245 parameters.go:238] Clock(Monotonic): error: -159 ns, adjusted frequency from 2299774092 Hz to 2299774189 Hz D0227 12:15:07.642361 6245 parameters.go:238] Clock(Realtime): error: 5 ns, adjusted frequency from 2299774206 Hz to 2299774554 Hz D0227 12:15:07.642474 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503762560875349 monotonicBaseRef:62001378871 monotonicFrequency:2299774189 realtimeReady:1 realtimeBaseCycles:8503762561307435 realtimeBaseRef:1582805707642357407 realtimeFrequency:2299774554} D0227 12:15:08.642757 6245 parameters.go:238] Clock(Monotonic): error: 354 ns, adjusted frequency from 2299774189 Hz to 2299775321 Hz D0227 12:15:08.643024 6245 parameters.go:238] Clock(Realtime): error: 253 ns, adjusted frequency from 2299774554 Hz to 2299775108 Hz D0227 12:15:08.643150 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503764861962572 monotonicBaseRef:63001949811 monotonicFrequency:2299775321 realtimeReady:1 realtimeBaseCycles:8503764862602133 realtimeBaseRef:1582805708643018403 realtimeFrequency:2299775108} D0227 12:15:09.643584 6245 parameters.go:238] Clock(Monotonic): error: -272 ns, adjusted frequency from 2299775321 Hz to 2299773945 Hz D0227 12:15:09.643831 6245 parameters.go:238] Clock(Realtime): error: -21 ns, adjusted frequency from 2299775108 Hz to 2299774487 Hz D0227 12:15:09.643976 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503767163638708 monotonicBaseRef:64002776333 monotonicFrequency:2299773945 realtimeReady:1 realtimeBaseCycles:8503767164233731 realtimeBaseRef:1582805709643825651 realtimeFrequency:2299774487} D0227 12:15:10.644133 6245 parameters.go:238] Clock(Monotonic): error: 32 ns, adjusted frequency from 2299773945 Hz to 2299774634 Hz D0227 12:15:10.644336 6245 parameters.go:238] Clock(Realtime): error: -55 ns, adjusted frequency from 2299774487 Hz to 2299774472 Hz D0227 12:15:10.644479 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503769464669998 monotonicBaseRef:65003323058 monotonicFrequency:2299774634 realtimeReady:1 realtimeBaseCycles:8503769465170762 realtimeBaseRef:1582805710644331154 realtimeFrequency:2299774472} D0227 12:15:11.641776 6245 parameters.go:238] Clock(Monotonic): error: -40 ns, adjusted frequency from 2299774634 Hz to 2299774472 Hz D0227 12:15:11.642103 6245 parameters.go:238] Clock(Realtime): error: 261 ns, adjusted frequency from 2299774472 Hz to 2299775197 Hz D0227 12:15:11.642199 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503771758984608 monotonicBaseRef:66000948901 monotonicFrequency:2299774472 realtimeReady:1 realtimeBaseCycles:8503771759802530 realtimeBaseRef:1582805711642094976 realtimeFrequency:2299775197} D0227 12:15:12.642095 6245 parameters.go:238] Clock(Monotonic): error: 151 ns, adjusted frequency from 2299774472 Hz to 2299774937 Hz D0227 12:15:12.642410 6245 parameters.go:238] Clock(Realtime): error: 198 ns, adjusted frequency from 2299775197 Hz to 2299775031 Hz D0227 12:15:12.642593 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503774059525151 monotonicBaseRef:67001282008 monotonicFrequency:2299774937 realtimeReady:1 realtimeBaseCycles:8503774060287009 realtimeBaseRef:1582805712642403389 realtimeFrequency:2299775031} D0227 12:15:13.643480 6245 parameters.go:238] Clock(Monotonic): error: 289 ns, adjusted frequency from 2299774937 Hz to 2299775215 Hz D0227 12:15:13.643722 6245 parameters.go:238] Clock(Realtime): error: -361 ns, adjusted frequency from 2299775031 Hz to 2299773692 Hz D0227 12:15:13.643850 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503776362494264 monotonicBaseRef:68002670916 monotonicFrequency:2299775215 realtimeReady:1 realtimeBaseCycles:8503776363077935 realtimeBaseRef:1582805713643714775 realtimeFrequency:2299773692} D0227 12:15:14.642305 6245 parameters.go:238] Clock(Monotonic): error: -139 ns, adjusted frequency from 2299775215 Hz to 2299774227 Hz D0227 12:15:14.642501 6245 parameters.go:238] Clock(Realtime): error: -138 ns, adjusted frequency from 2299773692 Hz to 2299774232 Hz D0227 12:15:14.642592 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503778659577067 monotonicBaseRef:69001500187 monotonicFrequency:2299774227 realtimeReady:1 realtimeBaseCycles:8503778660048318 realtimeBaseRef:1582805714642495825 realtimeFrequency:2299774232} D0227 12:15:15.226087 6245 urpc.go:577] urpc: unmarshal success. D0227 12:15:15.226306 6245 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-0 Signo:0 PID:0 Mode:Process} D0227 12:15:15.226645 6245 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 12:15:15.642462 6245 parameters.go:238] Clock(Monotonic): error: 116 ns, adjusted frequency from 2299774227 Hz to 2299774780 Hz D0227 12:15:15.642764 6245 parameters.go:238] Clock(Realtime): error: 365 ns, adjusted frequency from 2299774232 Hz to 2299775324 Hz D0227 12:15:15.642878 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503780959706592 monotonicBaseRef:70001654679 monotonicFrequency:2299774780 realtimeReady:1 realtimeBaseCycles:8503780960421675 realtimeBaseRef:1582805715642756339 realtimeFrequency:2299775324} D0227 12:15:16.643374 6245 parameters.go:238] Clock(Monotonic): error: -419 ns, adjusted frequency from 2299774780 Hz to 2299773598 Hz D0227 12:15:16.643606 6245 parameters.go:238] Clock(Realtime): error: -285 ns, adjusted frequency from 2299775324 Hz to 2299773902 Hz D0227 12:15:16.643721 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503783261573379 monotonicBaseRef:71002564336 monotonicFrequency:2299773598 realtimeReady:1 realtimeBaseCycles:8503783262137792 realtimeBaseRef:1582805716643600244 realtimeFrequency:2299773902} D0227 12:15:17.641245 6245 parameters.go:238] Clock(Monotonic): error: 14 ns, adjusted frequency from 2299773598 Hz to 2299774651 Hz D0227 12:15:17.641433 6245 parameters.go:238] Clock(Realtime): error: -5 ns, adjusted frequency from 2299773902 Hz to 2299774543 Hz D0227 12:15:17.641596 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503785556440443 monotonicBaseRef:72000430850 monotonicFrequency:2299774651 realtimeReady:1 realtimeBaseCycles:8503785556913799 realtimeBaseRef:1582805717641427032 realtimeFrequency:2299774543} D0227 12:15:18.641121 6245 parameters.go:238] Clock(Monotonic): error: 28 ns, adjusted frequency from 2299774651 Hz to 2299774632 Hz D0227 12:15:18.641367 6245 parameters.go:238] Clock(Realtime): error: 50 ns, adjusted frequency from 2299774543 Hz to 2299774691 Hz D0227 12:15:18.641488 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503787855938299 monotonicBaseRef:73000310492 monotonicFrequency:2299774632 realtimeReady:1 realtimeBaseCycles:8503787856534442 realtimeBaseRef:1582805718641360112 realtimeFrequency:2299774691} D0227 12:15:19.641324 6245 parameters.go:238] Clock(Monotonic): error: -9 ns, adjusted frequency from 2299774632 Hz to 2299774546 Hz D0227 12:15:19.641548 6245 parameters.go:238] Clock(Realtime): error: 45 ns, adjusted frequency from 2299774691 Hz to 2299774642 Hz D0227 12:15:19.641671 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503790156183777 monotonicBaseRef:74000515227 monotonicFrequency:2299774546 realtimeReady:1 realtimeBaseCycles:8503790156727897 realtimeBaseRef:1582805719641542201 realtimeFrequency:2299774642} D0227 12:15:20.641284 6245 parameters.go:238] Clock(Monotonic): error: -9 ns, adjusted frequency from 2299774546 Hz to 2299774545 Hz D0227 12:15:20.641506 6245 parameters.go:238] Clock(Realtime): error: -140 ns, adjusted frequency from 2299774642 Hz to 2299774270 Hz D0227 12:15:20.641603 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503792455867827 monotonicBaseRef:75000475877 monotonicFrequency:2299774545 realtimeReady:1 realtimeBaseCycles:8503792456405917 realtimeBaseRef:1582805720641500187 realtimeFrequency:2299774270} D0227 12:15:21.643225 6245 parameters.go:238] Clock(Monotonic): error: 202 ns, adjusted frequency from 2299774545 Hz to 2299775051 Hz D0227 12:15:21.643447 6245 parameters.go:238] Clock(Realtime): error: 1 ns, adjusted frequency from 2299774270 Hz to 2299774560 Hz D0227 12:15:21.643550 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503794760047237 monotonicBaseRef:76002391223 monotonicFrequency:2299775051 realtimeReady:1 realtimeBaseCycles:8503794760643263 realtimeBaseRef:1582805721643440845 realtimeFrequency:2299774560} D0227 12:15:22.643472 6245 parameters.go:238] Clock(Monotonic): error: -173 ns, adjusted frequency from 2299775051 Hz to 2299774240 Hz D0227 12:15:22.644188 6245 parameters.go:238] Clock(Realtime): error: 148 ns, adjusted frequency from 2299774560 Hz to 2299774887 Hz D0227 12:15:22.644328 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503797060437992 monotonicBaseRef:77002658946 monotonicFrequency:2299774240 realtimeReady:1 realtimeBaseCycles:8503797062109691 realtimeBaseRef:1582805722644176511 realtimeFrequency:2299774887} D0227 12:15:23.641108 6245 parameters.go:238] Clock(Monotonic): error: -107 ns, adjusted frequency from 2299774240 Hz to 2299774392 Hz D0227 12:15:23.641309 6245 parameters.go:238] Clock(Realtime): error: -99 ns, adjusted frequency from 2299774887 Hz to 2299774330 Hz D0227 12:15:23.641446 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503799354772676 monotonicBaseRef:78000293689 monotonicFrequency:2299774392 realtimeReady:1 realtimeBaseCycles:8503799355277137 realtimeBaseRef:1582805723641303429 realtimeFrequency:2299774330} D0227 12:15:24.641119 6245 parameters.go:238] Clock(Monotonic): error: -42 ns, adjusted frequency from 2299774392 Hz to 2299774502 Hz D0227 12:15:24.641327 6245 parameters.go:238] Clock(Realtime): error: 25 ns, adjusted frequency from 2299774330 Hz to 2299774652 Hz D0227 12:15:24.641444 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503801654578769 monotonicBaseRef:79000307473 monotonicFrequency:2299774502 realtimeReady:1 realtimeBaseCycles:8503801655094698 realtimeBaseRef:1582805724641322226 realtimeFrequency:2299774652} D0227 12:15:25.641107 6245 parameters.go:238] Clock(Monotonic): error: 18 ns, adjusted frequency from 2299774502 Hz to 2299774615 Hz D0227 12:15:25.641367 6245 parameters.go:238] Clock(Realtime): error: 30 ns, adjusted frequency from 2299774652 Hz to 2299774597 Hz D0227 12:15:25.641487 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503803954289294 monotonicBaseRef:80000279654 monotonicFrequency:2299774615 realtimeReady:1 realtimeBaseCycles:8503803954958931 realtimeBaseRef:1582805725641361178 realtimeFrequency:2299774597} D0227 12:15:26.642576 6245 parameters.go:238] Clock(Monotonic): error: -23 ns, adjusted frequency from 2299774615 Hz to 2299774513 Hz D0227 12:15:26.642777 6245 parameters.go:238] Clock(Realtime): error: -106 ns, adjusted frequency from 2299774597 Hz to 2299774367 Hz D0227 12:15:26.642922 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503806257480794 monotonicBaseRef:81001765401 monotonicFrequency:2299774513 realtimeReady:1 realtimeBaseCycles:8503806257977162 realtimeBaseRef:1582805726642771591 realtimeFrequency:2299774367} D0227 12:15:27.641383 6245 parameters.go:238] Clock(Monotonic): error: 111 ns, adjusted frequency from 2299774513 Hz to 2299774808 Hz D0227 12:15:27.641597 6245 parameters.go:238] Clock(Realtime): error: 38 ns, adjusted frequency from 2299774367 Hz to 2299774676 Hz D0227 12:15:27.641735 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503808554509527 monotonicBaseRef:82000571466 monotonicFrequency:2299774808 realtimeReady:1 realtimeBaseCycles:8503808555038841 realtimeBaseRef:1582805727641592045 realtimeFrequency:2299774676} D0227 12:15:28.641039 6245 parameters.go:238] Clock(Monotonic): error: -85 ns, adjusted frequency from 2299774808 Hz to 2299774367 Hz D0227 12:15:28.641256 6245 parameters.go:238] Clock(Realtime): error: 14 ns, adjusted frequency from 2299774676 Hz to 2299774594 Hz D0227 12:15:28.641903 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503810853495637 monotonicBaseRef:83000228520 monotonicFrequency:2299774367 realtimeReady:1 realtimeBaseCycles:8503810853992105 realtimeBaseRef:1582805728641234874 realtimeFrequency:2299774594} D0227 12:15:29.642147 6245 parameters.go:238] Clock(Monotonic): error: -26 ns, adjusted frequency from 2299774367 Hz to 2299774497 Hz D0227 12:15:29.642350 6245 parameters.go:238] Clock(Realtime): error: -252 ns, adjusted frequency from 2299774594 Hz to 2299774019 Hz D0227 12:15:29.642473 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503813155825509 monotonicBaseRef:84001339718 monotonicFrequency:2299774497 realtimeReady:1 realtimeBaseCycles:8503813156318249 realtimeBaseRef:1582805729642344352 realtimeFrequency:2299774019} D0227 12:15:30.641197 6245 parameters.go:238] Clock(Monotonic): error: 81 ns, adjusted frequency from 2299774497 Hz to 2299774744 Hz D0227 12:15:30.641448 6245 parameters.go:238] Clock(Realtime): error: -24 ns, adjusted frequency from 2299774019 Hz to 2299774552 Hz D0227 12:15:30.641560 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503815453380726 monotonicBaseRef:85000374719 monotonicFrequency:2299774744 realtimeReady:1 realtimeBaseCycles:8503815454016517 realtimeBaseRef:1582805730641441762 realtimeFrequency:2299774552} D0227 12:15:31.641700 6245 parameters.go:238] Clock(Monotonic): error: 315 ns, adjusted frequency from 2299774744 Hz to 2299775196 Hz D0227 12:15:31.641918 6245 parameters.go:238] Clock(Realtime): error: 296 ns, adjusted frequency from 2299774552 Hz to 2299775301 Hz D0227 12:15:31.642043 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503817754205660 monotonicBaseRef:86000831368 monotonicFrequency:2299775196 realtimeReady:1 realtimeBaseCycles:8503817754872275 realtimeBaseRef:1582805731641911897 realtimeFrequency:2299775301} D0227 12:15:32.641061 6245 parameters.go:238] Clock(Monotonic): error: -306 ns, adjusted frequency from 2299775196 Hz to 2299773860 Hz D0227 12:15:32.641290 6245 parameters.go:238] Clock(Realtime): error: 15 ns, adjusted frequency from 2299775301 Hz to 2299774552 Hz D0227 12:15:32.641443 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503820052640636 monotonicBaseRef:87000248606 monotonicFrequency:2299773860 realtimeReady:1 realtimeBaseCycles:8503820053204800 realtimeBaseRef:1582805732641284541 realtimeFrequency:2299774552} D0227 12:15:33.641329 6245 parameters.go:238] Clock(Monotonic): error: 295 ns, adjusted frequency from 2299773860 Hz to 2299775178 Hz D0227 12:15:33.641531 6245 parameters.go:238] Clock(Realtime): error: -12 ns, adjusted frequency from 2299774552 Hz to 2299774511 Hz D0227 12:15:33.641646 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503822353016835 monotonicBaseRef:88000510518 monotonicFrequency:2299775178 realtimeReady:1 realtimeBaseCycles:8503822353531497 realtimeBaseRef:1582805733641524627 realtimeFrequency:2299774511} D0227 12:15:34.641557 6245 parameters.go:238] Clock(Monotonic): error: -180 ns, adjusted frequency from 2299775178 Hz to 2299774150 Hz D0227 12:15:34.641761 6245 parameters.go:238] Clock(Realtime): error: -98 ns, adjusted frequency from 2299774511 Hz to 2299774343 Hz D0227 12:15:34.641868 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503824653335538 monotonicBaseRef:89000746856 monotonicFrequency:2299774150 realtimeReady:1 realtimeBaseCycles:8503824653834757 realtimeBaseRef:1582805734641754540 realtimeFrequency:2299774343} D0227 12:15:35.642556 6245 parameters.go:238] Clock(Monotonic): error: -92 ns, adjusted frequency from 2299774150 Hz to 2299774327 Hz D0227 12:15:35.643402 6245 parameters.go:238] Clock(Realtime): error: -147 ns, adjusted frequency from 2299774343 Hz to 2299774268 Hz D0227 12:15:35.643547 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503826955387075 monotonicBaseRef:90001737121 monotonicFrequency:2299774327 realtimeReady:1 realtimeBaseCycles:8503826957381883 realtimeBaseRef:1582805735643395041 realtimeFrequency:2299774268} I0227 12:15:35.850000 6245 watchdog.go:277] Watchdog starting loop, tasks: 13, discount: 0s D0227 12:15:36.641649 6245 parameters.go:238] Clock(Monotonic): error: 181 ns, adjusted frequency from 2299774327 Hz to 2299775003 Hz D0227 12:15:36.641921 6245 parameters.go:238] Clock(Realtime): error: 64 ns, adjusted frequency from 2299774268 Hz to 2299774741 Hz D0227 12:15:36.642085 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503829253099294 monotonicBaseRef:91000840464 monotonicFrequency:2299775003 realtimeReady:1 realtimeBaseCycles:8503829253748927 realtimeBaseRef:1582805736641913493 realtimeFrequency:2299774741} D0227 12:15:37.641133 6245 parameters.go:238] Clock(Monotonic): error: 197 ns, adjusted frequency from 2299775003 Hz to 2299774992 Hz D0227 12:15:37.641343 6245 parameters.go:238] Clock(Realtime): error: 153 ns, adjusted frequency from 2299774741 Hz to 2299774927 Hz D0227 12:15:37.641435 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503831551691565 monotonicBaseRef:92000326182 monotonicFrequency:2299774992 realtimeReady:1 realtimeBaseCycles:8503831552198467 realtimeBaseRef:1582805737641337262 realtimeFrequency:2299774927} D0227 12:15:37.687985 6245 urpc.go:577] urpc: unmarshal success. D0227 12:15:37.688287 6245 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-0 Signo:0 PID:0 Mode:Process} D0227 12:15:37.688568 6245 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 12:15:38.641164 6245 parameters.go:238] Clock(Monotonic): error: -386 ns, adjusted frequency from 2299774992 Hz to 2299773673 Hz D0227 12:15:38.641425 6245 parameters.go:238] Clock(Realtime): error: -269 ns, adjusted frequency from 2299774927 Hz to 2299773951 Hz D0227 12:15:38.641534 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503833851534881 monotonicBaseRef:93000355890 monotonicFrequency:2299773673 realtimeReady:1 realtimeBaseCycles:8503833852159748 realtimeBaseRef:1582805738641418293 realtimeFrequency:2299773951} I0227 12:15:39.147425 16123 main.go:296] *************************** I0227 12:15:39.147598 16123 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-0 /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 /syzkaller925062890] I0227 12:15:39.148056 16123 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 12:15:39.148125 16123 main.go:299] PID: 16123 I0227 12:15:39.148221 16123 main.go:300] UID: 0, GID: 0 I0227 12:15:39.148322 16123 main.go:301] Configuration: I0227 12:15:39.148409 16123 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 12:15:39.148522 16123 main.go:303] Platform: ptrace I0227 12:15:39.148631 16123 main.go:304] FileAccess: shared, overlay: false I0227 12:15:39.148741 16123 main.go:305] Network: sandbox, logging: false I0227 12:15:39.148854 16123 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 12:15:39.148975 16123 main.go:307] *************************** W0227 12:15:39.149076 16123 main.go:312] Block the TERM signal. This is only safe in tests! D0227 12:15:39.149494 16123 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.156663 16123 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-0": signal 0 D0227 12:15:39.156883 16123 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.157010 16123 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.157639 16123 urpc.go:534] urpc: successfully marshalled 117 bytes. D0227 12:15:39.158849 6245 urpc.go:577] urpc: unmarshal success. D0227 12:15:39.159102 6245 controller.go:501] containerManager.Signal &{CID:ci-gvisor-ptrace-proxy-sandbox-race-0 Signo:0 PID:0 Mode:Process} D0227 12:15:39.159324 6245 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 12:15:39.159554 16123 urpc.go:577] urpc: unmarshal success. D0227 12:15:39.159826 16123 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 /syzkaller925062890 D0227 12:15:39.160037 16123 exec.go:121] Exec capablities: &{PermittedCaps:274877898751 InheritableCaps:274877898751 EffectiveCaps:274877898751 BoundingCaps:274877898751 AmbientCaps:0} D0227 12:15:39.160204 16123 container.go:532] Execute in container "ci-gvisor-ptrace-proxy-sandbox-race-0", 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 /syzkaller925062890 D0227 12:15:39.160340 16123 sandbox.go:283] Executing new process in container "ci-gvisor-ptrace-proxy-sandbox-race-0" in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.160492 16123 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.161485 16123 urpc.go:534] urpc: successfully marshalled 634 bytes. D0227 12:15:39.161997 6245 urpc.go:577] urpc: unmarshal success. D0227 12:15:39.163221 6245 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 /syzkaller925062890 D0227 12:15:39.163471 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [etc]} D0227 12:15:39.165109 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:39.165266 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 12:15:39.165831 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} I0227 12:15:39.166401 6245 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 /syzkaller925062890] D0227 12:15:39.167305 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 5, Names: [syz-execprog]} D0227 12:15:39.169418 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582792705, NanoSec: 196725805}, MTime: {Sec: 1582792705, NanoSec: 196725805}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515320}]} D0227 12:15:39.170205 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-execprog, Size: 1} D0227 12:15:39.171384 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:39.171705 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetattr{FID: 5, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 12:15:39.172857 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515320}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 24119712, BlockSize: 4096, Blocks: 47112, ATime: {Sec: 1582792705, NanoSec: 196725805}, MTime: {Sec: 1582792705, NanoSec: 196725805}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 12:15:39.173134 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalk{FID: 5, NewFID: 6, Names: []} D0227 12:15:39.173733 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rwalk{QIDs: []} D0227 12:15:39.173904 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tlopen{FID: 6, Flags: ReadOnly} D0227 12:15:39.174559 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515320}, IoUnit: 0, File: &{{33}}} D0227 12:15:39.179393 6245 syscalls.go:266] Allocating stack with size of 8388608 bytes D0227 12:15:39.182309 6245 loader.go:832] updated processes: map[{ci-gvisor-ptrace-proxy-sandbox-race-0 0}:0xc00034c7a0 {ci-gvisor-ptrace-proxy-sandbox-race-0 19}:0xc0001b9d00] D0227 12:15:39.182684 6245 urpc.go:534] urpc: successfully marshalled 37 bytes. D0227 12:15:39.182852 16123 urpc.go:577] urpc: unmarshal success. D0227 12:15:39.182994 16123 container.go:579] Wait on PID 19 in container "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.183130 16123 sandbox.go:743] Waiting for PID 19 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.183240 16123 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:39.183534 16123 urpc.go:534] urpc: successfully marshalled 100 bytes. D0227 12:15:39.183913 6245 urpc.go:577] urpc: unmarshal success. D0227 12:15:39.184193 6245 controller.go:443] containerManager.Wait D0227 12:15:39.185547 6245 task_block.go:223] [ 19] Interrupt queued D0227 12:15:39.408705 6245 task_block.go:223] [ 20] Interrupt queued D0227 12:15:39.409383 6245 task_block.go:223] [ 21] Interrupt queued D0227 12:15:39.412301 6245 task_block.go:223] [ 22] Interrupt queued D0227 12:15:39.437416 6245 task_block.go:223] [ 23] Interrupt queued D0227 12:15:39.441165 6245 task_block.go:223] [ 24] Interrupt queued D0227 12:15:39.443660 6245 task_block.go:223] [ 25] Interrupt queued D0227 12:15:39.514787 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [etc]} D0227 12:15:39.515432 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:39.515608 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 12:15:39.516021 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:39.574902 6245 task_block.go:223] [ 26] Interrupt queued D0227 12:15:39.583293 6245 task_block.go:223] [ 27] Interrupt queued D0227 12:15:39.633637 6245 task_block.go:223] [ 28] Interrupt queued D0227 12:15:39.636755 6245 task_block.go:223] [ 29] Interrupt queued D0227 12:15:39.641483 6245 parameters.go:238] Clock(Monotonic): error: 325 ns, adjusted frequency from 2299773673 Hz to 2299775236 Hz D0227 12:15:39.641729 6245 parameters.go:238] Clock(Realtime): error: 259 ns, adjusted frequency from 2299773951 Hz to 2299775100 Hz D0227 12:15:39.641817 6245 timekeeper.go:209] Updating VDSO parameters: {monotonicReady:1 monotonicBaseCycles:8503836152039155 monotonicBaseRef:94000673573 monotonicFrequency:2299775236 realtimeReady:1 realtimeBaseCycles:8503836152635611 realtimeBaseRef:1582805739641723502 realtimeFrequency:2299775100} D0227 12:15:39.644344 6245 task_block.go:223] [ 30] Interrupt queued D0227 12:15:39.685601 6245 task_block.go:223] [ 31] Interrupt queued D0227 12:15:39.700463 6245 task_block.go:223] [ 32] Interrupt queued D0227 12:15:39.750068 6245 task_block.go:223] [ 33] Interrupt queued D0227 12:15:39.760395 6245 task_block.go:223] [ 34] Interrupt queued D0227 12:15:39.761656 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 7, Names: [syzkaller925062890]} D0227 12:15:39.762864 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] 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: 208, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582805739, NanoSec: 105325511}, MTime: {Sec: 1582805739, NanoSec: 105325511}, CTime: {Sec: 1582805739, NanoSec: 105325511}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515213}]} D0227 12:15:39.763129 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzkaller925062890, Size: 1} D0227 12:15:39.763613 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:39.764025 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetattr{FID: 7, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 12:15:39.765898 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515213}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 208, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582805739, NanoSec: 105325511}, MTime: {Sec: 1582805739, NanoSec: 105325511}, CTime: {Sec: 1582805739, NanoSec: 105325511}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 12:15:39.766047 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalk{FID: 7, NewFID: 8, Names: []} D0227 12:15:39.766564 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rwalk{QIDs: []} D0227 12:15:39.766708 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tlopen{FID: 8, Flags: ReadOnly} D0227 12:15:39.767425 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515213}, IoUnit: 0, File: &{{27}}} D0227 12:15:39.768732 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetattr{FID: 8, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 12:15:39.769759 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515213}, Attr: Attr{Mode: 0o100600, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 208, BlockSize: 4096, Blocks: 8, ATime: {Sec: 1582805739, NanoSec: 105325511}, MTime: {Sec: 1582805739, NanoSec: 105325511}, CTime: {Sec: 1582805739, NanoSec: 105325511}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} 2020/02/27 12:15:39 parsed 1 programs D0227 12:15:39.790745 6245 task_stop.go:118] [ 29] Entering internal stop (*kernel.vforkStop)(nil) D0227 12:15:39.791508 6245 task_block.go:223] [ 35] Interrupt queued D0227 12:15:39.795966 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 9, Names: [syz-executor]} D0227 12:15:39.797376 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515325}]} D0227 12:15:39.797732 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syz-executor, Size: 1} D0227 12:15:39.798204 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:39.798567 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 12:15:39.799615 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515325}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 12:15:39.800653 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalk{FID: 9, NewFID: 10, Names: []} D0227 12:15:39.801514 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rwalk{QIDs: []} D0227 12:15:39.801899 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tlopen{FID: 10, Flags: ReadOnly} D0227 12:15:39.803085 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlopen{QID: QID{Type: 0, Version: 0, Path: 16515325}, IoUnit: 0, File: &{{28}}} D0227 12:15:39.804643 6245 syscalls.go:266] [ 35] Allocating stack with size of 8388608 bytes D0227 12:15:39.805984 6245 task_stop.go:137] [ 29] Leaving internal stop (*kernel.vforkStop)(nil) D0227 12:15:39.847059 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 12:15:39.847920 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:39.848111 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 12:15:39.848682 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:39.849857 6245 task_exit.go:221] [ 35] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:39.851056 6245 task_exit.go:221] [ 35] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:39.851198 6245 task_signals.go:446] [ 19] Notified of signal 17 D0227 12:15:39.851296 6245 task_block.go:223] [ 19] Interrupt queued D0227 12:15:39.851575 6245 task_block.go:223] [ 19] Interrupt queued D0227 12:15:39.851711 6245 task_signals.go:179] [ 19] Restarting syscall 202 after errno 512: interrupted by signal 17 D0227 12:15:39.851805 6245 task_signals.go:220] [ 19] Signal 17: delivering to handler D0227 12:15:39.852993 6245 task_exit.go:221] [ 35] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:39.857267 6245 task_block.go:223] [ 36] Interrupt queued D0227 12:15:39.893561 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 12:15:39.912154 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515325}]} D0227 12:15:39.912567 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tclunk{FID: 11} D0227 12:15:39.914512 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rclunk{} D0227 12:15:39.914838 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} 2020/02/27 12:15:39 executed programs: 0 D0227 12:15:39.915845 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515325}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 12:15:39.939602 6245 task_stop.go:118] [ 31] Entering internal stop (*kernel.vforkStop)(nil) D0227 12:15:39.940328 6245 task_block.go:223] [ 37] Interrupt queued D0227 12:15:39.945821 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syz-executor]} D0227 12:15:39.947015 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rwalkgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}, QIDs: [QID{Type: 0, Version: 0, Path: 16515325}]} D0227 12:15:39.947176 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tclunk{FID: 11} D0227 12:15:39.947712 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rclunk{} D0227 12:15:39.948061 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetattr{FID: 9, AttrMask: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime INo Size Blocks BTime Gen DataVersion}} D0227 12:15:39.948995 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rgetattr{Valid: AttrMask{with: Mode NLink UID GID RDev ATime MTime CTime Size Blocks}, QID: QID{Type: 0, Version: 0, Path: 16515325}, Attr: Attr{Mode: 0o100755, UID: 0, GID: 0, NLink: 1, RDev: 0, Size: 1579448, BlockSize: 4096, Blocks: 3088, ATime: {Sec: 1582792705, NanoSec: 424748149}, MTime: {Sec: 1582792705, NanoSec: 424748149}, CTime: {Sec: 1582805646, NanoSec: 936291481}, BTime: {Sec: 0, NanoSec: 0}, Gen: 0, DataVersion: 0}} D0227 12:15:39.950029 6245 syscalls.go:266] [ 37] Allocating stack with size of 8388608 bytes D0227 12:15:39.950984 6245 task_stop.go:137] [ 31] Leaving internal stop (*kernel.vforkStop)(nil) D0227 12:15:39.961915 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [etc]} D0227 12:15:39.962508 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:39.962749 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.etc, Size: 1} D0227 12:15:39.963239 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:39.997178 6245 task_block.go:223] [ 38] Interrupt queued D0227 12:15:40.000075 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.008052 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.008333 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.011112 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.011628 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.012188 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.012456 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.013772 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.014413 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.015124 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.015288 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.040546 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.041886 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.042728 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.042901 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.046388 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.046804 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.047315 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.047473 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.048062 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.048749 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.049416 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.049609 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.050130 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.050476 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.050989 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.051189 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.051607 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.052025 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.052583 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.052772 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.053374 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.053919 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.054529 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.054671 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.055286 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.083706 6245 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 12:15:40.083935 6245 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 12:15:40.084064 6245 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 12:15:40.084221 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.084433 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.085134 6245 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 12:15:40.086307 6245 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 152 D0227 12:15:40.086441 6245 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 152 D0227 12:15:40.086511 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.086628 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.087115 6245 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 12:15:40.087199 6245 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 12:15:40.087279 6245 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 12:15:40.087356 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.087429 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.087904 6245 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 12:15:40.088010 6245 netfilter.go:54] netfilter: convert to binary: found hook 4 at offset 456 D0227 12:15:40.088098 6245 netfilter.go:54] netfilter: convert to binary: found underflow 4 at offset 456 D0227 12:15:40.088199 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.088272 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.088865 6245 netfilter.go:54] netfilter: convert to binary: current offset: 608 D0227 12:15:40.088988 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0227 12:15:40.089654 6245 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 12:15:40.089789 6245 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 12:15:40.089890 6245 netfilter.go:54] netfilter: convert to binary: found hook 0 at offset 0 D0227 12:15:40.089985 6245 netfilter.go:54] netfilter: convert to binary: found underflow 0 at offset 0 D0227 12:15:40.090085 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.090155 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.090699 6245 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 12:15:40.090856 6245 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 152 D0227 12:15:40.090964 6245 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 152 D0227 12:15:40.091026 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.091095 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.091623 6245 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 12:15:40.091723 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0227 12:15:40.092292 6245 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 12:15:40.092377 6245 netfilter.go:54] netfilter: convert to binary: current offset: 0 D0227 12:15:40.092460 6245 netfilter.go:54] netfilter: convert to binary: found hook 1 at offset 0 D0227 12:15:40.092553 6245 netfilter.go:54] netfilter: convert to binary: found underflow 1 at offset 0 D0227 12:15:40.092651 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.092753 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.093276 6245 netfilter.go:54] netfilter: convert to binary: current offset: 152 D0227 12:15:40.093381 6245 netfilter.go:54] netfilter: convert to binary: found hook 2 at offset 152 D0227 12:15:40.093472 6245 netfilter.go:54] netfilter: convert to binary: found underflow 2 at offset 152 D0227 12:15:40.093557 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.093626 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.094135 6245 netfilter.go:54] netfilter: convert to binary: current offset: 304 D0227 12:15:40.094206 6245 netfilter.go:54] netfilter: convert to binary: found hook 3 at offset 304 D0227 12:15:40.094274 6245 netfilter.go:54] netfilter: convert to binary: found underflow 3 at offset 304 D0227 12:15:40.094357 6245 netfilter.go:54] netfilter: convert to binary: marshalling standard target D0227 12:15:40.094436 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:152 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[40 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 254 255 255 255 0 0 0 0]} D0227 12:15:40.094880 6245 netfilter.go:54] netfilter: convert to binary: current offset: 456 D0227 12:15:40.094974 6245 netfilter.go:54] netfilter: convert to binary: adding entry: {IPTEntry:{IP:{Src:[0 0 0 0] Dst:[0 0 0 0] SrcMask:[0 0 0 0] DstMask:[0 0 0 0] InputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterface:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] InputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] OutputInterfaceMask:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] Protocol:0 Flags:0 InverseFlags:0} NFCache:0 TargetOffset:112 NextOffset:176 Comeback:0 Counters:{Pcnt:0 Bcnt:0}} Elems:[64 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 69 82 82 79 82 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]} D0227 12:15:40.095495 6245 netfilter.go:54] netfilter: convert to binary: finished with an marshalled size of 0 D0227 12:15:40.202822 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.205621 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.205802 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.206328 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.206678 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.207190 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.207311 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.207909 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.208200 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.208820 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.208969 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.209497 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.209833 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.213040 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.213255 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.216458 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.217003 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.217612 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.217791 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.218998 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.219570 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.242045 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.242650 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.244759 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.245246 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.248441 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.248735 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.249333 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.249751 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.250375 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.250508 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.251027 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.251436 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.252540 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.253295 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.253761 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.254121 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.254698 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.254868 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.255303 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.274577 6245 task_block.go:223] [ 39] Interrupt queued D0227 12:15:40.292771 6245 task_block.go:223] [ 40] Interrupt queued D0227 12:15:40.331274 6245 task_block.go:223] [ 41] Interrupt queued D0227 12:15:40.340842 6245 task_block.go:223] [ 40] Interrupt queued D0227 12:15:40.341117 6245 task_block.go:223] [ 41] Interrupt queued D0227 12:15:40.341138 6245 task_block.go:223] [ 41] Interrupt queued D0227 12:15:40.340941 6245 task_block.go:223] [ 40] Interrupt queued D0227 12:15:40.341245 6245 task_exit.go:221] [ 39] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:40.341483 6245 task_signals.go:189] [ 40] Signal 9: terminating thread group D0227 12:15:40.341602 6245 task_exit.go:221] [ 39] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.341607 6245 task_signals.go:189] [ 41] Signal 9: terminating thread group I0227 12:15:40.341795 6245 compat.go:129] Uncaught signal: "killed" (9), PID: 39, TID: 40, fault addr: 0x0 D0227 12:15:40.342218 6245 task_exit.go:221] [ 40] Transitioning from exit state TaskExitNone to TaskExitInitiated I0227 12:15:40.342210 6245 compat.go:129] Uncaught signal: "killed" (9), PID: 39, TID: 41, fault addr: 0x0 D0227 12:15:40.342386 6245 task_exit.go:221] [ 41] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:40.342758 6245 task_exit.go:221] [ 41] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.342965 6245 task_exit.go:221] [ 41] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.345025 6245 task_exit.go:221] [ 40] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.345175 6245 task_exit.go:221] [ 40] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.345384 6245 task_signals.go:419] [ 38] Discarding ignored signal 17 D0227 12:15:40.345641 6245 task_exit.go:221] [ 39] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.348643 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.349420 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.349608 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.350025 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.350778 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.351201 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.351375 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.364797 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.365830 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.366332 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.366472 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.366947 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.373634 6245 task_block.go:223] [ 42] Interrupt queued D0227 12:15:40.388359 6245 task_block.go:223] [ 43] Interrupt queued D0227 12:15:40.399401 6245 task_block.go:223] [ 44] Interrupt queued D0227 12:15:40.406114 6245 task_block.go:223] [ 43] Interrupt queued D0227 12:15:40.406140 6245 task_block.go:223] [ 43] Interrupt queued D0227 12:15:40.406240 6245 task_block.go:223] [ 44] Interrupt queued D0227 12:15:40.406376 6245 task_exit.go:221] [ 42] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:40.406580 6245 task_exit.go:221] [ 42] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.406738 6245 task_signals.go:189] [ 43] Signal 9: terminating thread group D0227 12:15:40.406334 6245 task_block.go:223] [ 44] Interrupt queued I0227 12:15:40.406973 6245 compat.go:129] Uncaught signal: "killed" (9), PID: 42, TID: 43, fault addr: 0x0 D0227 12:15:40.407094 6245 task_signals.go:189] [ 44] Signal 9: terminating thread group D0227 12:15:40.407250 6245 task_exit.go:221] [ 43] Transitioning from exit state TaskExitNone to TaskExitInitiated I0227 12:15:40.407511 6245 compat.go:129] Uncaught signal: "killed" (9), PID: 42, TID: 44, fault addr: 0x0 D0227 12:15:40.407567 6245 task_exit.go:221] [ 43] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.407729 6245 task_exit.go:221] [ 43] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.408132 6245 task_exit.go:221] [ 44] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:40.410081 6245 task_exit.go:221] [ 44] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.410221 6245 task_exit.go:221] [ 44] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.410418 6245 task_signals.go:419] [ 38] Discarding ignored signal 17 D0227 12:15:40.410737 6245 task_exit.go:221] [ 42] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.412711 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.413366 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.413570 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.413946 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.414654 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.416550 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.416708 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.417964 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.418594 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.419051 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.419270 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.419730 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.425724 6245 task_block.go:223] [ 45] Interrupt queued D0227 12:15:40.462007 6245 task_block.go:223] [ 46] Interrupt queued D0227 12:15:40.482390 6245 task_block.go:223] [ 47] Interrupt queued D0227 12:15:40.488800 6245 task_block.go:223] [ 46] Interrupt queued D0227 12:15:40.488966 6245 task_block.go:223] [ 47] Interrupt queued D0227 12:15:40.489068 6245 task_exit.go:221] [ 45] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:40.489061 6245 task_block.go:223] [ 47] Interrupt queued D0227 12:15:40.489238 6245 task_exit.go:221] [ 45] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.489272 6245 task_signals.go:189] [ 47] Signal 9: terminating thread group I0227 12:15:40.489451 6245 compat.go:129] Uncaught signal: "killed" (9), PID: 45, TID: 47, fault addr: 0x0 D0227 12:15:40.489611 6245 task_exit.go:221] [ 47] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:40.489816 6245 task_exit.go:221] [ 47] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.489907 6245 task_exit.go:221] [ 47] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.500586 6245 task_signals.go:189] [ 46] Signal 9: terminating thread group I0227 12:15:40.500835 6245 compat.go:129] Uncaught signal: "killed" (9), PID: 45, TID: 46, fault addr: 0x0 D0227 12:15:40.500993 6245 task_exit.go:221] [ 46] Transitioning from exit state TaskExitNone to TaskExitInitiated D0227 12:15:40.502770 6245 task_exit.go:221] [ 46] Transitioning from exit state TaskExitInitiated to TaskExitZombie D0227 12:15:40.502933 6245 task_exit.go:221] [ 46] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.503164 6245 task_signals.go:419] [ 38] Discarding ignored signal 17 D0227 12:15:40.503440 6245 task_exit.go:221] [ 45] Transitioning from exit state TaskExitZombie to TaskExitDead D0227 12:15:40.507684 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.508860 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.509050 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.509591 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.510450 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.510941 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.511165 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.511565 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.512223 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Twalkgetattr{FID: 1, NewFID: 11, Names: [syzcgroup]} D0227 12:15:40.512675 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 2} D0227 12:15:40.512924 6245 transport_flipcall.go:127] send [channel @0xc00016c0c0] Tgetxattr{FID: 1, Name: trusted.overlay.whiteout.syzcgroup, Size: 1} D0227 12:15:40.513312 6245 transport_flipcall.go:234] recv [channel @0xc00016c0c0] Rlerror{Error: 95} D0227 12:15:40.527870 6245 task_block.go:223] [ 48] Interrupt queued D0227 12:15:40.537640 6245 task_block.go:223] [ 49] Interrupt queued D0227 12:15:40.552717 6245 task_block.go:223] [ 50] Interrupt queued ================== WARNING: DATA RACE Read at 0x00c0003ac250 by goroutine 341: gvisor.dev/gvisor/pkg/tcpip/stack.(*TransportEndpointInfo).AddrNetProto() pkg/tcpip/stack/stack.go:573 +0x79 gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).checkV4Mapped() pkg/tcpip/transport/udp/endpoint.go:931 +0xee gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Connect() pkg/tcpip/transport/udp/endpoint.go:984 +0x6c gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Connect() pkg/sentry/socket/netstack/netstack.go:698 +0x4c5 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Connect() pkg/sentry/syscalls/linux/sys_socket.go:280 +0x251 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 Previous write at 0x00c0003ac250 by goroutine 349: gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).bindLocked() pkg/tcpip/transport/udp/endpoint.go:1176 +0x28a gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).prepareForWrite() pkg/tcpip/transport/udp/endpoint.go:323 +0x267 gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).write() pkg/tcpip/transport/udp/endpoint.go:400 +0x12b gvisor.dev/gvisor/pkg/tcpip/transport/udp.(*endpoint).Write() pkg/tcpip/transport/udp/endpoint.go:360 +0x81 gvisor.dev/gvisor/pkg/sentry/socket/netstack.(*SocketOperations).Write() pkg/sentry/socket/netstack/netstack.go:522 +0x152 gvisor.dev/gvisor/pkg/sentry/fs.(*File).Writev() pkg/sentry/fs/file.go:336 +0x308 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.writev() pkg/sentry/syscalls/linux/sys_write.go:262 +0xe0 gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Write() pkg/sentry/syscalls/linux/sys_write.go:72 +0x2ab 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 341 (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 DIAGNOSIS: I0227 12:15:40.592625 16276 main.go:296] *************************** I0227 12:15:40.592864 16276 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-0] I0227 12:15:40.593135 16276 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 12:15:40.593265 16276 main.go:299] PID: 16276 I0227 12:15:40.593416 16276 main.go:300] UID: 0, GID: 0 I0227 12:15:40.593548 16276 main.go:301] Configuration: I0227 12:15:40.593669 16276 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 12:15:40.593801 16276 main.go:303] Platform: ptrace I0227 12:15:40.593945 16276 main.go:304] FileAccess: shared, overlay: false I0227 12:15:40.594128 16276 main.go:305] Network: sandbox, logging: false I0227 12:15:40.594272 16276 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 12:15:40.594418 16276 main.go:307] *************************** W0227 12:15:40.594542 16276 main.go:312] Block the TERM signal. This is only safe in tests! D0227 12:15:40.594797 16276 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.601004 16276 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-0": signal 0 D0227 12:15:40.601218 16276 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.601379 16276 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.601869 16276 urpc.go:534] urpc: successfully marshalled 117 bytes. I0227 12:15:40.665788 16276 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0", PID: 6245 I0227 12:15:40.665954 16276 debug.go:131] Retrieving sandbox stacks D0227 12:15:40.666036 16276 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.666121 16276 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" W0227 12:15:40.666273 16276 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 6245: connection refused retrieving stacks: connecting to control server at PID 6245: connection refused W0227 12:15:40.666511 16276 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-0"]: exit status 128 I0227 12:15:40.592625 16276 main.go:296] *************************** I0227 12:15:40.592864 16276 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-0] I0227 12:15:40.593135 16276 main.go:298] Version release-20200219.0-47-gde0b2ebf8635 I0227 12:15:40.593265 16276 main.go:299] PID: 16276 I0227 12:15:40.593416 16276 main.go:300] UID: 0, GID: 0 I0227 12:15:40.593548 16276 main.go:301] Configuration: I0227 12:15:40.593669 16276 main.go:302] RootDir: /syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root I0227 12:15:40.593801 16276 main.go:303] Platform: ptrace I0227 12:15:40.593945 16276 main.go:304] FileAccess: shared, overlay: false I0227 12:15:40.594128 16276 main.go:305] Network: sandbox, logging: false I0227 12:15:40.594272 16276 main.go:306] Strace: false, max size: 1024, syscalls: [] I0227 12:15:40.594418 16276 main.go:307] *************************** W0227 12:15:40.594542 16276 main.go:312] Block the TERM signal. This is only safe in tests! D0227 12:15:40.594797 16276 container.go:158] Load container "/syzkaller/managers/ptrace-proxy-sandbox-race/workdir/gvisor_root" "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.601004 16276 container.go:591] Signal container "ci-gvisor-ptrace-proxy-sandbox-race-0": signal 0 D0227 12:15:40.601218 16276 sandbox.go:788] Signal sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.601379 16276 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.601869 16276 urpc.go:534] urpc: successfully marshalled 117 bytes. I0227 12:15:40.665788 16276 debug.go:122] Found sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0", PID: 6245 I0227 12:15:40.665954 16276 debug.go:131] Retrieving sandbox stacks D0227 12:15:40.666036 16276 sandbox.go:906] Stacks sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.666121 16276 sandbox.go:318] Connecting to sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" W0227 12:15:40.666273 16276 error.go:48] FATAL ERROR: retrieving stacks: connecting to control server at PID 6245: connection refused retrieving stacks: connecting to control server at PID 6245: connection refused W0227 12:15:40.666511 16276 main.go:329] Failure to execute command, err: 1 Goroutine 349 (running) created at: gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Start() pkg/sentry/kernel/task_start.go:315 +0x19d gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Clone() pkg/sentry/kernel/task_clone.go:361 +0x12af gvisor.dev/gvisor/pkg/sentry/syscalls/linux.clone() pkg/sentry/syscalls/linux/sys_thread.go:226 +0x1fe gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Clone() pkg/sentry/syscalls/linux/sys_clone_amd64.go:34 +0x80 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall() pkg/sentry/kernel/task_syscall.go:170 +0x455 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke() pkg/sentry/kernel/task_syscall.go:291 +0xb4 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter() pkg/sentry/kernel/task_syscall.go:252 +0x109 gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall() pkg/sentry/kernel/task_syscall.go:227 +0x1b3 gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute() pkg/sentry/kernel/task_run.go:232 +0x1aaf gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run() pkg/sentry/kernel/task_run.go:92 +0x308 ================== W0227 12:15:40.657127 16123 error.go:48] FATAL ERROR: waiting on pid 19: waiting on PID 19 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0": urpc method "containerManager.WaitPID" failed: EOF waiting on pid 19: waiting on PID 19 in sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0": urpc method "containerManager.WaitPID" failed: EOF W0227 12:15:40.658112 16123 main.go:329] Failure to execute command, err: 1 W0227 12:15:40.665626 6225 sandbox.go:724] Wait RPC to container "ci-gvisor-ptrace-proxy-sandbox-race-0" failed: urpc method "containerManager.Wait" failed: EOF. Will try waiting on the sandbox process instead. D0227 12:15:40.666230 6225 container.go:713] Destroy container "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.666380 6225 container.go:800] Destroying container "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.666480 6225 sandbox.go:1040] Destroying root container "ci-gvisor-ptrace-proxy-sandbox-race-0" by destroying sandbox D0227 12:15:40.666602 6225 sandbox.go:770] Destroy sandbox "ci-gvisor-ptrace-proxy-sandbox-race-0" D0227 12:15:40.666693 6225 container.go:814] Killing gofer for container "ci-gvisor-ptrace-proxy-sandbox-race-0", PID: 6244 I0227 12:15:40.767539 6225 main.go:320] Exiting with status: 16896