igt@kms_flip@flip-vs-expired-vblank-interruptible@a-hdmi-a1 on shard-snb@CI_DRM

Detail	Value
Duration	1.20 seconds
Hostname	shard-snb5
Igt-Version	IGT-Version: 2.3-ge007dbf29 (x86_64) (Linux: 7.0.0-rc3-CI_DRM_18134-g169ea69ad8f2+ x86_64)
Out	Starting dynamic subtest: A-HDMI-A1 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043() #4 ../tests/kms_flip.c:2043 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A1: FAIL (1.202s)
Err	Starting dynamic subtest: A-HDMI-A1 (kms_flip:2450) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2450) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2450) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-HDMI-A1 failed. ** DEBUG (kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0) (kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=7680) (kms_flip:2450) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0) (kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680) (kms_flip:2450) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2450) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS (kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info (kms_flip:2450) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS (kms_flip:2450) igt_kms-INFO: 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 (kms_flip:2450) DEBUG: No stale events found (kms_flip:2450) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0 (kms_flip:2450) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0 (kms_flip:2450) DEBUG: name = flip last_ts = 0.000000 last_received_ts = 0.000000 last_seq = 0 current_ts = 104.636421 current_received_ts = 104.635902 current_seq = 1840 count = 0 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.636421 last_received_ts = 104.635902 last_seq = 1840 current_ts = 104.653046 current_received_ts = 104.652573 current_seq = 1841 count = 1 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.653046 last_received_ts = 104.652573 last_seq = 1841 current_ts = 104.669670 current_received_ts = 104.669159 current_seq = 1842 count = 2 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 9us (kms_flip:2450) DEBUG: name = flip last_ts = 104.669670 last_received_ts = 104.669159 last_seq = 1842 current_ts = 104.686317 current_received_ts = 104.685844 current_seq = 1843 count = 3 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.686317 last_received_ts = 104.685844 last_seq = 1843 current_ts = 104.702942 current_received_ts = 104.702377 current_seq = 1844 count = 4 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.702942 last_received_ts = 104.702377 last_seq = 1844 current_ts = 104.719582 current_received_ts = 104.719116 current_seq = 1845 count = 5 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 11us (kms_flip:2450) DEBUG: name = flip last_ts = 104.719582 last_received_ts = 104.719116 last_seq = 1845 current_ts = 104.736214 current_received_ts = 104.735687 current_seq = 1846 count = 6 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 9us (kms_flip:2450) DEBUG: name = flip last_ts = 104.736214 last_received_ts = 104.735687 last_seq = 1846 current_ts = 104.752846 current_received_ts = 104.752296 current_seq = 1847 count = 7 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.752846 last_received_ts = 104.752296 last_seq = 1847 current_ts = 104.769478 current_received_ts = 104.769058 current_seq = 1848 count = 8 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.769478 last_received_ts = 104.769058 last_seq = 1848 current_ts = 104.786118 current_received_ts = 104.785606 current_seq = 1849 count = 9 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.786118 last_received_ts = 104.785606 last_seq = 1849 current_ts = 104.802742 current_received_ts = 104.802231 current_seq = 1850 count = 10 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.802742 last_received_ts = 104.802231 last_seq = 1850 current_ts = 104.819382 current_received_ts = 104.818909 current_seq = 1851 count = 11 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.819382 last_received_ts = 104.818909 last_seq = 1851 current_ts = 104.836006 current_received_ts = 104.835487 current_seq = 1852 count = 12 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 9us (kms_flip:2450) DEBUG: name = flip last_ts = 104.836006 last_received_ts = 104.835487 last_seq = 1852 current_ts = 104.852638 current_received_ts = 104.852119 current_seq = 1853 count = 13 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 104.852638 last_received_ts = 104.852119 last_seq = 1853 current_ts = 104.869278 current_received_ts = 104.868797 current_seq = 1854 count = 14 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.869278 last_received_ts = 104.868797 last_seq = 1854 current_ts = 104.885910 current_received_ts = 104.885429 current_seq = 1855 count = 15 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.885910 last_received_ts = 104.885429 last_seq = 1855 current_ts = 104.902542 current_received_ts = 104.902107 current_seq = 1856 count = 16 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 11us (kms_flip:2450) DEBUG: name = flip last_ts = 104.902542 last_received_ts = 104.902107 last_seq = 1856 current_ts = 104.919174 current_received_ts = 104.918686 current_seq = 1857 count = 17 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.919174 last_received_ts = 104.918686 last_seq = 1857 current_ts = 104.935799 current_received_ts = 104.935295 current_seq = 1858 count = 18 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 9us (kms_flip:2450) DEBUG: name = flip last_ts = 104.935799 last_received_ts = 104.935295 last_seq = 1858 current_ts = 104.952446 current_received_ts = 104.951965 current_seq = 1859 count = 19 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 9us (kms_flip:2450) DEBUG: name = flip last_ts = 104.952446 last_received_ts = 104.951965 last_seq = 1859 current_ts = 104.969078 current_received_ts = 104.968536 current_seq = 1860 count = 20 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.969078 last_received_ts = 104.968536 last_seq = 1860 current_ts = 104.985710 current_received_ts = 104.985199 current_seq = 1861 count = 21 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 104.985710 last_received_ts = 104.985199 last_seq = 1861 current_ts = 105.002342 current_received_ts = 105.001854 current_seq = 1862 count = 22 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 9us (kms_flip:2450) DEBUG: name = flip last_ts = 105.002342 last_received_ts = 105.001854 last_seq = 1862 current_ts = 105.018967 current_received_ts = 105.018494 current_seq = 1863 count = 23 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.018967 last_received_ts = 105.018494 last_seq = 1863 current_ts = 105.035606 current_received_ts = 105.035103 current_seq = 1864 count = 24 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.035606 last_received_ts = 105.035103 last_seq = 1864 current_ts = 105.052238 current_received_ts = 105.051727 current_seq = 1865 count = 25 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.052238 last_received_ts = 105.051727 last_seq = 1865 current_ts = 105.068871 current_received_ts = 105.068398 current_seq = 1866 count = 26 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.068871 last_received_ts = 105.068398 last_seq = 1866 current_ts = 105.085503 current_received_ts = 105.084969 current_seq = 1867 count = 27 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 30us (kms_flip:2450) DEBUG: name = flip last_ts = 105.085503 last_received_ts = 105.084969 last_seq = 1867 current_ts = 105.102127 current_received_ts = 105.101624 current_seq = 1868 count = 28 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.102127 last_received_ts = 105.101624 last_seq = 1868 current_ts = 105.118759 current_received_ts = 105.118256 current_seq = 1869 count = 29 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.118759 last_received_ts = 105.118256 last_seq = 1869 current_ts = 105.135406 current_received_ts = 105.134895 current_seq = 1870 count = 30 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.135406 last_received_ts = 105.134895 last_seq = 1870 current_ts = 105.152039 current_received_ts = 105.151520 current_seq = 1871 count = 31 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.152039 last_received_ts = 105.151520 last_seq = 1871 current_ts = 105.168663 current_received_ts = 105.168129 current_seq = 1872 count = 32 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.168663 last_received_ts = 105.168129 last_seq = 1872 current_ts = 105.185303 current_received_ts = 105.184784 current_seq = 1873 count = 33 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.185303 last_received_ts = 105.184784 last_seq = 1873 current_ts = 105.201927 current_received_ts = 105.201416 current_seq = 1874 count = 34 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.201927 last_received_ts = 105.201416 last_seq = 1874 current_ts = 105.218567 current_received_ts = 105.218071 current_seq = 1875 count = 35 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.218567 last_received_ts = 105.218071 last_seq = 1875 current_ts = 105.235199 current_received_ts = 105.234642 current_seq = 1876 count = 36 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.235199 last_received_ts = 105.234642 last_seq = 1876 current_ts = 105.251831 current_received_ts = 105.251305 current_seq = 1877 count = 37 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.251831 last_received_ts = 105.251305 last_seq = 1877 current_ts = 105.268471 current_received_ts = 105.267960 current_seq = 1878 count = 38 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.268471 last_received_ts = 105.267960 last_seq = 1878 current_ts = 105.285095 current_received_ts = 105.284584 current_seq = 1879 count = 39 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.285095 last_received_ts = 105.284584 last_seq = 1879 current_ts = 105.301735 current_received_ts = 105.301216 current_seq = 1880 count = 40 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.301735 last_received_ts = 105.301216 last_seq = 1880 current_ts = 105.318359 current_received_ts = 105.317795 current_seq = 1881 count = 41 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.318359 last_received_ts = 105.317795 last_seq = 1881 current_ts = 105.334991 current_received_ts = 105.334435 current_seq = 1882 count = 42 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.334991 last_received_ts = 105.334435 last_seq = 1882 current_ts = 105.351631 current_received_ts = 105.351158 current_seq = 1883 count = 43 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.351631 last_received_ts = 105.351158 last_seq = 1883 current_ts = 105.368263 current_received_ts = 105.367744 current_seq = 1884 count = 44 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.368263 last_received_ts = 105.367744 last_seq = 1884 current_ts = 105.384895 current_received_ts = 105.384377 current_seq = 1885 count = 45 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.384895 last_received_ts = 105.384377 last_seq = 1885 current_ts = 105.401527 current_received_ts = 105.400963 current_seq = 1886 count = 46 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.401527 last_received_ts = 105.400963 last_seq = 1886 current_ts = 105.418159 current_received_ts = 105.417641 current_seq = 1887 count = 47 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.418159 last_received_ts = 105.417641 last_seq = 1887 current_ts = 105.434799 current_received_ts = 105.434258 current_seq = 1888 count = 48 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.434799 last_received_ts = 105.434258 last_seq = 1888 current_ts = 105.451424 current_received_ts = 105.450912 current_seq = 1889 count = 49 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.451424 last_received_ts = 105.450912 last_seq = 1889 current_ts = 105.468063 current_received_ts = 105.467522 current_seq = 1890 count = 50 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.468063 last_received_ts = 105.467522 last_seq = 1890 current_ts = 105.484688 current_received_ts = 105.484093 current_seq = 1891 count = 51 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.484688 last_received_ts = 105.484093 last_seq = 1891 current_ts = 105.501328 current_received_ts = 105.500816 current_seq = 1892 count = 52 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.501328 last_received_ts = 105.500816 last_seq = 1892 current_ts = 105.517960 current_received_ts = 105.517403 current_seq = 1893 count = 53 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.517960 last_received_ts = 105.517403 last_seq = 1893 current_ts = 105.534584 current_received_ts = 105.533989 current_seq = 1894 count = 54 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 7us (kms_flip:2450) DEBUG: name = flip last_ts = 105.534584 last_received_ts = 105.533989 last_seq = 1894 current_ts = 105.551216 current_received_ts = 105.550766 current_seq = 1895 count = 55 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.551216 last_received_ts = 105.550766 last_seq = 1895 current_ts = 105.567848 current_received_ts = 105.567352 current_seq = 1896 count = 56 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 8us (kms_flip:2450) DEBUG: name = flip last_ts = 105.567848 last_received_ts = 105.567352 last_seq = 1896 current_ts = 105.584488 current_received_ts = 105.584045 current_seq = 1897 count = 57 seq_step = 1 (kms_flip:2450) DEBUG: Vblank took 567us (kms_flip:2450) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2450) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2450) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2450) igt_core-INFO: Stack trace: (kms_flip:2450) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2450) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:2450) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:2450) igt_core-INFO: #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043() (kms_flip:2450) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:2450) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2450) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2450) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A1: FAIL (1.202s)
Dmesg	<6> [104.440021] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1 <7> [104.441026] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:87] <7> [104.441389] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90] <7> [104.474149] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A] <7> [104.474537] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:71:pipe B] <7> [104.474722] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.enable (expected yes, found no) <7> [104.475315] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.active (expected yes, found no) <7> [104.475835] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1) <7> [104.476249] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in has_pch_encoder (expected yes, found no) <7> [104.476664] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in fdi_lanes (expected 1, found 0) <7> [104.477114] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0) <7> [104.477564] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in output_types (expected 0x00000002, found 0x00000000) <7> [104.477810] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [104.478043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1024, found 0) <7> [104.478303] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 1344, found 0) <7> [104.478547] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1024, found 0) <7> [104.478779] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 1344, found 0) <7> [104.479012] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1048, found 0) <7> [104.479243] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 1184, found 0) <7> [104.479491] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 768, found 0) <7> [104.479724] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 768, found 0) <7> [104.479955] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 771, found 0) <7> [104.480187] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 777, found 0) <7> [104.480437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 806, found 0) <7> [104.480669] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 806, found 0) <7> [104.480901] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1024, found 0) <7> [104.481133] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 1344, found 0) <7> [104.481394] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1024, found 0) <7> [104.481627] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 1344, found 0) <7> [104.481859] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1048, found 0) <7> [104.482091] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 1184, found 0) <7> [104.482336] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 768, found 0) <7> [104.482569] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 768, found 0) <7> [104.482801] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 771, found 0) <7> [104.483032] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 777, found 0) <7> [104.483264] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 806, found 0) <7> [104.483512] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 806, found 0) <7> [104.483745] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [104.483977] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [104.484209] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [104.484452] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [104.484685] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 64800, found 0) <7> [104.484917] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 64800, found 0) <7> [104.485149] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in port_clock (expected 64800, found 0) <7> [104.485432] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:71:pipe B] fastset requirement not met, forcing full modeset <7> [104.485674] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:71:pipe B] releasing PCH DPLL A <7> [104.485941] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:71:pipe B] min cdclk: 72000 kHz -> 0 kHz <7> [104.486177] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:71:pipe B] enable: no [modeset] <7> [104.486419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:primary B] fb: [NOFB], visible: no <7> [104.486847] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B <7> [104.489833] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found <7> [104.490060] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found <7> [104.490298] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found <7> [104.505798] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:71:pipe B] <7> [104.506330] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A <7> [104.507036] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT] <7> [104.507538] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D] <7> [104.508214] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D] <7> [104.508669] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:72:VGA-1] <7> [104.509230] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:71:pipe B] <7> [104.510119] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A] <7> [104.510149] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:75:HDMI-A-1] <7> [104.510249] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [104.510524] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [104.510863] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3 <7> [104.511209] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [104.511488] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [104.511731] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [104.511972] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes) <7> [104.512312] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3) <7> [104.512645] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288) <7> [104.512881] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [104.513121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [104.513470] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [104.513773] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [104.514007] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [104.514249] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [104.514625] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [104.514870] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [104.515103] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [104.515473] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [104.515727] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [104.515960] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [104.516239] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [104.516608] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [104.516901] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [104.517143] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [104.517437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [104.517705] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [104.518040] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [104.518330] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [104.518567] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [104.518859] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [104.519162] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [104.519437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [104.519681] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [104.520024] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [104.520304] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [104.520547] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [104.520805] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [104.521137] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [104.521418] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [104.521662] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [104.521925] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in dpll_hw_state <7> [104.522307] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [104.522552] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09 <7> [104.522779] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [104.523005] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [104.523326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [104.523646] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800) <7> [104.523874] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800) <7> [104.524101] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in port_clock (expected 0, found 223200) <7> [104.524463] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [104.524712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [104.524939] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in avi infoframe <7> [104.525220] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [104.525589] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [104.525851] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [104.525854] i915 0000:00:02.0: colorspace: RGB <7> [104.525857] i915 0000:00:02.0: scan mode: Underscan <7> [104.525859] i915 0000:00:02.0: colorimetry: No Data <7> [104.525868] i915 0000:00:02.0: picture aspect: 16:9 <7> [104.525870] i915 0000:00:02.0: active aspect: Same as Picture <7> [104.525872] i915 0000:00:02.0: itc: No Data <7> [104.525874] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [104.525876] i915 0000:00:02.0: quantization range: Default <7> [104.525878] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [104.525880] i915 0000:00:02.0: video code: 16 <7> [104.525882] i915 0000:00:02.0: ycc quantization range: Full <7> [104.525883] i915 0000:00:02.0: hdmi content type: Graphics <7> [104.525885] i915 0000:00:02.0: pixel repeat: 0 <7> [104.525887] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [104.525890] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in spd infoframe <7> [104.526121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [104.526505] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [104.526855] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [104.526860] i915 0000:00:02.0: vendor: Intel <7> [104.526864] i915 0000:00:02.0: product: Integrated gfx <7> [104.526867] i915 0000:00:02.0: source device information: PC General (0x9) <7> [104.526871] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hdmi infoframe <7> [104.527119] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [104.527412] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [104.527448] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on <7> [104.527657] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [104.527659] i915 0000:00:02.0: empty frame <7> [104.527661] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] fastset requirement not met, forcing full modeset <7> [104.527933] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:52:pipe A] min cdclk: 0 kHz -> 165334 kHz <7> [104.528300] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:52:pipe A] allocated PCH DPLL A <7> [104.528632] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:52:pipe A] reserving PCH DPLL A <7> [104.528869] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:52:pipe A] enable: yes [modeset] <7> [104.529096] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [104.529471] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0 <7> [104.529745] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [104.529971] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [104.530343] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [104.530616] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [104.530842] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64 <7> [104.531139] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [104.531501] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6 <7> [104.531761] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [104.531763] i915 0000:00:02.0: colorspace: RGB <7> [104.531765] i915 0000:00:02.0: scan mode: Underscan <7> [104.531767] i915 0000:00:02.0: colorimetry: No Data <7> [104.531769] i915 0000:00:02.0: picture aspect: 16:9 <7> [104.531771] i915 0000:00:02.0: active aspect: Same as Picture <7> [104.531773] i915 0000:00:02.0: itc: No Data <7> [104.531775] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [104.531777] i915 0000:00:02.0: quantization range: Default <7> [104.531778] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [104.531780] i915 0000:00:02.0: video code: 16 <7> [104.531782] i915 0000:00:02.0: ycc quantization range: Full <7> [104.531784] i915 0000:00:02.0: hdmi content type: Graphics <7> [104.531786] i915 0000:00:02.0: pixel repeat: 0 <7> [104.531788] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [104.531790] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [104.531792] i915 0000:00:02.0: vendor: Intel <7> [104.531794] i915 0000:00:02.0: product: Integrated gfx <7> [104.531796] i915 0000:00:02.0: source device information: PC General (0x9) <7> [104.531798] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [104.531800] i915 0000:00:02.0: empty frame <7> [104.531802] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00 <7> [104.532029] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51 <7> [104.532341] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00 <7> [104.532686] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1 <7> [104.533030] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [104.533364] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0 <7> [104.533627] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0 <7> [104.533903] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [104.534249] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [104.534542] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [104.534788] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [104.535030] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 <7> [104.535405] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [104.535683] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pipe src: 1920x1080+0+0, pixel rate 148800, min cdclk 165334 <7> [104.535919] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0 <7> [104.536259] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [104.536549] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [104.536800] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06 <7> [104.537134] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [104.537447] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [104.537716] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [104.538056] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [104.538306] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [104.538556] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [104.538898] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [104.539136] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:primary A] fb: [FB:87] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [104.539406] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [104.539740] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [104.542163] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on <7> [104.542508] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT] <7> [104.542849] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D] <7> [104.543126] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D] <7> [104.544066] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A <7> [104.545177] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100 <7> [104.545486] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done. <7> [104.546445] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x600 <7> [104.546688] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done. <7> [104.546916] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done. <7> [104.547235] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:52:pipe A] <7> [104.547561] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A <7> [104.599327] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:75:HDMI-A-1][ENCODER:74:HDMI D] Enable audio codec on [CRTC:52:pipe A], 36 bytes ELD <7> [104.615904] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults <7> [104.616369] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000) <7> [104.616816] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:75:HDMI-A-1] <7> [104.617297] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:52:pipe A] <6> [105.642665] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL

Detail

Value

Duration

1.20 seconds

Hostname

shard-snb5

Igt-Version

IGT-Version: 2.3-ge007dbf29 (x86_64) (Linux: 7.0.0-rc3-CI_DRM_18134-g169ea69ad8f2+ x86_64)

Out

Starting dynamic subtest: A-HDMI-A1
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A1: FAIL (1.202s)

Err

Starting dynamic subtest: A-HDMI-A1
(kms_flip:2450) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2450) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2450) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0)
(kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=7680)
(kms_flip:2450) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000001, size=0)
(kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2450) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2450) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680)
(kms_flip:2450) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2450) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2450) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2450) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_flip:2450) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
(kms_flip:2450) DEBUG: No stale events found
(kms_flip:2450) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2450) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2450) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 104.636421
current_received_ts = 104.635902
current_seq = 1840
count = 0
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.636421
last_received_ts = 104.635902
last_seq = 1840
current_ts = 104.653046
current_received_ts = 104.652573
current_seq = 1841
count = 1
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.653046
last_received_ts = 104.652573
last_seq = 1841
current_ts = 104.669670
current_received_ts = 104.669159
current_seq = 1842
count = 2
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 9us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.669670
last_received_ts = 104.669159
last_seq = 1842
current_ts = 104.686317
current_received_ts = 104.685844
current_seq = 1843
count = 3
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.686317
last_received_ts = 104.685844
last_seq = 1843
current_ts = 104.702942
current_received_ts = 104.702377
current_seq = 1844
count = 4
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.702942
last_received_ts = 104.702377
last_seq = 1844
current_ts = 104.719582
current_received_ts = 104.719116
current_seq = 1845
count = 5
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 11us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.719582
last_received_ts = 104.719116
last_seq = 1845
current_ts = 104.736214
current_received_ts = 104.735687
current_seq = 1846
count = 6
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 9us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.736214
last_received_ts = 104.735687
last_seq = 1846
current_ts = 104.752846
current_received_ts = 104.752296
current_seq = 1847
count = 7
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.752846
last_received_ts = 104.752296
last_seq = 1847
current_ts = 104.769478
current_received_ts = 104.769058
current_seq = 1848
count = 8
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.769478
last_received_ts = 104.769058
last_seq = 1848
current_ts = 104.786118
current_received_ts = 104.785606
current_seq = 1849
count = 9
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.786118
last_received_ts = 104.785606
last_seq = 1849
current_ts = 104.802742
current_received_ts = 104.802231
current_seq = 1850
count = 10
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.802742
last_received_ts = 104.802231
last_seq = 1850
current_ts = 104.819382
current_received_ts = 104.818909
current_seq = 1851
count = 11
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.819382
last_received_ts = 104.818909
last_seq = 1851
current_ts = 104.836006
current_received_ts = 104.835487
current_seq = 1852
count = 12
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 9us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.836006
last_received_ts = 104.835487
last_seq = 1852
current_ts = 104.852638
current_received_ts = 104.852119
current_seq = 1853
count = 13
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.852638
last_received_ts = 104.852119
last_seq = 1853
current_ts = 104.869278
current_received_ts = 104.868797
current_seq = 1854
count = 14
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.869278
last_received_ts = 104.868797
last_seq = 1854
current_ts = 104.885910
current_received_ts = 104.885429
current_seq = 1855
count = 15
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.885910
last_received_ts = 104.885429
last_seq = 1855
current_ts = 104.902542
current_received_ts = 104.902107
current_seq = 1856
count = 16
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 11us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.902542
last_received_ts = 104.902107
last_seq = 1856
current_ts = 104.919174
current_received_ts = 104.918686
current_seq = 1857
count = 17
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.919174
last_received_ts = 104.918686
last_seq = 1857
current_ts = 104.935799
current_received_ts = 104.935295
current_seq = 1858
count = 18
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 9us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.935799
last_received_ts = 104.935295
last_seq = 1858
current_ts = 104.952446
current_received_ts = 104.951965
current_seq = 1859
count = 19
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 9us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.952446
last_received_ts = 104.951965
last_seq = 1859
current_ts = 104.969078
current_received_ts = 104.968536
current_seq = 1860
count = 20
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.969078
last_received_ts = 104.968536
last_seq = 1860
current_ts = 104.985710
current_received_ts = 104.985199
current_seq = 1861
count = 21
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 104.985710
last_received_ts = 104.985199
last_seq = 1861
current_ts = 105.002342
current_received_ts = 105.001854
current_seq = 1862
count = 22
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 9us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.002342
last_received_ts = 105.001854
last_seq = 1862
current_ts = 105.018967
current_received_ts = 105.018494
current_seq = 1863
count = 23
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.018967
last_received_ts = 105.018494
last_seq = 1863
current_ts = 105.035606
current_received_ts = 105.035103
current_seq = 1864
count = 24
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.035606
last_received_ts = 105.035103
last_seq = 1864
current_ts = 105.052238
current_received_ts = 105.051727
current_seq = 1865
count = 25
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.052238
last_received_ts = 105.051727
last_seq = 1865
current_ts = 105.068871
current_received_ts = 105.068398
current_seq = 1866
count = 26
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.068871
last_received_ts = 105.068398
last_seq = 1866
current_ts = 105.085503
current_received_ts = 105.084969
current_seq = 1867
count = 27
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 30us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.085503
last_received_ts = 105.084969
last_seq = 1867
current_ts = 105.102127
current_received_ts = 105.101624
current_seq = 1868
count = 28
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.102127
last_received_ts = 105.101624
last_seq = 1868
current_ts = 105.118759
current_received_ts = 105.118256
current_seq = 1869
count = 29
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.118759
last_received_ts = 105.118256
last_seq = 1869
current_ts = 105.135406
current_received_ts = 105.134895
current_seq = 1870
count = 30
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.135406
last_received_ts = 105.134895
last_seq = 1870
current_ts = 105.152039
current_received_ts = 105.151520
current_seq = 1871
count = 31
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.152039
last_received_ts = 105.151520
last_seq = 1871
current_ts = 105.168663
current_received_ts = 105.168129
current_seq = 1872
count = 32
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.168663
last_received_ts = 105.168129
last_seq = 1872
current_ts = 105.185303
current_received_ts = 105.184784
current_seq = 1873
count = 33
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.185303
last_received_ts = 105.184784
last_seq = 1873
current_ts = 105.201927
current_received_ts = 105.201416
current_seq = 1874
count = 34
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.201927
last_received_ts = 105.201416
last_seq = 1874
current_ts = 105.218567
current_received_ts = 105.218071
current_seq = 1875
count = 35
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.218567
last_received_ts = 105.218071
last_seq = 1875
current_ts = 105.235199
current_received_ts = 105.234642
current_seq = 1876
count = 36
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.235199
last_received_ts = 105.234642
last_seq = 1876
current_ts = 105.251831
current_received_ts = 105.251305
current_seq = 1877
count = 37
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.251831
last_received_ts = 105.251305
last_seq = 1877
current_ts = 105.268471
current_received_ts = 105.267960
current_seq = 1878
count = 38
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.268471
last_received_ts = 105.267960
last_seq = 1878
current_ts = 105.285095
current_received_ts = 105.284584
current_seq = 1879
count = 39
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.285095
last_received_ts = 105.284584
last_seq = 1879
current_ts = 105.301735
current_received_ts = 105.301216
current_seq = 1880
count = 40
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.301735
last_received_ts = 105.301216
last_seq = 1880
current_ts = 105.318359
current_received_ts = 105.317795
current_seq = 1881
count = 41
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.318359
last_received_ts = 105.317795
last_seq = 1881
current_ts = 105.334991
current_received_ts = 105.334435
current_seq = 1882
count = 42
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.334991
last_received_ts = 105.334435
last_seq = 1882
current_ts = 105.351631
current_received_ts = 105.351158
current_seq = 1883
count = 43
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.351631
last_received_ts = 105.351158
last_seq = 1883
current_ts = 105.368263
current_received_ts = 105.367744
current_seq = 1884
count = 44
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.368263
last_received_ts = 105.367744
last_seq = 1884
current_ts = 105.384895
current_received_ts = 105.384377
current_seq = 1885
count = 45
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.384895
last_received_ts = 105.384377
last_seq = 1885
current_ts = 105.401527
current_received_ts = 105.400963
current_seq = 1886
count = 46
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.401527
last_received_ts = 105.400963
last_seq = 1886
current_ts = 105.418159
current_received_ts = 105.417641
current_seq = 1887
count = 47
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.418159
last_received_ts = 105.417641
last_seq = 1887
current_ts = 105.434799
current_received_ts = 105.434258
current_seq = 1888
count = 48
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.434799
last_received_ts = 105.434258
last_seq = 1888
current_ts = 105.451424
current_received_ts = 105.450912
current_seq = 1889
count = 49
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.451424
last_received_ts = 105.450912
last_seq = 1889
current_ts = 105.468063
current_received_ts = 105.467522
current_seq = 1890
count = 50
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.468063
last_received_ts = 105.467522
last_seq = 1890
current_ts = 105.484688
current_received_ts = 105.484093
current_seq = 1891
count = 51
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.484688
last_received_ts = 105.484093
last_seq = 1891
current_ts = 105.501328
current_received_ts = 105.500816
current_seq = 1892
count = 52
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.501328
last_received_ts = 105.500816
last_seq = 1892
current_ts = 105.517960
current_received_ts = 105.517403
current_seq = 1893
count = 53
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.517960
last_received_ts = 105.517403
last_seq = 1893
current_ts = 105.534584
current_received_ts = 105.533989
current_seq = 1894
count = 54
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 7us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.534584
last_received_ts = 105.533989
last_seq = 1894
current_ts = 105.551216
current_received_ts = 105.550766
current_seq = 1895
count = 55
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.551216
last_received_ts = 105.550766
last_seq = 1895
current_ts = 105.567848
current_received_ts = 105.567352
current_seq = 1896
count = 56
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 8us
(kms_flip:2450) DEBUG: name = flip
last_ts = 105.567848
last_received_ts = 105.567352
last_seq = 1896
current_ts = 105.584488
current_received_ts = 105.584045
current_seq = 1897
count = 57
seq_step = 1
(kms_flip:2450) DEBUG: Vblank took 567us
(kms_flip:2450) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2450) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2450) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2450) igt_core-INFO: Stack trace:
(kms_flip:2450) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2450) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:2450) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:2450) igt_core-INFO:   #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
(kms_flip:2450) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:2450) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2450) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2450) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A1: FAIL (1.202s)

Dmesg

<6> [104.440021] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1

<7> [104.441026] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:87]

<7> [104.441389] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:90]

<7> [104.474149] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A]

<7> [104.474537] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:71:pipe B]

<7> [104.474722] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.enable (expected yes, found no)

<7> [104.475315] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.active (expected yes, found no)

<7> [104.475835] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)

<7> [104.476249] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in has_pch_encoder (expected yes, found no)

<7> [104.476664] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in fdi_lanes (expected 1, found 0)

<7> [104.477114] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0)

<7> [104.477564] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in output_types (expected 0x00000002, found 0x00000000)

<7> [104.477810] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)

<7> [104.478043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1024, found 0)

<7> [104.478303] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 1344, found 0)

<7> [104.478547] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1024, found 0)

<7> [104.478779] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 1344, found 0)

<7> [104.479012] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1048, found 0)

<7> [104.479243] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 1184, found 0)

<7> [104.479491] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 768, found 0)

<7> [104.479724] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 768, found 0)

<7> [104.479955] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 771, found 0)

<7> [104.480187] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 777, found 0)

<7> [104.480437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 806, found 0)

<7> [104.480669] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 806, found 0)

<7> [104.480901] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1024, found 0)

<7> [104.481133] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 1344, found 0)

<7> [104.481394] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1024, found 0)

<7> [104.481627] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 1344, found 0)

<7> [104.481859] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1048, found 0)

<7> [104.482091] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 1184, found 0)

<7> [104.482336] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 768, found 0)

<7> [104.482569] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 768, found 0)

<7> [104.482801] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 771, found 0)

<7> [104.483032] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 777, found 0)

<7> [104.483264] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 806, found 0)

<7> [104.483512] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 806, found 0)

<7> [104.483745] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)

<7> [104.483977] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)

<7> [104.484209] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)

<7> [104.484452] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)

<7> [104.484685] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 64800, found 0)

<7> [104.484917] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 64800, found 0)

<7> [104.485149] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:71:pipe B] fastset requirement not met in port_clock (expected 64800, found 0)

<7> [104.485432] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:71:pipe B] fastset requirement not met, forcing full modeset

<7> [104.485674] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:71:pipe B] releasing PCH DPLL A

<7> [104.485941] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:71:pipe B] min cdclk: 72000 kHz -> 0 kHz

<7> [104.486177] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:71:pipe B] enable: no [modeset]

<7> [104.486419] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:53:primary B] fb: [NOFB], visible: no

<7> [104.486847] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B

<7> [104.489833] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found

<7> [104.490060] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found

<7> [104.490298] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found

<7> [104.505798] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:71:pipe B]

<7> [104.506330] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A

<7> [104.507036] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT]

<7> [104.507538] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D]

<7> [104.508214] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D]

<7> [104.508669] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:72:VGA-1]

<7> [104.509230] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:71:pipe B]

<7> [104.510119] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:52:pipe A]

<7> [104.510149] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:75:HDMI-A-1]

<7> [104.510249] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)

<7> [104.510524] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0

<7> [104.510863] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3

<7> [104.511209] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.enable (expected no, found yes)

<7> [104.511488] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.active (expected no, found yes)

<7> [104.511731] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)

<7> [104.511972] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes)

<7> [104.512312] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3)

<7> [104.512645] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288)

<7> [104.512881] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in lane_count (expected 0, found 4)

<7> [104.513121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)

<7> [104.513470] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)

<7> [104.513773] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)

<7> [104.514007] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)

<7> [104.514249] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)

<7> [104.514625] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)

<7> [104.514870] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)

<7> [104.515103] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)

<7> [104.515473] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)

<7> [104.515727] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)

<7> [104.515960] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)

<7> [104.516239] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)

<7> [104.516608] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)

<7> [104.516901] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)

<7> [104.517143] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)

<7> [104.517437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)

<7> [104.517705] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)

<7> [104.518040] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)

<7> [104.518330] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)

<7> [104.518567] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)

<7> [104.518859] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)

<7> [104.519162] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)

<7> [104.519437] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)

<7> [104.519681] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)

<7> [104.520024] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)

<7> [104.520304] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)

<7> [104.520547] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)

<7> [104.520805] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)

<7> [104.521137] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)

<7> [104.521418] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)

<7> [104.521662] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)

<7> [104.521925] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in dpll_hw_state

<7> [104.522307] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [104.522552] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09

<7> [104.522779] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [104.523005] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06

<7> [104.523326] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)

<7> [104.523646] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800)

<7> [104.523874] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800)

<7> [104.524101] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in port_clock (expected 0, found 223200)

<7> [104.524463] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)

<7> [104.524712] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)

<7> [104.524939] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in avi infoframe

<7> [104.525220] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [104.525589] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [104.525851] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13

<7> [104.525854] i915 0000:00:02.0: colorspace: RGB

<7> [104.525857] i915 0000:00:02.0: scan mode: Underscan

<7> [104.525859] i915 0000:00:02.0: colorimetry: No Data

<7> [104.525868] i915 0000:00:02.0: picture aspect: 16:9

<7> [104.525870] i915 0000:00:02.0: active aspect: Same as Picture

<7> [104.525872] i915 0000:00:02.0: itc: No Data

<7> [104.525874] i915 0000:00:02.0: extended colorimetry: xvYCC 601

<7> [104.525876] i915 0000:00:02.0: quantization range: Default

<7> [104.525878] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling

<7> [104.525880] i915 0000:00:02.0: video code: 16

<7> [104.525882] i915 0000:00:02.0: ycc quantization range: Full

<7> [104.525883] i915 0000:00:02.0: hdmi content type: Graphics

<7> [104.525885] i915 0000:00:02.0: pixel repeat: 0

<7> [104.525887] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0

<7> [104.525890] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in spd infoframe

<7> [104.526121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [104.526505] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [104.526855] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25

<7> [104.526860] i915 0000:00:02.0: vendor: Intel

<7> [104.526864] i915 0000:00:02.0: product: Integrated gfx

<7> [104.526867] i915 0000:00:02.0: source device information: PC General (0x9)

<7> [104.526871] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:52:pipe A] fastset requirement not met in hdmi infoframe

<7> [104.527119] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:

<7> [104.527412] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:

<7> [104.527448] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on

<7> [104.527657] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4

<7> [104.527659] i915 0000:00:02.0: empty frame

<7> [104.527661] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:52:pipe A] fastset requirement not met, forcing full modeset

<7> [104.527933] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:52:pipe A] min cdclk: 0 kHz -> 165334 kHz

<7> [104.528300] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:52:pipe A] allocated PCH DPLL A

<7> [104.528632] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:52:pipe A] reserving PCH DPLL A

<7> [104.528869] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:52:pipe A] enable: yes [modeset]

<7> [104.529096] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB

<7> [104.529471] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0

<7> [104.529745] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>

<7> [104.529971] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0

<7> [104.530343] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0

<7> [104.530616] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0

<7> [104.530842] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64

<7> [104.531139] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71

<7> [104.531501] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6

<7> [104.531761] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13

<7> [104.531763] i915 0000:00:02.0: colorspace: RGB

<7> [104.531765] i915 0000:00:02.0: scan mode: Underscan

<7> [104.531767] i915 0000:00:02.0: colorimetry: No Data

<7> [104.531769] i915 0000:00:02.0: picture aspect: 16:9

<7> [104.531771] i915 0000:00:02.0: active aspect: Same as Picture

<7> [104.531773] i915 0000:00:02.0: itc: No Data

<7> [104.531775] i915 0000:00:02.0: extended colorimetry: xvYCC 601

<7> [104.531777] i915 0000:00:02.0: quantization range: Default

<7> [104.531778] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling

<7> [104.531780] i915 0000:00:02.0: video code: 16

<7> [104.531782] i915 0000:00:02.0: ycc quantization range: Full

<7> [104.531784] i915 0000:00:02.0: hdmi content type: Graphics

<7> [104.531786] i915 0000:00:02.0: pixel repeat: 0

<7> [104.531788] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0

<7> [104.531790] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25

<7> [104.531792] i915 0000:00:02.0: vendor: Intel

<7> [104.531794] i915 0000:00:02.0: product: Integrated gfx

<7> [104.531796] i915 0000:00:02.0: source device information: PC General (0x9)

<7> [104.531798] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4

<7> [104.531800] i915 0000:00:02.0: empty frame

<7> [104.531802] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00

<7> [104.532029] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51

<7> [104.532341] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00

<7> [104.532686] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1

<7> [104.533030] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0

<7> [104.533364] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0

<7> [104.533627] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0

<7> [104.533903] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0

<7> [104.534249] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [104.534542] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [104.534788] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [104.535030] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5

<7> [104.535405] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [104.535683] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pipe src: 1920x1080+0+0, pixel rate 148800, min cdclk 165334

<7> [104.535919] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0

<7> [104.536259] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no

<7> [104.536549] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0

<7> [104.536800] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06

<7> [104.537134] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

<7> [104.537447] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries

<7> [104.537716] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000

<7> [104.538056] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [104.538306] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [104.538556] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [104.538898] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0

<7> [104.539136] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:primary A] fb: [FB:87] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes

<7> [104.539406] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0

<7> [104.539740] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0

<7> [104.542163] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on

<7> [104.542508] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:73:CRT]

<7> [104.542849] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:74:HDMI D]

<7> [104.543126] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:82:DP D]

<7> [104.544066] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A

<7> [104.545177] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100

<7> [104.545486] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done.

<7> [104.546445] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x600

<7> [104.546688] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done.

<7> [104.546916] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done.

<7> [104.547235] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:52:pipe A]

<7> [104.547561] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A

<7> [104.599327] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:75:HDMI-A-1][ENCODER:74:HDMI D] Enable audio codec on [CRTC:52:pipe A], 36 bytes ELD

<7> [104.615904] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults

<7> [104.616369] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000)

<7> [104.616816] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:75:HDMI-A-1]

<7> [104.617297] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:52:pipe A]

<6> [105.642665] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL

Results for igt@kms_flip@flip-vs-expired-vblank-interruptible@a-hdmi-a1