[41.663611] Initializing watchdogs
[41.663743]   /dev/watchdog0
[41.696719] [FACT before any test] new: hardware.pci.gpu_at_addr.0000:00:02.0: 8086:1916 Intel Skylake (Gen9) Skylake GT2 [HD Graphics 520]
[41.704947] [001/162] (960s left) i915_module_load (load)
[41.782047] Starting subtest: load
[43.492099] Subtest load: SUCCESS (1.708s)
[43.551607] [FACT i915_module_load (load)] new: hardware.pci.drm_card_at_addr.0000:00:02.0: card0
[43.555050] [FACT i915_module_load (load)] new: kernel.kmod_is_loaded.i915: true
[43.559374] [002/162] (958s left) core_auth (basic-auth)
[43.642323] Starting subtest: basic-auth
[43.643302] Subtest basic-auth: SUCCESS (0.001s)
[43.814160] [003/162] (958s left) core_debugfs (read-all-entries)
[43.882535] Starting subtest: read-all-entries
[44.008748] Subtest read-all-entries: SUCCESS (0.127s)
[44.125490] [004/162] (958s left) core_sysfs (read-all-entries)
[44.195042] Starting subtest: read-all-entries
[44.202741] Subtest read-all-entries: SUCCESS (0.008s)
[44.305122] [005/162] (958s left) fbdev (eof)
[44.392073] Starting subtest: eof
[44.393015] Subtest eof: SUCCESS (0.001s)
[44.549664] [006/162] (958s left) fbdev (info)
[44.614015] Starting subtest: info
[44.615208] Subtest info: SUCCESS (0.000s)
[44.721511] [007/162] (957s left) fbdev (nullptr)
[44.807443] Starting subtest: nullptr
[44.808512] Subtest nullptr: SUCCESS (0.000s)
[44.913152] [008/162] (957s left) fbdev (read)
[44.990589] Starting subtest: read
[45.892212] Subtest read: SUCCESS (0.892s)
[45.987864] [009/162] (956s left) fbdev (write)
[46.057451] Starting subtest: write
[46.533105] Subtest write: SUCCESS (0.466s)
[46.621486] [010/162] (956s left) gem_basic (bad-close)
[46.691901] Starting subtest: bad-close
[46.694022] Subtest bad-close: SUCCESS (0.000s)
[46.806295] [011/162] (956s left) gem_basic (create-close)
[46.875457] Starting subtest: create-close
[46.877387] Subtest create-close: SUCCESS (0.000s)
[47.021268] [012/162] (955s left) gem_basic (create-fd-close)
[47.096150] Starting subtest: create-fd-close
[47.098098] Subtest create-fd-close: SUCCESS (0.000s)
[47.283682] [013/162] (955s left) gem_busy (busy@all-engines)
[47.378359] Starting subtest: busy
[47.379447] Starting dynamic subtest: all-engines
[47.447274] Dynamic subtest all-engines: SUCCESS (0.069s)
[47.448327] Subtest busy: SUCCESS (0.069s)
[47.903020] [014/162] (955s left) gem_close_race (basic-process)
[47.995118] Starting subtest: basic-process
[48.061667] Subtest basic-process: SUCCESS (0.066s)
[48.376660] [015/162] (954s left) gem_close_race (basic-threads)
[48.470303] Starting subtest: basic-threads
[49.676890] Subtest basic-threads: SUCCESS (1.207s)
[49.966618] [016/162] (953s left) gem_ctx_create (basic)
[50.052958] Starting subtest: basic
[50.054171] Subtest basic: SUCCESS (0.000s)
[50.326507] [017/162] (953s left) gem_ctx_create (basic-files)
[50.414622] Starting subtest: basic-files
[52.437107] Subtest basic-files: SUCCESS (2.022s)
[52.753988] [018/162] (950s left) gem_ctx_exec (basic)
[52.831036] Starting subtest: basic
[52.836527] Subtest basic: SUCCESS (0.007s)
[53.012310] [019/162] (950s left) gem_exec_basic (basic)
[53.094073] Starting subtest: basic
[53.095149] Starting dynamic subtest: rcs0-smem
[53.096181] Dynamic subtest rcs0-smem: SUCCESS (0.003s)
[53.109581] Starting dynamic subtest: bcs0-smem
[53.110756] Dynamic subtest bcs0-smem: SUCCESS (0.002s)
[53.123094] Starting dynamic subtest: vcs0-smem
[53.124511] Dynamic subtest vcs0-smem: SUCCESS (0.001s)
[53.135800] Starting dynamic subtest: vecs0-smem
[53.137172] Dynamic subtest vecs0-smem: SUCCESS (0.001s)
[53.138543] Subtest basic: SUCCESS (0.010s)
[53.370640] [020/162] (950s left) gem_exec_create (basic)
[53.454527] Starting subtest: basic
[53.455584] Starting dynamic subtest: smem
[55.502639] Dynamic subtest smem: SUCCESS (2.096s)
[55.503730] Subtest basic: SUCCESS (2.097s)
[55.773318] [021/162] (947s left) gem_exec_fence (basic-busy)
[56.039187] Starting subtest: basic-busy
[56.040116] Starting dynamic subtest: rcs0
[56.071285] Dynamic subtest rcs0: SUCCESS (0.034s)
[56.086167] Starting dynamic subtest: bcs0
[56.096352] Dynamic subtest bcs0: SUCCESS (0.025s)
[56.109115] Starting dynamic subtest: vcs0
[56.122251] Dynamic subtest vcs0: SUCCESS (0.026s)
[56.136546] Starting dynamic subtest: vecs0
[56.146151] Dynamic subtest vecs0: SUCCESS (0.024s)
[56.147192] Subtest basic-busy: SUCCESS (0.111s)
[56.966517] [FACT gem_exec_fence (basic-busy)] new: kernel.kmod_is_loaded.vgem: true
[56.971312] [022/162] (946s left) gem_exec_fence (basic-wait)
[57.206240] Starting subtest: basic-wait
[57.207386] Starting dynamic subtest: rcs0
[57.232155] Dynamic subtest rcs0: SUCCESS (0.026s)
[57.245147] Starting dynamic subtest: bcs0
[57.261155] Dynamic subtest bcs0: SUCCESS (0.029s)
[57.274087] Starting dynamic subtest: vcs0
[57.283336] Dynamic subtest vcs0: SUCCESS (0.022s)
[57.296936] Starting dynamic subtest: vecs0
[57.299381] Dynamic subtest vecs0: SUCCESS (0.016s)
[57.300502] Subtest basic-wait: SUCCESS (0.095s)
[58.081798] [023/162] (945s left) gem_exec_fence (basic-await)
[58.326551] Starting subtest: basic-await
[58.327813] Starting dynamic subtest: rcs0
[58.430539] Dynamic subtest rcs0: SUCCESS (0.107s)
[58.445215] Starting dynamic subtest: bcs0
[58.530995] Dynamic subtest bcs0: SUCCESS (0.101s)
[58.545983] Starting dynamic subtest: vcs0
[58.634460] Dynamic subtest vcs0: SUCCESS (0.104s)
[58.652208] Starting dynamic subtest: vecs0
[58.743884] Dynamic subtest vecs0: SUCCESS (0.108s)
[58.745250] Subtest basic-await: SUCCESS (0.422s)
[59.517911] [024/162] (944s left) gem_exec_fence (nb-await)
[59.744491] Starting subtest: nb-await
[59.746133] Starting dynamic subtest: rcs0
[59.819506] Dynamic subtest rcs0: SUCCESS (0.078s)
[59.851058] Starting dynamic subtest: bcs0
[59.902175] Dynamic subtest bcs0: SUCCESS (0.082s)
[59.919032] Starting dynamic subtest: vcs0
[59.968958] Dynamic subtest vcs0: SUCCESS (0.068s)
[59.982709] Starting dynamic subtest: vecs0
[60.032785] Dynamic subtest vecs0: SUCCESS (0.062s)
[60.034917] Subtest nb-await: SUCCESS (0.294s)
[60.743970] [025/162] (943s left) gem_exec_gttfill (basic)
[60.832608] Starting subtest: basic
[66.408516] Subtest basic: SUCCESS (5.614s)
[66.707511] [026/162] (937s left) gem_exec_parallel (engines)
[66.862040] Starting subtest: engines
[66.863177] Starting dynamic subtest: basic
[69.904287] Dynamic subtest basic: SUCCESS (3.056s)
[69.918910] Starting dynamic subtest: contexts
[73.849743] Dynamic subtest contexts: SUCCESS (3.945s)
[73.863994] Starting dynamic subtest: fds
[79.669862] Dynamic subtest fds: SUCCESS (5.835s)
[79.685530] Starting dynamic subtest: userptr
[82.161613] Dynamic subtest userptr: SUCCESS (2.470s)
[82.162770] Subtest engines: SUCCESS (15.308s)
[82.418425] [027/162] (921s left) gem_exec_store (basic)
[82.503894] Starting subtest: basic
[82.575432] Subtest basic: SUCCESS (0.072s)
[82.852455] [028/162] (921s left) gem_flink_basic (bad-flink)
[82.923240] Starting subtest: bad-flink
[82.924324] Subtest bad-flink: SUCCESS (0.000s)
[83.038150] [029/162] (921s left) gem_flink_basic (bad-open)
[83.106354] Starting subtest: bad-open
[83.107420] Subtest bad-open: SUCCESS (0.000s)
[83.222285] [030/162] (921s left) gem_flink_basic (basic)
[83.292408] Starting subtest: basic
[83.293531] Subtest basic: SUCCESS (0.000s)
[83.498598] [031/162] (920s left) gem_flink_basic (double-flink)
[83.567131] Starting subtest: double-flink
[83.568203] Subtest double-flink: SUCCESS (0.000s)
[83.752102] [032/162] (920s left) gem_flink_basic (flink-lifetime)
[83.819615] Starting subtest: flink-lifetime
[83.821801] Subtest flink-lifetime: SUCCESS (0.002s)
[84.020339] [033/162] (920s left) gem_huc_copy (huc-copy)
[84.101280] Starting subtest: huc-copy
[84.103277] Subtest huc-copy: SKIP (0.000s)
[84.339693] [034/162] (920s left) gem_linear_blits (basic)
[84.615442] Starting subtest: basic
[84.630736] Subtest basic: SUCCESS (0.016s)
[84.850736] [035/162] (919s left) gem_mmap (basic)
[84.990567] Starting subtest: basic
[84.995082] Subtest basic: SUCCESS (0.001s)
[85.137867] [036/162] (919s left) gem_mmap_gtt (basic)
[85.208482] Starting subtest: basic
[85.209531] Subtest basic: SUCCESS (0.001s)
[85.356543] [037/162] (919s left) gem_render_linear_blits (basic)
[85.444158] Starting subtest: basic
[85.486880] Subtest basic: SUCCESS (0.042s)
[85.582154] [038/162] (919s left) gem_render_tiled_blits (basic)
[85.660261] Starting subtest: basic
[85.716807] Subtest basic: SUCCESS (0.056s)
[85.816963] [039/162] (919s left) gem_ringfill (basic-all)
[86.124931] Starting subtest: basic-all
[87.298704] Subtest basic-all: SUCCESS (1.165s)
[87.470843] [040/162] (917s left) gem_softpin (allocator-basic)
[87.554123] Starting subtest: allocator-basic
[87.736919] Subtest allocator-basic: SUCCESS (0.174s)
[87.942693] [041/162] (917s left) gem_softpin (allocator-basic-reserve)
[88.017899] Starting subtest: allocator-basic-reserve
[88.211959] Subtest allocator-basic-reserve: SUCCESS (0.185s)
[88.402671] [042/162] (916s left) gem_softpin (safe-alignment)
[88.480845] Starting subtest: safe-alignment
[88.501196] Subtest safe-alignment: SUCCESS (0.021s)
[88.726036] [043/162] (916s left) gem_sync (basic-all)
[88.814858] Starting subtest: basic-all
[91.320726] Subtest basic-all: SUCCESS (2.505s)
[91.622078] [044/162] (913s left) gem_sync (basic-each)
[91.710367] Starting subtest: basic-each
[93.902105] Subtest basic-each: SUCCESS (2.191s)
[94.272792] [045/162] (911s left) gem_tiled_blits (basic)
[94.437697] Starting subtest: basic
[94.459899] Subtest basic: SUCCESS (0.023s)
[94.675458] [046/162] (911s left) gem_tiled_fence_blits (basic)
[94.918240] Starting subtest: basic
[94.932960] Subtest basic: SUCCESS (0.014s)
[95.140251] [047/162] (910s left) gem_tiled_pread_basic (basic)
[95.266125] Starting subtest: basic
[95.419108] Subtest basic: SUCCESS (0.144s)
[95.602456] [048/162] (910s left) gem_wait (busy@all-engines)
[95.702359] Starting subtest: busy
[95.703371] Starting dynamic subtest: all-engines
[96.233370] Dynamic subtest all-engines: SUCCESS (0.531s)
[96.234426] Subtest busy: SUCCESS (0.531s)
[96.560717] [049/162] (909s left) gem_wait (wait@all-engines)
[96.657675] Starting subtest: wait
[96.658668] Starting dynamic subtest: all-engines
[97.714304] Dynamic subtest all-engines: SUCCESS (1.055s)
[97.717610] Subtest wait: SUCCESS (1.057s)
[98.070930] [050/162] (908s left) i915_getparams_basic (basic-eu-total)
[98.142218] Starting subtest: basic-eu-total
[98.144253] Subtest basic-eu-total: SUCCESS (0.000s)
[98.308616] [051/162] (907s left) i915_getparams_basic (basic-subslice-total)
[98.376496] Starting subtest: basic-subslice-total
[98.378481] Subtest basic-subslice-total: SUCCESS (0.000s)
[98.548139] [052/162] (907s left) i915_hangman (error-state-basic)
[98.639775] Starting subtest: error-state-basic
[98.649737] Subtest error-state-basic: SUCCESS (0.010s)
[98.790192] [053/162] (907s left) i915_pciid
[98.973714] [054/162] (907s left) intel_hwmon (hwmon-read)
[99.044073] Subtest hwmon-read: SKIP (0.000s)
[99.133269] [055/162] (907s left) intel_hwmon (hwmon-write)
[99.203061] Subtest hwmon-write: SKIP (0.000s)
[99.321217] [056/162] (907s left) kms_addfb_basic (addfb25-4-tiled)
[99.524267] Starting subtest: addfb25-4-tiled
[99.526051] Subtest addfb25-4-tiled: SUCCESS (0.000s)
[99.757013] [057/162] (907s left) kms_addfb_basic (addfb25-bad-modifier)
[99.883198] Starting subtest: addfb25-bad-modifier
[99.884149] Subtest addfb25-bad-modifier: SUCCESS (0.001s)
[100.021969] [058/162] (906s left) kms_addfb_basic (addfb25-framebuffer-vs-set-tiling)
[100.152270] Starting subtest: addfb25-framebuffer-vs-set-tiling
[100.153378] Subtest addfb25-framebuffer-vs-set-tiling: SUCCESS (0.000s)
[100.302410] [059/162] (906s left) kms_addfb_basic (addfb25-modifier-no-flag)
[100.428190] Starting subtest: addfb25-modifier-no-flag
[100.429197] Subtest addfb25-modifier-no-flag: SUCCESS (0.000s)
[100.587391] [060/162] (906s left) kms_addfb_basic (addfb25-x-tiled-legacy)
[100.714142] Starting subtest: addfb25-x-tiled-legacy
[100.715181] Subtest addfb25-x-tiled-legacy: SUCCESS (0.000s)
[100.895016] [061/162] (906s left) kms_addfb_basic (addfb25-x-tiled-mismatch-legacy)
[101.018394] Starting subtest: addfb25-x-tiled-mismatch-legacy
[101.019387] Subtest addfb25-x-tiled-mismatch-legacy: SUCCESS (0.000s)
[101.201201] [062/162] (905s left) kms_addfb_basic (addfb25-yf-tiled-legacy)
[101.332210] Starting subtest: addfb25-yf-tiled-legacy
[101.333245] Subtest addfb25-yf-tiled-legacy: SUCCESS (0.000s)
[101.467860] [063/162] (905s left) kms_addfb_basic (addfb25-y-tiled-legacy)
[101.599163] Starting subtest: addfb25-y-tiled-legacy
[101.600135] Subtest addfb25-y-tiled-legacy: SUCCESS (0.000s)
[101.784690] [064/162] (905s left) kms_addfb_basic (addfb25-y-tiled-small-legacy)
[101.914678] Starting subtest: addfb25-y-tiled-small-legacy
[101.915782] Subtest addfb25-y-tiled-small-legacy: SUCCESS (0.001s)
[102.077730] [065/162] (905s left) kms_addfb_basic (bad-pitch-0)
[102.147259] Starting subtest: bad-pitch-0
[102.148380] Subtest bad-pitch-0: SUCCESS (0.000s)
[102.354323] [066/162] (905s left) kms_addfb_basic (bad-pitch-1024)
[102.423382] Starting subtest: bad-pitch-1024
[102.424417] Subtest bad-pitch-1024: SUCCESS (0.000s)
[102.639853] [067/162] (904s left) kms_addfb_basic (bad-pitch-128)
[102.707353] Starting subtest: bad-pitch-128
[102.708386] Subtest bad-pitch-128: SUCCESS (0.000s)
[102.930395] [068/162] (904s left) kms_addfb_basic (bad-pitch-256)
[102.999642] Starting subtest: bad-pitch-256
[103.000702] Subtest bad-pitch-256: SUCCESS (0.000s)
[103.233653] [069/162] (904s left) kms_addfb_basic (bad-pitch-32)
[103.303522] Starting subtest: bad-pitch-32
[103.304582] Subtest bad-pitch-32: SUCCESS (0.000s)
[103.505505] [070/162] (904s left) kms_addfb_basic (bad-pitch-63)
[103.574495] Starting subtest: bad-pitch-63
[103.575538] Subtest bad-pitch-63: SUCCESS (0.000s)
[103.775429] [071/162] (904s left) kms_addfb_basic (bad-pitch-65536)
[103.845578] Starting subtest: bad-pitch-65536
[103.846740] Subtest bad-pitch-65536: SUCCESS (0.001s)
[104.055654] [072/162] (903s left) kms_addfb_basic (bad-pitch-999)
[104.126240] Starting subtest: bad-pitch-999
[104.127129] Subtest bad-pitch-999: SUCCESS (0.000s)
[104.367425] [073/162] (903s left) kms_addfb_basic (basic)
[104.435708] Starting subtest: basic
[104.436764] Subtest basic: SUCCESS (0.000s)
[104.640183] [074/162] (903s left) kms_addfb_basic (basic-x-tiled-legacy)
[104.711440] Starting subtest: basic-x-tiled-legacy
[104.712381] Subtest basic-x-tiled-legacy: SUCCESS (0.000s)
[104.923118] [075/162] (903s left) kms_addfb_basic (basic-y-tiled-legacy)
[104.994321] Starting subtest: basic-y-tiled-legacy
[104.995384] Subtest basic-y-tiled-legacy: SUCCESS (0.000s)
[105.220539] [076/162] (903s left) kms_addfb_basic (bo-too-small)
[105.349355] Starting subtest: bo-too-small
[105.350547] Subtest bo-too-small: SUCCESS (0.001s)
[105.506753] [077/162] (902s left) kms_addfb_basic (bo-too-small-due-to-tiling)
[105.634194] Starting subtest: bo-too-small-due-to-tiling
[105.635193] Subtest bo-too-small-due-to-tiling: SUCCESS (0.000s)
[105.805261] [078/162] (902s left) kms_addfb_basic (clobberred-modifier)
[105.874055] Starting subtest: clobberred-modifier
[105.875295] Subtest clobberred-modifier: SUCCESS (0.000s)
[106.133293] [079/162] (902s left) kms_addfb_basic (framebuffer-vs-set-tiling)
[106.203366] Starting subtest: framebuffer-vs-set-tiling
[106.204400] Subtest framebuffer-vs-set-tiling: SUCCESS (0.000s)
[106.424893] [080/162] (902s left) kms_addfb_basic (invalid-get-prop)
[106.495944] Starting subtest: invalid-get-prop
[106.497135] Subtest invalid-get-prop: SUCCESS (0.000s)
[106.736750] [081/162] (902s left) kms_addfb_basic (invalid-get-prop-any)
[106.806332] Starting subtest: invalid-get-prop-any
[106.807319] Subtest invalid-get-prop-any: SUCCESS (0.000s)
[107.017304] [082/162] (901s left) kms_addfb_basic (invalid-set-prop)
[107.087182] Starting subtest: invalid-set-prop
[107.088293] Subtest invalid-set-prop: SUCCESS (0.000s)
[107.320464] [083/162] (901s left) kms_addfb_basic (invalid-set-prop-any)
[107.389766] Starting subtest: invalid-set-prop-any
[107.390828] Subtest invalid-set-prop-any: SUCCESS (0.000s)
[107.639142] [084/162] (901s left) kms_addfb_basic (no-handle)
[107.707925] Starting subtest: no-handle
[107.709036] Subtest no-handle: SUCCESS (0.000s)
[107.953315] [085/162] (901s left) kms_addfb_basic (size-max)
[108.079161] Starting subtest: size-max
[108.080248] Subtest size-max: SUCCESS (0.000s)
[108.229100] [086/162] (900s left) kms_addfb_basic (small-bo)
[108.361475] Starting subtest: small-bo
[108.362433] Subtest small-bo: SUCCESS (0.000s)
[108.520768] [087/162] (900s left) kms_addfb_basic (tile-pitch-mismatch)
[108.590480] Starting subtest: tile-pitch-mismatch
[108.591543] Subtest tile-pitch-mismatch: SUCCESS (0.000s)
[108.824566] [088/162] (900s left) kms_addfb_basic (too-high)
[108.945331] Starting subtest: too-high
[108.946381] Subtest too-high: SUCCESS (0.001s)
[109.153527] [089/162] (900s left) kms_addfb_basic (too-wide)
[109.274269] Starting subtest: too-wide
[109.275310] Subtest too-wide: SUCCESS (0.000s)
[109.404866] [090/162] (900s left) kms_addfb_basic (unused-handle)
[109.480733] Starting subtest: unused-handle
[109.481818] Subtest unused-handle: SUCCESS (0.000s)
[109.725046] [091/162] (899s left) kms_addfb_basic (unused-modifier)
[109.797618] Starting subtest: unused-modifier
[109.798721] Subtest unused-modifier: SUCCESS (0.000s)
[110.000717] [092/162] (899s left) kms_addfb_basic (unused-offsets)
[110.069205] Starting subtest: unused-offsets
[110.070226] Subtest unused-offsets: SUCCESS (0.000s)
[110.308971] [093/162] (899s left) kms_addfb_basic (unused-pitches)
[110.378146] Starting subtest: unused-pitches
[110.379151] Subtest unused-pitches: SUCCESS (0.000s)
[110.616808] [094/162] (899s left) kms_busy (basic)