On Thu, Nov 03, 2022 at 12:40:59PM +0100, Mauro Carvalho Chehab wrote: > On Thu, 3 Nov 2022 10:48:40 +0100 > Mauro Carvalho Chehab <mauro.chehab@xxxxxxxxxxxxxxx> wrote: > > > On Sun, 28 Aug 2022 21:09:19 -0300 > > Isabella Basso <isabbasso@xxxxxxxxxx> wrote: > > > > > This adds functions for both executing the tests as well as parsing (K)TAP > > > kmsg output, as per the KTAP spec [1]. > > > > > > [1] https://www.kernel.org/doc/html/latest/dev-tools/ktap.html > > > > > > Signed-off-by: Isabella Basso <isabbasso@xxxxxxxxxx> > > > > Hi Isabella, > > > > I'm doing some tests here with my i915 KUnit patch series. > > > > There's a problem with the way it is currently parsing the KTAP logs on > > IGT. It sounds that it is parsing the data only at the end, and not as > > they arrive. That's bad, as if something goes wrong, the previously > > reported data is still useful. > > > > Also, when there's a crash, the IGT process is getting segmentation > > fault. So, the end result is that nothing is actually reported. > > > > $ sudo ./build/tests/i915_selftest > > IGT-Version: 1.26-gbab20eb65 (x86_64) (Linux: 6.1.0-rc2-drm-990037e9984e+ x86_64) > > Segmentation fault (core dumped) > > Another issue related to KTAP parsing: this is the output before > the KUnit patch, which is used by IGT CI to check the test results, for > i915 mock selftest: > > <snip> > IGT-Version: 1.26-gbab20eb65 (x86_64) (Linux: 6.1.0-rc2-drm-8dacd9299fcc+ x86_64) > process 659 (alsactl) is using audio device. Should be terminated. > Starting subtest: mock > Starting dynamic subtest: sanitycheck > Dynamic subtest sanitycheck: SUCCESS (0.648s) > Starting dynamic subtest: shmem > Dynamic subtest shmem: SUCCESS (0.557s) > Starting dynamic subtest: fence > Dynamic subtest fence: SUCCESS (8.078s) > Starting dynamic subtest: scatterlist > Dynamic subtest scatterlist: SUCCESS (1.531s) > Starting dynamic subtest: syncmap > Dynamic subtest syncmap: SUCCESS (2.875s) > Starting dynamic subtest: uncore > Dynamic subtest uncore: SUCCESS (0.525s) > Starting dynamic subtest: ring > Dynamic subtest ring: SUCCESS (0.529s) > Starting dynamic subtest: engine > Dynamic subtest engine: SUCCESS (0.527s) > Starting dynamic subtest: timelines > Dynamic subtest timelines: SUCCESS (4.177s) > Starting dynamic subtest: requests > Dynamic subtest requests: SUCCESS (3.561s) > Starting dynamic subtest: objects > Dynamic subtest objects: SUCCESS (0.596s) > Starting dynamic subtest: phys > Dynamic subtest phys: SUCCESS (0.602s) > Starting dynamic subtest: dmabuf > Dynamic subtest dmabuf: SUCCESS (0.605s) > Starting dynamic subtest: vma > Dynamic subtest vma: SUCCESS (9.724s) > Starting dynamic subtest: evict > Dynamic subtest evict: SUCCESS (1.660s) > Starting dynamic subtest: gtt > Dynamic subtest gtt: SUCCESS (3.309s) > Starting dynamic subtest: hugepages > Dynamic subtest hugepages: SUCCESS (1.665s) > Starting dynamic subtest: memory_region > Dynamic subtest memory_region: SUCCESS (2.789s) > Subtest mock: SUCCESS (43.961s) > </snip> > > This is the logs after your patch: > > <snip> > Missing test version string > Executing 18 tests in: i915 mock selftests > kmsg> 1..18 > kmsg> i915: i915_mock_sanitycheck() - ok! > kmsg> ok 1 - mock_sanitycheck > kmsg> i915: Running shmem_utils_mock_selftests/igt_shmem_basic > kmsg> ok 2 - mock_shmem > kmsg> i915: Running i915_sw_fence_mock_selftests/test_self > kmsg> i915: Running i915_sw_fence_mock_selftests/test_dag > kmsg> i915: Running i915_sw_fence_mock_selftests/test_AB > kmsg> i915: Running i915_sw_fence_mock_selftests/test_ABC > kmsg> i915: Running i915_sw_fence_mock_selftests/test_AB_C > kmsg> i915: Running i915_sw_fence_mock_selftests/test_C_AB > kmsg> i915: Running i915_sw_fence_mock_selftests/test_chain > kmsg> i915: Running i915_sw_fence_mock_selftests/test_ipc > kmsg> i915: Running i915_sw_fence_mock_selftests/test_timer > kmsg> i915: Running i915_sw_fence_mock_selftests/test_dma_fence > kmsg> Asynchronous wait on fence mock:mock:0 timed out (hint:fence_notify [i915]) > kmsg> ok 3 - mock_fence > kmsg> i915: Running scatterlist_mock_selftests/igt_sg_alloc > kmsg> sg_alloc_table timed out > kmsg> i915: Running scatterlist_mock_selftests/igt_sg_trim > kmsg> i915_sg_trim timed out > kmsg> ok 4 - mock_scatterlist > kmsg> i915: Running i915_syncmap_mock_selftests/igt_syncmap_init > kmsg> i915: Running i915_syncmap_mock_selftests/igt_syncmap_one > kmsg> i915: Running i915_syncmap_mock_selftests/igt_syncmap_join_above > kmsg> i915: Running i915_syncmap_mock_selftests/igt_syncmap_join_below > kmsg> i915: Running i915_syncmap_mock_selftests/igt_syncmap_neighbours > kmsg> i915: Running i915_syncmap_mock_selftests/igt_syncmap_compact > kmsg> i915: Running i915_syncmap_mock_selftests/igt_syncmap_random > kmsg> ok 5 - mock_syncmap > kmsg> ok 6 - mock_uncore > kmsg> i915: Running intel_ring_mock_selftests/igt_ring_direction > kmsg> ok 7 - mock_ring > kmsg> i915: Running intel_engine_cs_mock_selftests/intel_mmio_bases_check > kmsg> ok 8 - mock_engine > kmsg> i915: Running intel_timeline_mock_selftests/mock_hwsp_freelist > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running intel_timeline_mock_selftests/igt_sync > kmsg> i915: Running intel_timeline_mock_selftests/bench_sync > kmsg> bench_sync: 44045 random insertions, 2288ns/insert > kmsg> bench_sync: 44045 random lookups, 80ns/lookup > kmsg> bench_sync: 877617 in-order insertions, 114ns/insert > kmsg> bench_sync: 877617 in-order lookups, 3ns/lookup > kmsg> bench_sync: 6357870 repeated insert/lookups, 10ns/op > kmsg> bench_sync: 19942183 cyclic/1 insert/lookups, 5ns/op > kmsg> bench_sync: 19353937 cyclic/2 insert/lookups, 5ns/op > kmsg> bench_sync: 16969941 cyclic/3 insert/lookups, 5ns/op > kmsg> bench_sync: 14438533 cyclic/5 insert/lookups, 6ns/op > kmsg> bench_sync: 13418112 cyclic/8 insert/lookups, 7ns/op > kmsg> bench_sync: 9257200 cyclic/13 insert/lookups, 10ns/op > kmsg> bench_sync: 53636 cyclic/21 insert/lookups, 1877ns/op > kmsg> ok 9 - mock_timelines > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_request_mock_selftests/igt_add_request > kmsg> i915: Running i915_request_mock_selftests/igt_wait_request > kmsg> i915: Running i915_request_mock_selftests/igt_fence_wait > kmsg> i915: Running i915_request_mock_selftests/igt_request_rewind > kmsg> i915: Running i915_request_mock_selftests/mock_breadcrumbs_smoketest > kmsg> Completed 92 waits for 49042 fence across 8 cpus > kmsg> ok 10 - mock_requests > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_gem_object_mock_selftests/igt_gem_object > kmsg> ok 11 - mock_objects > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_gem_phys_mock_selftests/mock_phys_object > kmsg> ok 12 - mock_phys > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_gem_dmabuf_mock_selftests/igt_dmabuf_export > kmsg> i915: Running i915_gem_dmabuf_mock_selftests/igt_dmabuf_import_self > kmsg> i915: Running i915_gem_dmabuf_mock_selftests/igt_dmabuf_import > kmsg> i915: Running i915_gem_dmabuf_mock_selftests/igt_dmabuf_import_ownership > kmsg> i915: Running i915_gem_dmabuf_mock_selftests/igt_dmabuf_export_vmap > kmsg> ok 13 - mock_dmabuf > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_vma_mock_selftests/igt_vma_create > kmsg> igt_vma_create timed out: after 31 objects in 23 contexts > kmsg> i915: Running i915_vma_mock_selftests/igt_vma_pin1 > kmsg> i915: Running i915_vma_mock_selftests/igt_vma_rotate_remap > kmsg> i915: Running i915_vma_mock_selftests/igt_vma_partial > kmsg> ok 14 - mock_vma > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_gem_evict_mock_selftests/igt_evict_something > kmsg> i915: Running i915_gem_evict_mock_selftests/igt_evict_for_vma > kmsg> i915: Running i915_gem_evict_mock_selftests/igt_evict_for_cache_color > kmsg> i915: Running i915_gem_evict_mock_selftests/igt_evict_vm > kmsg> i915: Running i915_gem_evict_mock_selftests/igt_overcommit > kmsg> ok 15 - mock_evict > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_gem_gtt_mock_selftests/igt_mock_drunk > kmsg> drunk_hole timed out after 31635/524288 > kmsg> i915: Running i915_gem_gtt_mock_selftests/igt_mock_walk > kmsg> walk_hole timed out at 812f000 > kmsg> i915: Running i915_gem_gtt_mock_selftests/igt_mock_pot > kmsg> pot_hole timed out after 19/33 > kmsg> i915: Running i915_gem_gtt_mock_selftests/igt_mock_fill > kmsg> fill_hole timed out (npages=1, prime=199) > kmsg> i915: Running i915_gem_gtt_mock_selftests/igt_gtt_reserve > kmsg> i915: Running i915_gem_gtt_mock_selftests/igt_gtt_insert > kmsg> ok 16 - mock_gtt > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running i915_gem_huge_page_mock_selftests/igt_mock_exhaust_device_supported_pages > kmsg> i915: Running i915_gem_huge_page_mock_selftests/igt_mock_memory_region_huge_pages > kmsg> i915: Running i915_gem_huge_page_mock_selftests/igt_mock_ppgtt_misaligned_dma > kmsg> i915: Running i915_gem_huge_page_mock_selftests/igt_mock_ppgtt_huge_fill > kmsg> igt_mock_ppgtt_huge_fill timed out at size 43986944 > kmsg> i915: Running i915_gem_huge_page_mock_selftests/igt_mock_ppgtt_64K > kmsg> ok 17 - mock_hugepages > kmsg> mock: [drm] Using Transparent Hugepages > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - HuC is not supported! > kmsg> mock: [drm] Incompatible option enable_guc=3 - GuC submission is N/A > kmsg> i915: Running intel_memory_region_mock_selftests/igt_mock_reserve > kmsg> i915: Running intel_memory_region_mock_selftests/igt_mock_fill > kmsg> i915: Running intel_memory_region_mock_selftests/igt_mock_contiguous > kmsg> i915: Running intel_memory_region_mock_selftests/igt_mock_splintered_region > kmsg> i915: Running intel_memory_region_mock_selftests/igt_mock_max_segment > kmsg> i915: Running intel_memory_region_mock_selftests/igt_mock_io_size > kmsg> igt_mock_io_size with ps=10000, io_size=10000000, total=cf110000 > kmsg> igt_mock_io_size mappable theft=(0MiB/256MiB), total=3313MiB > kmsg> ok 18 - mock_memory_region > kmsg> # i915 mock selftests: pass:18 fail:0 skip:0 total:18 > kmsg> # Totals: pass:18 fail:0 skip:0 total:18 > kmsg> ok 1 - i915 mock selftests > SUCCESS (29.259s) > </snip> > > Basically, the current output will break CI reports presented at: > https://intel-gfx-ci.01.org/tree/drm-tip/bat-all.html?testfilter=selftest > > The IGT output after your change should be similar to what we had > before, e. g. each test should output SUCCESS/FAIL/SKIP (plus the > final result of all tests at the suite). That should not be done manually though. Only with igt_subtest / igt_dynamic blocks. -- Petri Latvala
