igt@kms_flip@flip-vs-expired-vblank-interruptible@c-hdmi-a1 on shard-tglu@Patchwork

Detail	Value
Duration	6.93 seconds
Hostname	shard-tglu-9
Igt-Version	IGT-Version: 2.4-g65d691069 (x86_64) (Linux: 7.1.0-rc4-Patchwork_166770v2-gf05be6b98588+ x86_64)
Out	Starting dynamic subtest: C-HDMI-A1 1920x1080: 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2074 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest C-HDMI-A1: FAIL (6.931s)
Err	Starting dynamic subtest: C-HDMI-A1 [91.119918] (kms_flip:2102) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: [91.119971] (kms_flip:2102) CRITICAL: Failed assertion: end - start < 500 [91.120021] (kms_flip:2102) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest C-HDMI-A1 failed. ** DEBUG [90.110608] (kms_flip:2102) DEBUG: Vblank took 20us [90.119017] (kms_flip:2102) DEBUG: name = flip last_ts = 90.225906 last_received_ts = 90.225494 last_seq = 688 current_ts = 90.234238 current_received_ts = 90.233894 current_seq = 689 count = 683 seq_step = 1 [90.119061] (kms_flip:2102) DEBUG: Vblank took 31us [90.127338] (kms_flip:2102) DEBUG: name = flip last_ts = 90.234238 last_received_ts = 90.233894 last_seq = 689 current_ts = 90.242569 current_received_ts = 90.242249 current_seq = 690 count = 684 seq_step = 1 [90.127370] (kms_flip:2102) DEBUG: Vblank took 24us [90.135610] (kms_flip:2102) DEBUG: name = flip last_ts = 90.242569 last_received_ts = 90.242249 last_seq = 690 current_ts = 90.250908 current_received_ts = 90.250519 current_seq = 691 count = 685 seq_step = 1 [90.135640] (kms_flip:2102) DEBUG: Vblank took 22us [90.143996] (kms_flip:2102) DEBUG: name = flip last_ts = 90.250908 last_received_ts = 90.250519 last_seq = 691 current_ts = 90.259239 current_received_ts = 90.258896 current_seq = 692 count = 686 seq_step = 1 [90.144039] (kms_flip:2102) DEBUG: Vblank took 33us [90.152294] (kms_flip:2102) DEBUG: name = flip last_ts = 90.259239 last_received_ts = 90.258896 last_seq = 692 current_ts = 90.267570 current_received_ts = 90.267197 current_seq = 693 count = 687 seq_step = 1 [90.152329] (kms_flip:2102) DEBUG: Vblank took 26us [90.160611] (kms_flip:2102) DEBUG: name = flip last_ts = 90.267570 last_received_ts = 90.267197 last_seq = 693 current_ts = 90.275909 current_received_ts = 90.275513 current_seq = 694 count = 688 seq_step = 1 [90.160642] (kms_flip:2102) DEBUG: Vblank took 23us [90.168984] (kms_flip:2102) DEBUG: name = flip last_ts = 90.275909 last_received_ts = 90.275513 last_seq = 694 current_ts = 90.284241 current_received_ts = 90.283890 current_seq = 695 count = 689 seq_step = 1 [90.169012] (kms_flip:2102) DEBUG: Vblank took 22us [90.177350] (kms_flip:2102) DEBUG: name = flip last_ts = 90.284241 last_received_ts = 90.283890 last_seq = 695 current_ts = 90.292572 current_received_ts = 90.292244 current_seq = 696 count = 690 seq_step = 1 [90.177395] (kms_flip:2102) DEBUG: Vblank took 33us [90.185612] (kms_flip:2102) DEBUG: name = flip last_ts = 90.292572 last_received_ts = 90.292244 last_seq = 696 current_ts = 90.300911 current_received_ts = 90.300514 current_seq = 697 count = 691 seq_step = 1 [90.185642] (kms_flip:2102) DEBUG: Vblank took 24us [90.194210] (kms_flip:2102) DEBUG: name = flip last_ts = 90.300911 last_received_ts = 90.300514 last_seq = 697 current_ts = 90.309242 current_received_ts = 90.309105 current_seq = 698 count = 692 seq_step = 1 [90.194249] (kms_flip:2102) DEBUG: Vblank took 26us [90.202366] (kms_flip:2102) DEBUG: name = flip last_ts = 90.309242 last_received_ts = 90.309105 last_seq = 698 current_ts = 90.317574 current_received_ts = 90.317268 current_seq = 699 count = 693 seq_step = 1 [90.202404] (kms_flip:2102) DEBUG: Vblank took 29us [90.210692] (kms_flip:2102) DEBUG: name = flip last_ts = 90.317574 last_received_ts = 90.317268 last_seq = 699 current_ts = 90.325912 current_received_ts = 90.325592 current_seq = 700 count = 694 seq_step = 1 [90.210726] (kms_flip:2102) DEBUG: Vblank took 26us [90.218988] (kms_flip:2102) DEBUG: name = flip last_ts = 90.325912 last_received_ts = 90.325592 last_seq = 700 current_ts = 90.334244 current_received_ts = 90.333885 current_seq = 701 count = 695 seq_step = 1 [90.219023] (kms_flip:2102) DEBUG: Vblank took 25us [90.227372] (kms_flip:2102) DEBUG: name = flip last_ts = 90.334244 last_received_ts = 90.333885 last_seq = 701 current_ts = 90.342583 current_received_ts = 90.342270 current_seq = 702 count = 696 seq_step = 1 [90.227403] (kms_flip:2102) DEBUG: Vblank took 23us [90.235643] (kms_flip:2102) DEBUG: name = flip last_ts = 90.342583 last_received_ts = 90.342270 last_seq = 702 current_ts = 90.350914 current_received_ts = 90.350540 current_seq = 703 count = 697 seq_step = 1 [90.235673] (kms_flip:2102) DEBUG: Vblank took 23us [90.244000] (kms_flip:2102) DEBUG: name = flip last_ts = 90.350914 last_received_ts = 90.350540 last_seq = 703 current_ts = 90.359245 current_received_ts = 90.358894 current_seq = 704 count = 698 seq_step = 1 [90.244035] (kms_flip:2102) DEBUG: Vblank took 27us [90.252328] (kms_flip:2102) DEBUG: name = flip last_ts = 90.359245 last_received_ts = 90.358894 last_seq = 704 current_ts = 90.367584 current_received_ts = 90.367226 current_seq = 705 count = 699 seq_step = 1 [90.252357] (kms_flip:2102) DEBUG: Vblank took 22us [90.260734] (kms_flip:2102) DEBUG: name = flip last_ts = 90.367584 last_received_ts = 90.367226 last_seq = 705 current_ts = 90.375916 current_received_ts = 90.375633 current_seq = 706 count = 700 seq_step = 1 [90.260763] (kms_flip:2102) DEBUG: Vblank took 22us [90.269011] (kms_flip:2102) DEBUG: name = flip last_ts = 90.375916 last_received_ts = 90.375633 last_seq = 706 current_ts = 90.384247 current_received_ts = 90.383896 current_seq = 707 count = 701 seq_step = 1 [90.269056] (kms_flip:2102) DEBUG: Vblank took 33us [90.277343] (kms_flip:2102) DEBUG: name = flip last_ts = 90.384247 last_received_ts = 90.383896 last_seq = 707 current_ts = 90.392578 current_received_ts = 90.392235 current_seq = 708 count = 702 seq_step = 1 [90.277377] (kms_flip:2102) DEBUG: Vblank took 26us [90.285680] (kms_flip:2102) DEBUG: name = flip last_ts = 90.392578 last_received_ts = 90.392235 last_seq = 708 current_ts = 90.400917 current_received_ts = 90.400566 current_seq = 709 count = 703 seq_step = 1 [90.285725] (kms_flip:2102) DEBUG: Vblank took 33us [90.293988] (kms_flip:2102) DEBUG: name = flip last_ts = 90.400917 last_received_ts = 90.400566 last_seq = 709 current_ts = 90.409248 current_received_ts = 90.408875 current_seq = 710 count = 704 seq_step = 1 [90.294043] (kms_flip:2102) DEBUG: Vblank took 36us [90.302318] (kms_flip:2102) DEBUG: name = flip last_ts = 90.409248 last_received_ts = 90.408875 last_seq = 710 current_ts = 90.417587 current_received_ts = 90.417206 current_seq = 711 count = 705 seq_step = 1 [90.302359] (kms_flip:2102) DEBUG: Vblank took 32us [90.310669] (kms_flip:2102) DEBUG: name = flip last_ts = 90.417587 last_received_ts = 90.417206 last_seq = 711 current_ts = 90.425919 current_received_ts = 90.425560 current_seq = 712 count = 706 seq_step = 1 [90.310710] (kms_flip:2102) DEBUG: Vblank took 31us [90.319032] (kms_flip:2102) DEBUG: name = flip last_ts = 90.425919 last_received_ts = 90.425560 last_seq = 712 current_ts = 90.434250 current_received_ts = 90.433922 current_seq = 713 count = 707 seq_step = 1 [90.319079] (kms_flip:2102) DEBUG: Vblank took 36us [90.327350] (kms_flip:2102) DEBUG: name = flip last_ts = 90.434250 last_received_ts = 90.433922 last_seq = 713 current_ts = 90.442581 current_received_ts = 90.442238 current_seq = 714 count = 708 seq_step = 1 [90.327397] (kms_flip:2102) DEBUG: Vblank took 37us [90.335660] (kms_flip:2102) DEBUG: name = flip last_ts = 90.442581 last_received_ts = 90.442238 last_seq = 714 current_ts = 90.450920 current_received_ts = 90.450546 current_seq = 715 count = 709 seq_step = 1 [90.335711] (kms_flip:2102) DEBUG: Vblank took 39us [90.344037] (kms_flip:2102) DEBUG: name = flip last_ts = 90.450920 last_received_ts = 90.450546 last_seq = 715 current_ts = 90.459251 current_received_ts = 90.458916 current_seq = 716 count = 710 seq_step = 1 [90.344090] (kms_flip:2102) DEBUG: Vblank took 40us [90.352320] (kms_flip:2102) DEBUG: name = flip last_ts = 90.459251 last_received_ts = 90.458916 last_seq = 716 current_ts = 90.467583 current_received_ts = 90.467209 current_seq = 717 count = 711 seq_step = 1 [90.352364] (kms_flip:2102) DEBUG: Vblank took 34us [90.360650] (kms_flip:2102) DEBUG: name = flip last_ts = 90.467583 last_received_ts = 90.467209 last_seq = 717 current_ts = 90.475922 current_received_ts = 90.475533 current_seq = 718 count = 712 seq_step = 1 [90.360692] (kms_flip:2102) DEBUG: Vblank took 32us [90.369006] (kms_flip:2102) DEBUG: name = flip last_ts = 90.475922 last_received_ts = 90.475533 last_seq = 718 current_ts = 90.484253 current_received_ts = 90.483894 current_seq = 719 count = 713 seq_step = 1 [90.369045] (kms_flip:2102) DEBUG: Vblank took 30us [90.377372] (kms_flip:2102) DEBUG: name = flip last_ts = 90.484253 last_received_ts = 90.483894 last_seq = 719 current_ts = 90.492584 current_received_ts = 90.492249 current_seq = 720 count = 714 seq_step = 1 [90.377423] (kms_flip:2102) DEBUG: Vblank took 39us [90.385771] (kms_flip:2102) DEBUG: name = flip last_ts = 90.492584 last_received_ts = 90.492249 last_seq = 720 current_ts = 90.500916 current_received_ts = 90.500656 current_seq = 721 count = 715 seq_step = 1 [90.385812] (kms_flip:2102) DEBUG: Vblank took 31us [90.394032] (kms_flip:2102) DEBUG: name = flip last_ts = 90.500916 last_received_ts = 90.500656 last_seq = 721 current_ts = 90.509254 current_received_ts = 90.508919 current_seq = 722 count = 716 seq_step = 1 [90.394071] (kms_flip:2102) DEBUG: Vblank took 30us [90.402345] (kms_flip:2102) DEBUG: name = flip last_ts = 90.509254 last_received_ts = 90.508919 last_seq = 722 current_ts = 90.517586 current_received_ts = 90.517227 current_seq = 723 count = 717 seq_step = 1 [90.402383] (kms_flip:2102) DEBUG: Vblank took 30us [90.410710] (kms_flip:2102) DEBUG: name = flip last_ts = 90.517586 last_received_ts = 90.517227 last_seq = 723 current_ts = 90.525925 current_received_ts = 90.525581 current_seq = 724 count = 718 seq_step = 1 [90.410764] (kms_flip:2102) DEBUG: Vblank took 40us [90.419073] (kms_flip:2102) DEBUG: name = flip last_ts = 90.525925 last_received_ts = 90.525581 last_seq = 724 current_ts = 90.534256 current_received_ts = 90.533936 current_seq = 725 count = 719 seq_step = 1 [90.419147] (kms_flip:2102) DEBUG: Vblank took 56us [90.427443] (kms_flip:2102) DEBUG: name = flip last_ts = 90.534256 last_received_ts = 90.533936 last_seq = 725 current_ts = 90.542587 current_received_ts = 90.542313 current_seq = 726 count = 720 seq_step = 1 [90.427497] (kms_flip:2102) DEBUG: Vblank took 39us [90.435652] (kms_flip:2102) DEBUG: name = flip last_ts = 90.542587 last_received_ts = 90.542313 last_seq = 726 current_ts = 90.550926 current_received_ts = 90.550537 current_seq = 727 count = 721 seq_step = 1 [90.435688] (kms_flip:2102) DEBUG: Vblank took 29us [90.444046] (kms_flip:2102) DEBUG: name = flip last_ts = 90.550926 last_received_ts = 90.550537 last_seq = 727 current_ts = 90.559265 current_received_ts = 90.558922 current_seq = 728 count = 722 seq_step = 1 [90.444095] (kms_flip:2102) DEBUG: Vblank took 37us [90.452335] (kms_flip:2102) DEBUG: name = flip last_ts = 90.559265 last_received_ts = 90.558922 last_seq = 728 current_ts = 90.567589 current_received_ts = 90.567215 current_seq = 729 count = 723 seq_step = 1 [90.452379] (kms_flip:2102) DEBUG: Vblank took 33us [90.460693] (kms_flip:2102) DEBUG: name = flip last_ts = 90.567589 last_received_ts = 90.567215 last_seq = 729 current_ts = 90.575928 current_received_ts = 90.575569 current_seq = 730 count = 724 seq_step = 1 [90.460735] (kms_flip:2102) DEBUG: Vblank took 32us [90.469028] (kms_flip:2102) DEBUG: name = flip last_ts = 90.575928 last_received_ts = 90.575569 last_seq = 730 current_ts = 90.584259 current_received_ts = 90.583893 current_seq = 731 count = 725 seq_step = 1 [90.469088] (kms_flip:2102) DEBUG: Vblank took 44us [90.477346] (kms_flip:2102) DEBUG: name = flip last_ts = 90.584259 last_received_ts = 90.583893 last_seq = 731 current_ts = 90.592598 current_received_ts = 90.592216 current_seq = 732 count = 726 seq_step = 1 [90.477389] (kms_flip:2102) DEBUG: Vblank took 33us [90.485664] (kms_flip:2102) DEBUG: name = flip last_ts = 90.592598 last_received_ts = 90.592216 last_seq = 732 current_ts = 90.600929 current_received_ts = 90.600540 current_seq = 733 count = 727 seq_step = 1 [90.485705] (kms_flip:2102) DEBUG: Vblank took 32us [90.494043] (kms_flip:2102) DEBUG: name = flip last_ts = 90.600929 last_received_ts = 90.600540 last_seq = 733 current_ts = 90.609268 current_received_ts = 90.608917 current_seq = 734 count = 728 seq_step = 1 [90.494087] (kms_flip:2102) DEBUG: Vblank took 33us [90.502493] (kms_flip:2102) DEBUG: name = flip last_ts = 90.609268 last_received_ts = 90.608917 last_seq = 734 current_ts = 90.617599 current_received_ts = 90.617355 current_seq = 735 count = 729 seq_step = 1 [90.502550] (kms_flip:2102) DEBUG: Vblank took 43us [90.510784] (kms_flip:2102) DEBUG: name = flip last_ts = 90.617599 last_received_ts = 90.617355 last_seq = 735 current_ts = 90.625931 current_received_ts = 90.625648 current_seq = 736 count = 730 seq_step = 1 [90.510880] (kms_flip:2102) DEBUG: Vblank took 80us [90.519077] (kms_flip:2102) DEBUG: name = flip last_ts = 90.625931 last_received_ts = 90.625648 last_seq = 736 current_ts = 90.634262 current_received_ts = 90.633942 current_seq = 737 count = 731 seq_step = 1 [90.519148] (kms_flip:2102) DEBUG: Vblank took 56us [90.527427] (kms_flip:2102) DEBUG: name = flip last_ts = 90.634262 last_received_ts = 90.633942 last_seq = 737 current_ts = 90.642601 current_received_ts = 90.642296 current_seq = 738 count = 732 seq_step = 1 [90.527468] (kms_flip:2102) DEBUG: Vblank took 32us [90.535703] (kms_flip:2102) DEBUG: name = flip last_ts = 90.642601 last_received_ts = 90.642296 last_seq = 738 current_ts = 90.650932 current_received_ts = 90.650574 current_seq = 739 count = 733 seq_step = 1 [90.535745] (kms_flip:2102) DEBUG: Vblank took 32us [90.544062] (kms_flip:2102) DEBUG: name = flip last_ts = 90.650932 last_received_ts = 90.650574 last_seq = 739 current_ts = 90.659264 current_received_ts = 90.658928 current_seq = 740 count = 734 seq_step = 1 [90.544110] (kms_flip:2102) DEBUG: Vblank took 37us [90.552400] (kms_flip:2102) DEBUG: name = flip last_ts = 90.659264 last_received_ts = 90.658928 last_seq = 740 current_ts = 90.667603 current_received_ts = 90.667259 current_seq = 741 count = 735 seq_step = 1 [90.552454] (kms_flip:2102) DEBUG: Vblank took 39us [90.560716] (kms_flip:2102) DEBUG: name = flip last_ts = 90.667603 last_received_ts = 90.667259 last_seq = 741 current_ts = 90.675934 current_received_ts = 90.675575 current_seq = 742 count = 736 seq_step = 1 [90.560772] (kms_flip:2102) DEBUG: Vblank took 43us [90.569262] (kms_flip:2102) DEBUG: name = flip last_ts = 90.675934 last_received_ts = 90.675575 last_seq = 742 current_ts = 90.684265 current_received_ts = 90.684120 current_seq = 743 count = 737 seq_step = 1 [90.569313] (kms_flip:2102) DEBUG: Vblank took 34us [90.577378] (kms_flip:2102) DEBUG: name = flip last_ts = 90.684265 last_received_ts = 90.684120 last_seq = 743 current_ts = 90.692596 current_received_ts = 90.692245 current_seq = 744 count = 738 seq_step = 1 [90.577423] (kms_flip:2102) DEBUG: Vblank took 33us [90.585752] (kms_flip:2102) DEBUG: name = flip last_ts = 90.692596 last_received_ts = 90.692245 last_seq = 744 current_ts = 90.700935 current_received_ts = 90.700607 current_seq = 745 count = 739 seq_step = 1 [90.585808] (kms_flip:2102) DEBUG: Vblank took 41us [90.594034] (kms_flip:2102) DEBUG: name = flip last_ts = 90.700935 last_received_ts = 90.700607 last_seq = 745 current_ts = 90.709267 current_received_ts = 90.708900 current_seq = 746 count = 740 seq_step = 1 [90.594082] (kms_flip:2102) DEBUG: Vblank took 37us [90.602387] (kms_flip:2102) DEBUG: name = flip last_ts = 90.709267 last_received_ts = 90.708900 last_seq = 746 current_ts = 90.717606 current_received_ts = 90.717255 current_seq = 747 count = 741 seq_step = 1 [90.602430] (kms_flip:2102) DEBUG: Vblank took 34us [90.610728] (kms_flip:2102) DEBUG: name = flip last_ts = 90.717606 last_received_ts = 90.717255 last_seq = 747 current_ts = 90.725937 current_received_ts = 90.725594 current_seq = 748 count = 742 seq_step = 1 [90.610765] (kms_flip:2102) DEBUG: Vblank took 28us [90.619112] (kms_flip:2102) DEBUG: name = flip last_ts = 90.725937 last_received_ts = 90.725594 last_seq = 748 current_ts = 90.734276 current_received_ts = 90.733971 current_seq = 749 count = 743 seq_step = 1 [90.619197] (kms_flip:2102) DEBUG: Vblank took 45us [90.627474] (kms_flip:2102) DEBUG: name = flip last_ts = 90.734276 last_received_ts = 90.733971 last_seq = 749 current_ts = 90.742607 current_received_ts = 90.742310 current_seq = 750 count = 744 seq_step = 1 [90.627513] (kms_flip:2102) DEBUG: Vblank took 29us [90.635741] (kms_flip:2102) DEBUG: name = flip last_ts = 90.742607 last_received_ts = 90.742310 last_seq = 750 current_ts = 90.750938 current_received_ts = 90.750603 current_seq = 751 count = 745 seq_step = 1 [90.635780] (kms_flip:2102) DEBUG: Vblank took 31us [90.644025] (kms_flip:2102) DEBUG: name = flip last_ts = 90.750938 last_received_ts = 90.750603 last_seq = 751 current_ts = 90.759270 current_received_ts = 90.758888 current_seq = 752 count = 746 seq_step = 1 [90.644066] (kms_flip:2102) DEBUG: Vblank took 31us [90.652429] (kms_flip:2102) DEBUG: name = flip last_ts = 90.759270 last_received_ts = 90.758888 last_seq = 752 current_ts = 90.767609 current_received_ts = 90.767288 current_seq = 753 count = 747 seq_step = 1 [90.652480] (kms_flip:2102) DEBUG: Vblank took 38us [90.660724] (kms_flip:2102) DEBUG: name = flip last_ts = 90.767609 last_received_ts = 90.767288 last_seq = 753 current_ts = 90.775940 current_received_ts = 90.775574 current_seq = 754 count = 748 seq_step = 1 [90.660778] (kms_flip:2102) DEBUG: Vblank took 39us [90.669064] (kms_flip:2102) DEBUG: name = flip last_ts = 90.775940 last_received_ts = 90.775574 last_seq = 754 current_ts = 90.784271 current_received_ts = 90.783920 current_seq = 755 count = 749 seq_step = 1 [90.669107] (kms_flip:2102) DEBUG: Vblank took 33us [90.677435] (kms_flip:2102) DEBUG: name = flip last_ts = 90.784271 last_received_ts = 90.783920 last_seq = 755 current_ts = 90.792610 current_received_ts = 90.792282 current_seq = 756 count = 750 seq_step = 1 [90.677490] (kms_flip:2102) DEBUG: Vblank took 40us [90.685697] (kms_flip:2102) DEBUG: name = flip last_ts = 90.792610 last_received_ts = 90.792282 last_seq = 756 current_ts = 90.800941 current_received_ts = 90.800560 current_seq = 757 count = 751 seq_step = 1 [90.685738] (kms_flip:2102) DEBUG: Vblank took 31us [90.694100] (kms_flip:2102) DEBUG: name = flip last_ts = 90.800941 last_received_ts = 90.800560 last_seq = 757 current_ts = 90.809280 current_received_ts = 90.808952 current_seq = 758 count = 752 seq_step = 1 [90.694170] (kms_flip:2102) DEBUG: Vblank took 58us [90.702397] (kms_flip:2102) DEBUG: name = flip last_ts = 90.809280 last_received_ts = 90.808952 last_seq = 758 current_ts = 90.817612 current_received_ts = 90.817253 current_seq = 759 count = 753 seq_step = 1 [90.702439] (kms_flip:2102) DEBUG: Vblank took 30us [90.710850] (kms_flip:2102) DEBUG: name = flip last_ts = 90.817612 last_received_ts = 90.817253 last_seq = 759 current_ts = 90.825943 current_received_ts = 90.825699 current_seq = 760 count = 754 seq_step = 1 [90.710899] (kms_flip:2102) DEBUG: Vblank took 34us [90.719042] (kms_flip:2102) DEBUG: name = flip last_ts = 90.825943 last_received_ts = 90.825699 last_seq = 760 current_ts = 90.834282 current_received_ts = 90.833900 current_seq = 761 count = 755 seq_step = 1 [90.719084] (kms_flip:2102) DEBUG: Vblank took 34us [90.727414] (kms_flip:2102) DEBUG: name = flip last_ts = 90.834282 last_received_ts = 90.833900 last_seq = 761 current_ts = 90.842606 current_received_ts = 90.842270 current_seq = 762 count = 756 seq_step = 1 [90.727456] (kms_flip:2102) DEBUG: Vblank took 32us [90.735728] (kms_flip:2102) DEBUG: name = flip last_ts = 90.842606 last_received_ts = 90.842270 last_seq = 762 current_ts = 90.850945 current_received_ts = 90.850578 current_seq = 763 count = 757 seq_step = 1 [90.735783] (kms_flip:2102) DEBUG: Vblank took 41us [90.744092] (kms_flip:2102) DEBUG: name = flip last_ts = 90.850945 last_received_ts = 90.850578 last_seq = 763 current_ts = 90.859283 current_received_ts = 90.858948 current_seq = 764 count = 758 seq_step = 1 [90.744163] (kms_flip:2102) DEBUG: Vblank took 60us [90.752458] (kms_flip:2102) DEBUG: name = flip last_ts = 90.859283 last_received_ts = 90.858948 last_seq = 764 current_ts = 90.867615 current_received_ts = 90.867287 current_seq = 765 count = 759 seq_step = 1 [90.752498] (kms_flip:2102) DEBUG: Vblank took 30us [90.760803] (kms_flip:2102) DEBUG: name = flip last_ts = 90.867615 last_received_ts = 90.867287 last_seq = 765 current_ts = 90.875946 current_received_ts = 90.875656 current_seq = 766 count = 760 seq_step = 1 [90.760847] (kms_flip:2102) DEBUG: Vblank took 34us [90.769080] (kms_flip:2102) DEBUG: name = flip last_ts = 90.875946 last_received_ts = 90.875656 last_seq = 766 current_ts = 90.884285 current_received_ts = 90.883934 current_seq = 767 count = 761 seq_step = 1 [90.769118] (kms_flip:2102) DEBUG: Vblank took 30us [90.777435] (kms_flip:2102) DEBUG: name = flip last_ts = 90.884285 last_received_ts = 90.883934 last_seq = 767 current_ts = 90.892616 current_received_ts = 90.892288 current_seq = 768 count = 762 seq_step = 1 [90.777481] (kms_flip:2102) DEBUG: Vblank took 35us [90.785861] (kms_flip:2102) DEBUG: name = flip last_ts = 90.892616 last_received_ts = 90.892288 last_seq = 768 current_ts = 90.900955 current_received_ts = 90.900703 current_seq = 769 count = 763 seq_step = 1 [90.785908] (kms_flip:2102) DEBUG: Vblank took 31us [90.794094] (kms_flip:2102) DEBUG: name = flip last_ts = 90.900955 last_received_ts = 90.900703 last_seq = 769 current_ts = 90.909286 current_received_ts = 90.908943 current_seq = 770 count = 764 seq_step = 1 [90.794153] (kms_flip:2102) DEBUG: Vblank took 32us [90.802481] (kms_flip:2102) DEBUG: name = flip last_ts = 90.909286 last_received_ts = 90.908943 last_seq = 770 current_ts = 90.917618 current_received_ts = 90.917328 current_seq = 771 count = 765 seq_step = 1 [90.802523] (kms_flip:2102) DEBUG: Vblank took 31us [90.810714] (kms_flip:2102) DEBUG: name = flip last_ts = 90.917618 last_received_ts = 90.917328 last_seq = 771 current_ts = 90.925949 current_received_ts = 90.925568 current_seq = 772 count = 766 seq_step = 1 [90.810754] (kms_flip:2102) DEBUG: Vblank took 31us [90.819239] (kms_flip:2102) DEBUG: name = flip last_ts = 90.925949 last_received_ts = 90.925568 last_seq = 772 current_ts = 90.934288 current_received_ts = 90.934082 current_seq = 773 count = 767 seq_step = 1 [90.819291] (kms_flip:2102) DEBUG: Vblank took 36us [90.827391] (kms_flip:2102) DEBUG: name = flip last_ts = 90.934288 last_received_ts = 90.934082 last_seq = 773 current_ts = 90.942619 current_received_ts = 90.942238 current_seq = 774 count = 768 seq_step = 1 [90.827436] (kms_flip:2102) DEBUG: Vblank took 34us [90.835798] (kms_flip:2102) DEBUG: name = flip last_ts = 90.942619 last_received_ts = 90.942238 last_seq = 774 current_ts = 90.950951 current_received_ts = 90.950638 current_seq = 775 count = 769 seq_step = 1 [90.835855] (kms_flip:2102) DEBUG: Vblank took 40us [90.844124] (kms_flip:2102) DEBUG: name = flip last_ts = 90.950951 last_received_ts = 90.950638 last_seq = 775 current_ts = 90.959290 current_received_ts = 90.958969 current_seq = 776 count = 770 seq_step = 1 [90.844206] (kms_flip:2102) DEBUG: Vblank took 69us [90.852430] (kms_flip:2102) DEBUG: name = flip last_ts = 90.959290 last_received_ts = 90.958969 last_seq = 776 current_ts = 90.967621 current_received_ts = 90.967278 current_seq = 777 count = 771 seq_step = 1 [90.852473] (kms_flip:2102) DEBUG: Vblank took 33us [90.860799] (kms_flip:2102) DEBUG: name = flip last_ts = 90.967621 last_received_ts = 90.967278 last_seq = 777 current_ts = 90.975960 current_received_ts = 90.975639 current_seq = 778 count = 772 seq_step = 1 [90.860848] (kms_flip:2102) DEBUG: Vblank took 36us [90.869123] (kms_flip:2102) DEBUG: name = flip last_ts = 90.975960 last_received_ts = 90.975639 last_seq = 778 current_ts = 90.984283 current_received_ts = 90.983963 current_seq = 779 count = 773 seq_step = 1 [90.869208] (kms_flip:2102) DEBUG: Vblank took 68us [90.877515] (kms_flip:2102) DEBUG: name = flip last_ts = 90.984283 last_received_ts = 90.983963 last_seq = 779 current_ts = 90.992622 current_received_ts = 90.992355 current_seq = 780 count = 774 seq_step = 1 [90.877555] (kms_flip:2102) DEBUG: Vblank took 30us [90.885786] (kms_flip:2102) DEBUG: name = flip last_ts = 90.992622 last_received_ts = 90.992355 last_seq = 780 current_ts = 91.000954 current_received_ts = 91.000633 current_seq = 781 count = 775 seq_step = 1 [90.885854] (kms_flip:2102) DEBUG: Vblank took 58us [90.894100] (kms_flip:2102) DEBUG: name = flip last_ts = 91.000954 last_received_ts = 91.000633 last_seq = 781 current_ts = 91.009293 current_received_ts = 91.008942 current_seq = 782 count = 776 seq_step = 1 [90.894158] (kms_flip:2102) DEBUG: Vblank took 34us [90.902481] (kms_flip:2102) DEBUG: name = flip last_ts = 91.009293 last_received_ts = 91.008942 last_seq = 782 current_ts = 91.017624 current_received_ts = 91.017319 current_seq = 783 count = 777 seq_step = 1 [90.902523] (kms_flip:2102) DEBUG: Vblank took 32us [90.910788] (kms_flip:2102) DEBUG: name = flip last_ts = 91.017624 last_received_ts = 91.017319 last_seq = 783 current_ts = 91.025955 current_received_ts = 91.025620 current_seq = 784 count = 778 seq_step = 1 [90.910844] (kms_flip:2102) DEBUG: Vblank took 40us [90.919169] (kms_flip:2102) DEBUG: name = flip last_ts = 91.025955 last_received_ts = 91.025620 last_seq = 784 current_ts = 91.034294 current_received_ts = 91.033989 current_seq = 785 count = 779 seq_step = 1 [90.919228] (kms_flip:2102) DEBUG: Vblank took 46us [90.927468] (kms_flip:2102) DEBUG: name = flip last_ts = 91.034294 last_received_ts = 91.033989 last_seq = 785 current_ts = 91.042625 current_received_ts = 91.042297 current_seq = 786 count = 780 seq_step = 1 [90.927516] (kms_flip:2102) DEBUG: Vblank took 33us [90.935783] (kms_flip:2102) DEBUG: name = flip last_ts = 91.042625 last_received_ts = 91.042297 last_seq = 786 current_ts = 91.050957 current_received_ts = 91.050629 current_seq = 787 count = 781 seq_step = 1 [90.935820] (kms_flip:2102) DEBUG: Vblank took 30us [90.944188] (kms_flip:2102) DEBUG: name = flip last_ts = 91.050957 last_received_ts = 91.050629 last_seq = 787 current_ts = 91.059296 current_received_ts = 91.058983 current_seq = 788 count = 782 seq_step = 1 [90.944236] (kms_flip:2102) DEBUG: Vblank took 33us [90.952470] (kms_flip:2102) DEBUG: name = flip last_ts = 91.059296 last_received_ts = 91.058983 last_seq = 788 current_ts = 91.067635 current_received_ts = 91.067299 current_seq = 789 count = 783 seq_step = 1 [90.952522] (kms_flip:2102) DEBUG: Vblank took 40us [90.960779] (kms_flip:2102) DEBUG: name = flip last_ts = 91.067635 last_received_ts = 91.067299 last_seq = 789 current_ts = 91.075958 current_received_ts = 91.075615 current_seq = 790 count = 784 seq_step = 1 [90.960823] (kms_flip:2102) DEBUG: Vblank took 34us [90.969114] (kms_flip:2102) DEBUG: name = flip last_ts = 91.075958 last_received_ts = 91.075615 last_seq = 790 current_ts = 91.084297 current_received_ts = 91.083939 current_seq = 791 count = 785 seq_step = 1 [90.969192] (kms_flip:2102) DEBUG: Vblank took 59us [90.977502] (kms_flip:2102) DEBUG: name = flip last_ts = 91.084297 last_received_ts = 91.083939 last_seq = 791 current_ts = 91.092628 current_received_ts = 91.092331 current_seq = 792 count = 786 seq_step = 1 [90.977559] (kms_flip:2102) DEBUG: Vblank took 42us [90.985841] (kms_flip:2102) DEBUG: name = flip last_ts = 91.092628 last_received_ts = 91.092331 last_seq = 792 current_ts = 91.100960 current_received_ts = 91.100662 current_seq = 793 count = 787 seq_step = 1 [90.985893] (kms_flip:2102) DEBUG: Vblank took 35us [90.994137] (kms_flip:2102) DEBUG: name = flip last_ts = 91.100960 last_received_ts = 91.100662 last_seq = 793 current_ts = 91.109299 current_received_ts = 91.108971 current_seq = 794 count = 788 seq_step = 1 [90.994223] (kms_flip:2102) DEBUG: Vblank took 75us [91.002597] (kms_flip:2102) DEBUG: name = flip last_ts = 91.109299 last_received_ts = 91.108971 last_seq = 794 current_ts = 91.117630 current_received_ts = 91.117424 current_seq = 795 count = 789 seq_step = 1 [91.002651] (kms_flip:2102) DEBUG: Vblank took 39us [91.010819] (kms_flip:2102) DEBUG: name = flip last_ts = 91.117630 last_received_ts = 91.117424 last_seq = 795 current_ts = 91.125961 current_received_ts = 91.125633 current_seq = 796 count = 790 seq_step = 1 [91.010873] (kms_flip:2102) DEBUG: Vblank took 38us [91.019150] (kms_flip:2102) DEBUG: name = flip last_ts = 91.125961 last_received_ts = 91.125633 last_seq = 796 current_ts = 91.134300 current_received_ts = 91.133972 current_seq = 797 count = 791 seq_step = 1 [91.019227] (kms_flip:2102) DEBUG: Vblank took 40us [91.027554] (kms_flip:2102) DEBUG: name = flip last_ts = 91.134300 last_received_ts = 91.133972 last_seq = 797 current_ts = 91.142632 current_received_ts = 91.142380 current_seq = 798 count = 792 seq_step = 1 [91.027609] (kms_flip:2102) DEBUG: Vblank took 40us [91.035786] (kms_flip:2102) DEBUG: name = flip last_ts = 91.142632 last_received_ts = 91.142380 last_seq = 798 current_ts = 91.150970 current_received_ts = 91.150612 current_seq = 799 count = 793 seq_step = 1 [91.035842] (kms_flip:2102) DEBUG: Vblank took 43us [91.044152] (kms_flip:2102) DEBUG: name = flip last_ts = 91.150970 last_received_ts = 91.150612 last_seq = 799 current_ts = 91.159302 current_received_ts = 91.158981 current_seq = 800 count = 794 seq_step = 1 [91.044226] (kms_flip:2102) DEBUG: Vblank took 41us [91.052497] (kms_flip:2102) DEBUG: name = flip last_ts = 91.159302 last_received_ts = 91.158981 last_seq = 800 current_ts = 91.167633 current_received_ts = 91.167320 current_seq = 801 count = 795 seq_step = 1 [91.052546] (kms_flip:2102) DEBUG: Vblank took 33us [91.060754] (kms_flip:2102) DEBUG: name = flip last_ts = 91.167633 last_received_ts = 91.167320 last_seq = 801 current_ts = 91.175964 current_received_ts = 91.175583 current_seq = 802 count = 796 seq_step = 1 [91.060797] (kms_flip:2102) DEBUG: Vblank took 33us [91.069195] (kms_flip:2102) DEBUG: name = flip last_ts = 91.175964 last_received_ts = 91.175583 last_seq = 802 current_ts = 91.184303 current_received_ts = 91.183975 current_seq = 803 count = 797 seq_step = 1 [91.069242] (kms_flip:2102) DEBUG: Vblank took 33us [91.077426] (kms_flip:2102) DEBUG: name = flip last_ts = 91.184303 last_received_ts = 91.183975 last_seq = 803 current_ts = 91.192635 current_received_ts = 91.192253 current_seq = 804 count = 798 seq_step = 1 [91.077471] (kms_flip:2102) DEBUG: Vblank took 34us [91.085841] (kms_flip:2102) DEBUG: name = flip last_ts = 91.192635 last_received_ts = 91.192253 last_seq = 804 current_ts = 91.200974 current_received_ts = 91.200661 current_seq = 805 count = 799 seq_step = 1 [91.085890] (kms_flip:2102) DEBUG: Vblank took 33us [91.094152] (kms_flip:2102) DEBUG: name = flip last_ts = 91.200974 last_received_ts = 91.200661 last_seq = 805 current_ts = 91.209305 current_received_ts = 91.208977 current_seq = 806 count = 800 seq_step = 1 [91.094209] (kms_flip:2102) DEBUG: Vblank took 33us [91.102553] (kms_flip:2102) DEBUG: name = flip last_ts = 91.209305 last_received_ts = 91.208977 last_seq = 806 current_ts = 91.217636 current_received_ts = 91.217369 current_seq = 807 count = 801 seq_step = 1 [91.102606] (kms_flip:2102) DEBUG: Vblank took 39us [91.110832] (kms_flip:2102) DEBUG: name = flip last_ts = 91.217636 last_received_ts = 91.217369 last_seq = 807 current_ts = 91.225975 current_received_ts = 91.225655 current_seq = 808 count = 802 seq_step = 1 [91.110910] (kms_flip:2102) DEBUG: Vblank took 66us [91.119136] (kms_flip:2102) DEBUG: name = flip last_ts = 91.225975 last_received_ts = 91.225655 last_seq = 808 current_ts = 91.234306 current_received_ts = 91.233948 current_seq = 809 count = 803 seq_step = 1 [91.119911] (kms_flip:2102) DEBUG: Vblank took 758us [91.119918] (kms_flip:2102) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: [91.119971] (kms_flip:2102) CRITICAL: Failed assertion: end - start < 500 [91.120021] (kms_flip:2102) CRITICAL: Last errno: 4, Interrupted system call [91.158383] (kms_flip:2102) igt_core-INFO: Stack trace: [91.171309] (kms_flip:2102) igt_core-INFO: #0 ../lib/igt_core.c:2074 __igt_fail_assert() [91.172858] (kms_flip:2102) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() [91.172968] (kms_flip:2102) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() [91.173056] (kms_flip:2102) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() [91.173113] (kms_flip:2102) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() [91.178663] (kms_flip:2102) igt_core-INFO: #5 [__libc_init_first+0x8a] [91.180146] (kms_flip:2102) igt_core-INFO: #6 [__libc_start_main+0x8b] [91.180474] (kms_flip:2102) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest C-HDMI-A1: FAIL (6.931s)
Dmesg	<6> [84.426163] [IGT] kms_flip: starting dynamic subtest C-HDMI-A1 <7> [84.426990] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:637] <7> [84.427308] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:638] <7> [84.448058] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:171:pipe A] <7> [84.448370] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:309:pipe B] <7> [84.448446] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.enable (expected yes, found no) <7> [84.448638] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.active (expected yes, found no) <7> [84.448793] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1) <7> [84.448942] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in lane_count (expected 4, found 0) <7> [84.449122] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [84.449317] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [84.449481] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [84.449642] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2080, found 0) <7> [84.449825] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [84.450017] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2080, found 0) <7> [84.450200] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1968, found 0) <7> [84.450358] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2000, found 0) <7> [84.450525] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [84.450683] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [84.450840] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0) <7> [84.450996] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0) <7> [84.451186] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1144, found 0) <7> [84.451403] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1144, found 0) <7> [84.451572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [84.451728] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2080, found 0) <7> [84.451883] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [84.452039] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2080, found 0) <7> [84.452216] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1968, found 0) <7> [84.452387] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2000, found 0) <7> [84.452542] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [84.452697] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [84.452852] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0) <7> [84.453007] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0) <7> [84.453176] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1144, found 0) <7> [84.453346] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1144, found 0) <7> [84.453501] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [84.453657] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [84.453814] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [84.453969] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in has_hdmi_sink (expected yes, found no) <7> [84.454138] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in has_infoframe (expected yes, found no) <7> [84.454316] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [84.454473] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 285500, found 0) <7> [84.454639] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 285500, found 0) <7> [84.454794] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in port_clock (expected 285500, found 0) <7> [84.454950] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000) <7> [84.455177] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in avi infoframe <7> [84.455342] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [84.455520] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [84.455524] i915 0000:00:02.0: colorspace: RGB <7> [84.455527] i915 0000:00:02.0: scan mode: Underscan <7> [84.455529] i915 0000:00:02.0: colorimetry: No Data <7> [84.455532] i915 0000:00:02.0: picture aspect: No Data <7> [84.455535] i915 0000:00:02.0: active aspect: Same as Picture <7> [84.455537] i915 0000:00:02.0: itc: No Data <7> [84.455540] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [84.455543] i915 0000:00:02.0: quantization range: Full <7> [84.455545] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [84.455548] i915 0000:00:02.0: video code: 0 <7> [84.455551] i915 0000:00:02.0: ycc quantization range: Full <7> [84.455554] i915 0000:00:02.0: hdmi content type: Graphics <7> [84.455556] i915 0000:00:02.0: pixel repeat: 0 <7> [84.455559] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [84.455562] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [84.455757] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in spd infoframe <7> [84.455921] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [84.456101] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [84.456105] i915 0000:00:02.0: vendor: Intel <7> [84.456108] i915 0000:00:02.0: product: Integrated gfx <7> [84.456110] i915 0000:00:02.0: source device information: PC General (0x9) <7> [84.456114] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [84.456296] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hdmi infoframe <7> [84.456455] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [84.456611] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [84.456613] i915 0000:00:02.0: empty frame <7> [84.456615] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [84.456773] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:309:pipe B] fastset requirement not met, forcing full modeset <7> [84.456933] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:309:pipe B] releasing DPLL 0 <7> [84.457149] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no <7> [84.457310] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:309:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0 <7> [84.457505] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:303:cursor B] ddb (1993 - 2048) -> ( 0 - 0), size 55 -> 0 <7> [84.457684] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:309:pipe B] min cdclk: 192000 kHz -> 0 kHz <7> [84.457875] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [84.458035] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 172800 kHz, actual 172800 kHz <7> [84.458214] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0 <7> [84.458392] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:309:pipe B] enable: no [modeset] <7> [84.458556] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:173:plane 1B] fb: [NOFB], visible: no <7> [84.458718] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:203:plane 2B] fb: [NOFB], visible: no <7> [84.458877] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:233:plane 3B] fb: [NOFB], visible: no <7> [84.459036] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:plane 4B] fb: [NOFB], visible: no <7> [84.459216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:273:plane 5B] fb: [NOFB], visible: no <7> [84.459387] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:283:plane 6B] fb: [NOFB], visible: no <7> [84.459542] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:293:plane 7B] fb: [NOFB], visible: no <7> [84.459700] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:303:cursor B] fb: [NOFB], visible: no <7> [84.459937] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:588:HDMI-A-1][ENCODER:587:DDI B/PHY B] Disable audio codec on [CRTC:309:pipe B] <7> [84.473127] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port B <7> [84.476086] i915 0000:00:02.0: [drm:intel_hdmi_handle_sink_scrambling [i915]] [CONNECTOR:588:HDMI-A-1] scrambling=no, TMDS bit clock ratio=1/10 <7> [84.476607] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1) <7> [84.476761] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK on first message, retry <7> [84.477346] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1) <7> [84.477583] i915 0000:00:02.0: [drm:drm_scdc_set_high_tmds_clock_ratio [drm_display_helper]] [CONNECTOR:588:HDMI-A-1] Failed to read TMDS config: -6 <7> [84.477610] i915 0000:00:02.0: [drm:intel_ddi_disable [i915]] [CONNECTOR:588:HDMI-A-1] Failed to reset sink scrambling/TMDS bit clock ratio <7> [84.477868] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B <7> [84.483100] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B <7> [84.483307] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable DPLL 0 (active 0x2, on? 1) for [CRTC:309:pipe B] <7> [84.483503] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0 <7> [84.483682] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 172800 kHz, VCO 345600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [84.483935] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DDI B/PHY B] <7> [84.484140] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:597:DDI TC1/PHY TC1] <7> [84.484306] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:599:DP-MST A] <7> [84.484469] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:600:DP-MST B] <7> [84.484630] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:601:DP-MST C] <7> [84.484791] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:602:DP-MST D] <7> [84.484953] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:607:DDI TC2/PHY TC2] <7> [84.485194] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:609:DP-MST A] <7> [84.485353] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST B] <7> [84.485512] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST C] <7> [84.485673] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST D] <7> [84.485855] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:616:DDI TC3/PHY TC3] <7> [84.486020] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:618:DP-MST A] <7> [84.486300] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:619:DP-MST B] <7> [84.486459] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DP-MST C] <7> [84.486619] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:621:DP-MST D] <7> [84.486847] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DDI TC4/PHY TC4] <7> [84.487006] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:627:DP-MST A] <7> [84.487178] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:628:DP-MST B] <7> [84.487337] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:629:DP-MST C] <7> [84.487496] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:630:DP-MST D] <7> [84.487653] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:588:HDMI-A-1] <7> [84.487965] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1 <7> [84.488195] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3 <7> [84.488380] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_2 <7> [84.488566] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:309:pipe B] <7> [84.489011] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:447:pipe C] <7> [84.489190] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:585:pipe D] <7> [84.489333] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:447:pipe C] <7> [84.489365] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:588:HDMI-A-1] <7> [84.489430] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:588:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36) <7> [84.489610] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [84.489775] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:447:pipe C] hw max bpp: 24, pipe bpp: 24, dithering: 0 <7> [84.489943] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:587:DDI B/PHY B] [CRTC:447:pipe C] <7> [84.490180] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.enable (expected no, found yes) <7> [84.490345] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.active (expected no, found yes) <7> [84.490507] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2) <7> [84.490669] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in lane_count (expected 0, found 4) <7> [84.490829] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [84.490988] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [84.491243] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [84.491434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2080) <7> [84.491593] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [84.491752] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2080) <7> [84.491912] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 1968) <7> [84.492083] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2000) <7> [84.492244] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [84.492409] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [84.492572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [84.492731] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [84.492890] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1144) <7> [84.493048] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1144) <7> [84.493225] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [84.493385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2080) <7> [84.493542] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [84.493699] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2080) <7> [84.493856] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 1968) <7> [84.494013] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2000) <7> [84.494188] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [84.494345] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [84.494507] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [84.494663] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [84.494847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1144) <7> [84.495082] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1144) <7> [84.495306] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [84.495530] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [84.495756] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [84.495991] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [84.496243] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in has_infoframe (expected no, found yes) <7> [84.496465] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in dpll_hw_state <7> [84.496680] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [84.496904] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: cfgcr0: 0x0, cfgcr1: 0x0, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0 <7> [84.497139] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [84.497361] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: cfgcr0: 0x1801be, cfgcr1: 0x488, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0 <7> [84.497556] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [84.497715] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 285500) <7> [84.497873] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 285500) <7> [84.498030] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in port_clock (expected 0, found 285500) <7> [84.498212] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [84.498370] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in avi infoframe <7> [84.498528] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [84.498684] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [84.498839] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [84.498841] i915 0000:00:02.0: colorspace: RGB <7> [84.498843] i915 0000:00:02.0: scan mode: Underscan <7> [84.498844] i915 0000:00:02.0: colorimetry: No Data <7> [84.498846] i915 0000:00:02.0: picture aspect: No Data <7> [84.498847] i915 0000:00:02.0: active aspect: Same as Picture <7> [84.498849] i915 0000:00:02.0: itc: No Data <7> [84.498850] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [84.498851] i915 0000:00:02.0: quantization range: Full <7> [84.498853] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [84.498854] i915 0000:00:02.0: video code: 0 <7> [84.498856] i915 0000:00:02.0: ycc quantization range: Full <7> [84.498857] i915 0000:00:02.0: hdmi content type: Graphics <7> [84.498859] i915 0000:00:02.0: pixel repeat: 0 <7> [84.498860] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [84.498862] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in spd infoframe <7> [84.499025] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [84.499234] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [84.499441] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [84.499443] i915 0000:00:02.0: vendor: Intel <7> [84.499444] i915 0000:00:02.0: product: Integrated gfx <7> [84.499446] i915 0000:00:02.0: source device information: PC General (0x9) <7> [84.499448] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hdmi infoframe <7> [84.499607] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected: <7> [84.499766] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found: <7> [84.499924] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [84.499926] i915 0000:00:02.0: empty frame <7> [84.499928] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:447:pipe C] fastset requirement not met, forcing full modeset <7> [84.500145] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no <7> [84.500326] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:447:pipe C] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4 <7> [84.500525] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:311:plane 1C] ddb ( 0 - 0) -> ( 0 - 1993), size 0 -> 1993 <7> [84.500683] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:441:cursor C] ddb ( 0 - 0) -> (1993 - 2048), size 0 -> 55 <7> [84.500840] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [84.501000] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 8, 8, 8, 8, 11, 16, 16, 0, 0, 0 <7> [84.501212] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 129, 129, 129, 129, 177, 257, 257, 30, 0, 0 <7> [84.501434] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 143, 143, 143, 143, 196, 284, 284, 31, 0, 0 <7> [84.501690] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:447:pipe C] data rate 1142000 num active planes 1 <7> [84.501926] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 14993 required 1142 <7> [84.502163] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <7> [84.502420] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:447:pipe C] min cdclk: 0 kHz -> 192000 kHz <7> [84.502728] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change <7> [84.502947] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [84.503183] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0 <7> [84.503408] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:447:pipe C] allocated DPLL 0 <7> [84.503636] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:447:pipe C] reserving DPLL 0 <7> [84.503875] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:447:pipe C] enable: yes [modeset] <7> [84.504111] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [84.504288] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: C, pipe bpp: 24, dithering: 0 <7> [84.504449] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [84.504609] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [84.504773] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [84.504935] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [84.505105] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [84.505264] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x0 <7> [84.505422] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [84.505424] i915 0000:00:02.0: colorspace: RGB <7> [84.505426] i915 0000:00:02.0: scan mode: Underscan <7> [84.505427] i915 0000:00:02.0: colorimetry: No Data <7> [84.505429] i915 0000:00:02.0: picture aspect: No Data <7> [84.505430] i915 0000:00:02.0: active aspect: Same as Picture <7> [84.505432] i915 0000:00:02.0: itc: No Data <7> [84.505433] i915 0000:00:02.0: extended colorimetry: xvYCC 601 <7> [84.505434] i915 0000:00:02.0: quantization range: Full <7> [84.505436] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling <7> [84.505437] i915 0000:00:02.0: video code: 0 <7> [84.505439] i915 0000:00:02.0: ycc quantization range: Full <7> [84.505440] i915 0000:00:02.0: hdmi content type: Graphics <7> [84.505442] i915 0000:00:02.0: pixel repeat: 0 <7> [84.505443] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0 <7> [84.505445] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [84.505446] i915 0000:00:02.0: vendor: Intel <7> [84.505448] i915 0000:00:02.0: product: Integrated gfx <7> [84.505449] i915 0000:00:02.0: source device information: PC General (0x9) <7> [84.505451] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4 <7> [84.505453] i915 0000:00:02.0: empty frame <7> [84.505454] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 0f 00 6d a2 00 7f 00 00 00 00 00 00 00 00 <7> [84.505613] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 0d 82 34 12 66 69 74 48 65 61 64 6c 65 73 73 47 <7> [84.505770] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 53 7f 7f 28 0f 7f 07 17 7f ff 3f 7f ff 47 7f ff <7> [84.505926] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 5f 7f 82 7f 7f 00 7f 7f 51 7f 7f 30 77 7f 03 00 <7> [84.506091] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [84.506247] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [84.506403] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1144, vmax: 1144, flipline: 1144, pipeline full: 61, guardband: 63 vsync start: 0, vsync end: 0 <7> [84.506560] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1144, vmax vtotal: 1144 <7> [84.506715] 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> [84.506872] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x48 0x5 <7> [84.507028] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x48 0x5 <7> [84.507200] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=285500, hd=1920 hb=1920-2080 hs=1968-2000 ht=2080, vd=1080 vb=1080-1144 vs=1083-1088 vt=1144, flags=0x5 <7> [84.507358] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x40 0x5 <7> [84.507515] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=285500, hd=1920 hb=1920-2080 hs=1968-2000 ht=2080, vd=1080 vb=1080-1144 vs=1083-1088 vt=1144, flags=0x5 <7> [84.507672] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 285500, pixel rate 285500, min cdclk 192000, min voltage level 0 <7> [84.507828] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0 <7> [84.507982] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [84.508154] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0 <7> [84.508113] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off <7> [84.508318] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [84.508393] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6 <7> [84.508480] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [84.508643] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [84.508637] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02 <7> [84.508825] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1801be, cfgcr1: 0x488, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0 <7> [84.509050] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [84.509302] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [84.509534] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [84.509769] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [84.509877] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on <7> [84.510007] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [84.510252] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [84.510484] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [84.510708] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [84.510927] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [84.511155] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [84.511377] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [84.511597] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [84.511789] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:311:plane 1C] fb: [FB:637] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes <7> [84.511949] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [84.512121] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [84.512280] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:341:plane 2C] fb: [NOFB], visible: no <7> [84.512438] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 3C] fb: [NOFB], visible: no <7> [84.512596] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:401:plane 4C] fb: [NOFB], visible: no <7> [84.512752] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:411:plane 5C] fb: [NOFB], visible: no <7> [84.512908] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:421:plane 6C] fb: [NOFB], visible: no <7> [84.513064] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:431:plane 7C] fb: [NOFB], visible: no <7> [84.513296] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:441:cursor C] fb: [NOFB], visible: no <7> [84.514023] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on <7> [84.514213] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off <7> [84.514901] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00 <7> [84.516099] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_2 <7> [84.516318] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3 <7> [84.516557] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_4 <7> [84.516837] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 192000 kHz, VCO 384000 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [84.517171] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DDI B/PHY B] <7> [84.517396] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:597:DDI TC1/PHY TC1] <7> [84.517626] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:599:DP-MST A] <7> [84.517856] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:600:DP-MST B] <7> [84.518103] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:601:DP-MST C] <7> [84.518321] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:602:DP-MST D] <7> [84.518540] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:607:DDI TC2/PHY TC2] <7> [84.518764] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:609:DP-MST A] <7> [84.518990] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST B] <7> [84.519230] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST C] <7> [84.519461] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST D] <7> [84.519698] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:616:DDI TC3/PHY TC3] <7> [84.519931] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:618:DP-MST A] <7> [84.520182] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:619:DP-MST B] <7> [84.520409] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DP-MST C] <7> [84.520606] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:621:DP-MST D] <7> [84.520766] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DDI TC4/PHY TC4] <7> [84.520924] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:627:DP-MST A] <7> [84.521093] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:628:DP-MST B] <7> [84.521253] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:629:DP-MST C] <7> [84.521411] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:630:DP-MST D] <7> [84.521698] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3 <7> [84.521901] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:447:pipe C] <7> [84.522065] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0 <7> [84.522332] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B <7> [84.522575] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C <7> [84.523292] i915 0000:00:02.0: [drm:intel_hdmi_handle_sink_scrambling [i915]] [CONNECTOR:588:HDMI-A-1] scrambling=no, TMDS bit clock ratio=1/10 <7> [84.523855] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1) <7> [84.524030] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK on first message, retry <7> [84.524654] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1) <7> [84.524876] i915 0000:00:02.0: [drm:drm_scdc_set_high_tmds_clock_ratio [drm_display_helper]] [CONNECTOR:588:HDMI-A-1] Failed to read TMDS config: -6 <7> [84.524902] i915 0000:00:02.0: [drm:intel_ddi_enable [i915]] [CONNECTOR:588:HDMI-A-1] Failed to configure sink scrambling/TMDS bit clock ratio <7> [84.541930] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:588:HDMI-A-1][ENCODER:587:DDI B/PHY B] Enable audio codec on [CRTC:447:pipe C], 64 bytes ELD <7> [84.549064] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x810 <7> [84.550263] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 285500 not found, falling back to defaults <7> [84.550461] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000) <7> [84.550626] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N <6> [84.550806] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 5 not expected <6> [84.550809] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 0 not expected <6> [84.550811] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 10 not expected <6> [84.550812] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 6 not expected <7> [84.550953] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:588:HDMI-A-1] <7> [84.551248] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:447:pipe C] <7> [84.553513] azx_init_pci: snd_hda_intel 0000:00:1f.3: Clearing TCSEL <7> [84.553547] azx_init_pci: snd_hda_intel 0000:00:1f.3: SCH snoop: Enabled <6> [91.357091] [IGT] kms_flip: finished subtest C-HDMI-A1, FAIL

Detail

Value

Duration

6.93 seconds

Hostname

shard-tglu-9

Igt-Version

IGT-Version: 2.4-g65d691069 (x86_64) (Linux: 7.1.0-rc4-Patchwork_166770v2-gf05be6b98588+ x86_64)

Out

Starting dynamic subtest: C-HDMI-A1
  1920x1080: 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2074 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest C-HDMI-A1: FAIL (6.931s)

Err

Starting dynamic subtest: C-HDMI-A1
[91.119918] (kms_flip:2102) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[91.119971] (kms_flip:2102) CRITICAL: Failed assertion: end - start < 500
[91.120021] (kms_flip:2102) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest C-HDMI-A1 failed.
**** DEBUG ****
[90.110608] (kms_flip:2102) DEBUG: Vblank took 20us
[90.119017] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.225906
last_received_ts = 90.225494
last_seq = 688
current_ts = 90.234238
current_received_ts = 90.233894
current_seq = 689
count = 683
seq_step = 1
[90.119061] (kms_flip:2102) DEBUG: Vblank took 31us
[90.127338] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.234238
last_received_ts = 90.233894
last_seq = 689
current_ts = 90.242569
current_received_ts = 90.242249
current_seq = 690
count = 684
seq_step = 1
[90.127370] (kms_flip:2102) DEBUG: Vblank took 24us
[90.135610] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.242569
last_received_ts = 90.242249
last_seq = 690
current_ts = 90.250908
current_received_ts = 90.250519
current_seq = 691
count = 685
seq_step = 1
[90.135640] (kms_flip:2102) DEBUG: Vblank took 22us
[90.143996] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.250908
last_received_ts = 90.250519
last_seq = 691
current_ts = 90.259239
current_received_ts = 90.258896
current_seq = 692
count = 686
seq_step = 1
[90.144039] (kms_flip:2102) DEBUG: Vblank took 33us
[90.152294] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.259239
last_received_ts = 90.258896
last_seq = 692
current_ts = 90.267570
current_received_ts = 90.267197
current_seq = 693
count = 687
seq_step = 1
[90.152329] (kms_flip:2102) DEBUG: Vblank took 26us
[90.160611] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.267570
last_received_ts = 90.267197
last_seq = 693
current_ts = 90.275909
current_received_ts = 90.275513
current_seq = 694
count = 688
seq_step = 1
[90.160642] (kms_flip:2102) DEBUG: Vblank took 23us
[90.168984] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.275909
last_received_ts = 90.275513
last_seq = 694
current_ts = 90.284241
current_received_ts = 90.283890
current_seq = 695
count = 689
seq_step = 1
[90.169012] (kms_flip:2102) DEBUG: Vblank took 22us
[90.177350] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.284241
last_received_ts = 90.283890
last_seq = 695
current_ts = 90.292572
current_received_ts = 90.292244
current_seq = 696
count = 690
seq_step = 1
[90.177395] (kms_flip:2102) DEBUG: Vblank took 33us
[90.185612] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.292572
last_received_ts = 90.292244
last_seq = 696
current_ts = 90.300911
current_received_ts = 90.300514
current_seq = 697
count = 691
seq_step = 1
[90.185642] (kms_flip:2102) DEBUG: Vblank took 24us
[90.194210] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.300911
last_received_ts = 90.300514
last_seq = 697
current_ts = 90.309242
current_received_ts = 90.309105
current_seq = 698
count = 692
seq_step = 1
[90.194249] (kms_flip:2102) DEBUG: Vblank took 26us
[90.202366] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.309242
last_received_ts = 90.309105
last_seq = 698
current_ts = 90.317574
current_received_ts = 90.317268
current_seq = 699
count = 693
seq_step = 1
[90.202404] (kms_flip:2102) DEBUG: Vblank took 29us
[90.210692] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.317574
last_received_ts = 90.317268
last_seq = 699
current_ts = 90.325912
current_received_ts = 90.325592
current_seq = 700
count = 694
seq_step = 1
[90.210726] (kms_flip:2102) DEBUG: Vblank took 26us
[90.218988] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.325912
last_received_ts = 90.325592
last_seq = 700
current_ts = 90.334244
current_received_ts = 90.333885
current_seq = 701
count = 695
seq_step = 1
[90.219023] (kms_flip:2102) DEBUG: Vblank took 25us
[90.227372] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.334244
last_received_ts = 90.333885
last_seq = 701
current_ts = 90.342583
current_received_ts = 90.342270
current_seq = 702
count = 696
seq_step = 1
[90.227403] (kms_flip:2102) DEBUG: Vblank took 23us
[90.235643] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.342583
last_received_ts = 90.342270
last_seq = 702
current_ts = 90.350914
current_received_ts = 90.350540
current_seq = 703
count = 697
seq_step = 1
[90.235673] (kms_flip:2102) DEBUG: Vblank took 23us
[90.244000] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.350914
last_received_ts = 90.350540
last_seq = 703
current_ts = 90.359245
current_received_ts = 90.358894
current_seq = 704
count = 698
seq_step = 1
[90.244035] (kms_flip:2102) DEBUG: Vblank took 27us
[90.252328] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.359245
last_received_ts = 90.358894
last_seq = 704
current_ts = 90.367584
current_received_ts = 90.367226
current_seq = 705
count = 699
seq_step = 1
[90.252357] (kms_flip:2102) DEBUG: Vblank took 22us
[90.260734] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.367584
last_received_ts = 90.367226
last_seq = 705
current_ts = 90.375916
current_received_ts = 90.375633
current_seq = 706
count = 700
seq_step = 1
[90.260763] (kms_flip:2102) DEBUG: Vblank took 22us
[90.269011] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.375916
last_received_ts = 90.375633
last_seq = 706
current_ts = 90.384247
current_received_ts = 90.383896
current_seq = 707
count = 701
seq_step = 1
[90.269056] (kms_flip:2102) DEBUG: Vblank took 33us
[90.277343] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.384247
last_received_ts = 90.383896
last_seq = 707
current_ts = 90.392578
current_received_ts = 90.392235
current_seq = 708
count = 702
seq_step = 1
[90.277377] (kms_flip:2102) DEBUG: Vblank took 26us
[90.285680] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.392578
last_received_ts = 90.392235
last_seq = 708
current_ts = 90.400917
current_received_ts = 90.400566
current_seq = 709
count = 703
seq_step = 1
[90.285725] (kms_flip:2102) DEBUG: Vblank took 33us
[90.293988] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.400917
last_received_ts = 90.400566
last_seq = 709
current_ts = 90.409248
current_received_ts = 90.408875
current_seq = 710
count = 704
seq_step = 1
[90.294043] (kms_flip:2102) DEBUG: Vblank took 36us
[90.302318] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.409248
last_received_ts = 90.408875
last_seq = 710
current_ts = 90.417587
current_received_ts = 90.417206
current_seq = 711
count = 705
seq_step = 1
[90.302359] (kms_flip:2102) DEBUG: Vblank took 32us
[90.310669] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.417587
last_received_ts = 90.417206
last_seq = 711
current_ts = 90.425919
current_received_ts = 90.425560
current_seq = 712
count = 706
seq_step = 1
[90.310710] (kms_flip:2102) DEBUG: Vblank took 31us
[90.319032] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.425919
last_received_ts = 90.425560
last_seq = 712
current_ts = 90.434250
current_received_ts = 90.433922
current_seq = 713
count = 707
seq_step = 1
[90.319079] (kms_flip:2102) DEBUG: Vblank took 36us
[90.327350] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.434250
last_received_ts = 90.433922
last_seq = 713
current_ts = 90.442581
current_received_ts = 90.442238
current_seq = 714
count = 708
seq_step = 1
[90.327397] (kms_flip:2102) DEBUG: Vblank took 37us
[90.335660] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.442581
last_received_ts = 90.442238
last_seq = 714
current_ts = 90.450920
current_received_ts = 90.450546
current_seq = 715
count = 709
seq_step = 1
[90.335711] (kms_flip:2102) DEBUG: Vblank took 39us
[90.344037] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.450920
last_received_ts = 90.450546
last_seq = 715
current_ts = 90.459251
current_received_ts = 90.458916
current_seq = 716
count = 710
seq_step = 1
[90.344090] (kms_flip:2102) DEBUG: Vblank took 40us
[90.352320] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.459251
last_received_ts = 90.458916
last_seq = 716
current_ts = 90.467583
current_received_ts = 90.467209
current_seq = 717
count = 711
seq_step = 1
[90.352364] (kms_flip:2102) DEBUG: Vblank took 34us
[90.360650] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.467583
last_received_ts = 90.467209
last_seq = 717
current_ts = 90.475922
current_received_ts = 90.475533
current_seq = 718
count = 712
seq_step = 1
[90.360692] (kms_flip:2102) DEBUG: Vblank took 32us
[90.369006] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.475922
last_received_ts = 90.475533
last_seq = 718
current_ts = 90.484253
current_received_ts = 90.483894
current_seq = 719
count = 713
seq_step = 1
[90.369045] (kms_flip:2102) DEBUG: Vblank took 30us
[90.377372] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.484253
last_received_ts = 90.483894
last_seq = 719
current_ts = 90.492584
current_received_ts = 90.492249
current_seq = 720
count = 714
seq_step = 1
[90.377423] (kms_flip:2102) DEBUG: Vblank took 39us
[90.385771] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.492584
last_received_ts = 90.492249
last_seq = 720
current_ts = 90.500916
current_received_ts = 90.500656
current_seq = 721
count = 715
seq_step = 1
[90.385812] (kms_flip:2102) DEBUG: Vblank took 31us
[90.394032] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.500916
last_received_ts = 90.500656
last_seq = 721
current_ts = 90.509254
current_received_ts = 90.508919
current_seq = 722
count = 716
seq_step = 1
[90.394071] (kms_flip:2102) DEBUG: Vblank took 30us
[90.402345] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.509254
last_received_ts = 90.508919
last_seq = 722
current_ts = 90.517586
current_received_ts = 90.517227
current_seq = 723
count = 717
seq_step = 1
[90.402383] (kms_flip:2102) DEBUG: Vblank took 30us
[90.410710] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.517586
last_received_ts = 90.517227
last_seq = 723
current_ts = 90.525925
current_received_ts = 90.525581
current_seq = 724
count = 718
seq_step = 1
[90.410764] (kms_flip:2102) DEBUG: Vblank took 40us
[90.419073] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.525925
last_received_ts = 90.525581
last_seq = 724
current_ts = 90.534256
current_received_ts = 90.533936
current_seq = 725
count = 719
seq_step = 1
[90.419147] (kms_flip:2102) DEBUG: Vblank took 56us
[90.427443] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.534256
last_received_ts = 90.533936
last_seq = 725
current_ts = 90.542587
current_received_ts = 90.542313
current_seq = 726
count = 720
seq_step = 1
[90.427497] (kms_flip:2102) DEBUG: Vblank took 39us
[90.435652] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.542587
last_received_ts = 90.542313
last_seq = 726
current_ts = 90.550926
current_received_ts = 90.550537
current_seq = 727
count = 721
seq_step = 1
[90.435688] (kms_flip:2102) DEBUG: Vblank took 29us
[90.444046] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.550926
last_received_ts = 90.550537
last_seq = 727
current_ts = 90.559265
current_received_ts = 90.558922
current_seq = 728
count = 722
seq_step = 1
[90.444095] (kms_flip:2102) DEBUG: Vblank took 37us
[90.452335] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.559265
last_received_ts = 90.558922
last_seq = 728
current_ts = 90.567589
current_received_ts = 90.567215
current_seq = 729
count = 723
seq_step = 1
[90.452379] (kms_flip:2102) DEBUG: Vblank took 33us
[90.460693] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.567589
last_received_ts = 90.567215
last_seq = 729
current_ts = 90.575928
current_received_ts = 90.575569
current_seq = 730
count = 724
seq_step = 1
[90.460735] (kms_flip:2102) DEBUG: Vblank took 32us
[90.469028] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.575928
last_received_ts = 90.575569
last_seq = 730
current_ts = 90.584259
current_received_ts = 90.583893
current_seq = 731
count = 725
seq_step = 1
[90.469088] (kms_flip:2102) DEBUG: Vblank took 44us
[90.477346] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.584259
last_received_ts = 90.583893
last_seq = 731
current_ts = 90.592598
current_received_ts = 90.592216
current_seq = 732
count = 726
seq_step = 1
[90.477389] (kms_flip:2102) DEBUG: Vblank took 33us
[90.485664] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.592598
last_received_ts = 90.592216
last_seq = 732
current_ts = 90.600929
current_received_ts = 90.600540
current_seq = 733
count = 727
seq_step = 1
[90.485705] (kms_flip:2102) DEBUG: Vblank took 32us
[90.494043] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.600929
last_received_ts = 90.600540
last_seq = 733
current_ts = 90.609268
current_received_ts = 90.608917
current_seq = 734
count = 728
seq_step = 1
[90.494087] (kms_flip:2102) DEBUG: Vblank took 33us
[90.502493] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.609268
last_received_ts = 90.608917
last_seq = 734
current_ts = 90.617599
current_received_ts = 90.617355
current_seq = 735
count = 729
seq_step = 1
[90.502550] (kms_flip:2102) DEBUG: Vblank took 43us
[90.510784] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.617599
last_received_ts = 90.617355
last_seq = 735
current_ts = 90.625931
current_received_ts = 90.625648
current_seq = 736
count = 730
seq_step = 1
[90.510880] (kms_flip:2102) DEBUG: Vblank took 80us
[90.519077] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.625931
last_received_ts = 90.625648
last_seq = 736
current_ts = 90.634262
current_received_ts = 90.633942
current_seq = 737
count = 731
seq_step = 1
[90.519148] (kms_flip:2102) DEBUG: Vblank took 56us
[90.527427] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.634262
last_received_ts = 90.633942
last_seq = 737
current_ts = 90.642601
current_received_ts = 90.642296
current_seq = 738
count = 732
seq_step = 1
[90.527468] (kms_flip:2102) DEBUG: Vblank took 32us
[90.535703] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.642601
last_received_ts = 90.642296
last_seq = 738
current_ts = 90.650932
current_received_ts = 90.650574
current_seq = 739
count = 733
seq_step = 1
[90.535745] (kms_flip:2102) DEBUG: Vblank took 32us
[90.544062] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.650932
last_received_ts = 90.650574
last_seq = 739
current_ts = 90.659264
current_received_ts = 90.658928
current_seq = 740
count = 734
seq_step = 1
[90.544110] (kms_flip:2102) DEBUG: Vblank took 37us
[90.552400] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.659264
last_received_ts = 90.658928
last_seq = 740
current_ts = 90.667603
current_received_ts = 90.667259
current_seq = 741
count = 735
seq_step = 1
[90.552454] (kms_flip:2102) DEBUG: Vblank took 39us
[90.560716] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.667603
last_received_ts = 90.667259
last_seq = 741
current_ts = 90.675934
current_received_ts = 90.675575
current_seq = 742
count = 736
seq_step = 1
[90.560772] (kms_flip:2102) DEBUG: Vblank took 43us
[90.569262] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.675934
last_received_ts = 90.675575
last_seq = 742
current_ts = 90.684265
current_received_ts = 90.684120
current_seq = 743
count = 737
seq_step = 1
[90.569313] (kms_flip:2102) DEBUG: Vblank took 34us
[90.577378] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.684265
last_received_ts = 90.684120
last_seq = 743
current_ts = 90.692596
current_received_ts = 90.692245
current_seq = 744
count = 738
seq_step = 1
[90.577423] (kms_flip:2102) DEBUG: Vblank took 33us
[90.585752] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.692596
last_received_ts = 90.692245
last_seq = 744
current_ts = 90.700935
current_received_ts = 90.700607
current_seq = 745
count = 739
seq_step = 1
[90.585808] (kms_flip:2102) DEBUG: Vblank took 41us
[90.594034] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.700935
last_received_ts = 90.700607
last_seq = 745
current_ts = 90.709267
current_received_ts = 90.708900
current_seq = 746
count = 740
seq_step = 1
[90.594082] (kms_flip:2102) DEBUG: Vblank took 37us
[90.602387] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.709267
last_received_ts = 90.708900
last_seq = 746
current_ts = 90.717606
current_received_ts = 90.717255
current_seq = 747
count = 741
seq_step = 1
[90.602430] (kms_flip:2102) DEBUG: Vblank took 34us
[90.610728] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.717606
last_received_ts = 90.717255
last_seq = 747
current_ts = 90.725937
current_received_ts = 90.725594
current_seq = 748
count = 742
seq_step = 1
[90.610765] (kms_flip:2102) DEBUG: Vblank took 28us
[90.619112] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.725937
last_received_ts = 90.725594
last_seq = 748
current_ts = 90.734276
current_received_ts = 90.733971
current_seq = 749
count = 743
seq_step = 1
[90.619197] (kms_flip:2102) DEBUG: Vblank took 45us
[90.627474] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.734276
last_received_ts = 90.733971
last_seq = 749
current_ts = 90.742607
current_received_ts = 90.742310
current_seq = 750
count = 744
seq_step = 1
[90.627513] (kms_flip:2102) DEBUG: Vblank took 29us
[90.635741] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.742607
last_received_ts = 90.742310
last_seq = 750
current_ts = 90.750938
current_received_ts = 90.750603
current_seq = 751
count = 745
seq_step = 1
[90.635780] (kms_flip:2102) DEBUG: Vblank took 31us
[90.644025] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.750938
last_received_ts = 90.750603
last_seq = 751
current_ts = 90.759270
current_received_ts = 90.758888
current_seq = 752
count = 746
seq_step = 1
[90.644066] (kms_flip:2102) DEBUG: Vblank took 31us
[90.652429] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.759270
last_received_ts = 90.758888
last_seq = 752
current_ts = 90.767609
current_received_ts = 90.767288
current_seq = 753
count = 747
seq_step = 1
[90.652480] (kms_flip:2102) DEBUG: Vblank took 38us
[90.660724] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.767609
last_received_ts = 90.767288
last_seq = 753
current_ts = 90.775940
current_received_ts = 90.775574
current_seq = 754
count = 748
seq_step = 1
[90.660778] (kms_flip:2102) DEBUG: Vblank took 39us
[90.669064] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.775940
last_received_ts = 90.775574
last_seq = 754
current_ts = 90.784271
current_received_ts = 90.783920
current_seq = 755
count = 749
seq_step = 1
[90.669107] (kms_flip:2102) DEBUG: Vblank took 33us
[90.677435] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.784271
last_received_ts = 90.783920
last_seq = 755
current_ts = 90.792610
current_received_ts = 90.792282
current_seq = 756
count = 750
seq_step = 1
[90.677490] (kms_flip:2102) DEBUG: Vblank took 40us
[90.685697] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.792610
last_received_ts = 90.792282
last_seq = 756
current_ts = 90.800941
current_received_ts = 90.800560
current_seq = 757
count = 751
seq_step = 1
[90.685738] (kms_flip:2102) DEBUG: Vblank took 31us
[90.694100] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.800941
last_received_ts = 90.800560
last_seq = 757
current_ts = 90.809280
current_received_ts = 90.808952
current_seq = 758
count = 752
seq_step = 1
[90.694170] (kms_flip:2102) DEBUG: Vblank took 58us
[90.702397] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.809280
last_received_ts = 90.808952
last_seq = 758
current_ts = 90.817612
current_received_ts = 90.817253
current_seq = 759
count = 753
seq_step = 1
[90.702439] (kms_flip:2102) DEBUG: Vblank took 30us
[90.710850] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.817612
last_received_ts = 90.817253
last_seq = 759
current_ts = 90.825943
current_received_ts = 90.825699
current_seq = 760
count = 754
seq_step = 1
[90.710899] (kms_flip:2102) DEBUG: Vblank took 34us
[90.719042] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.825943
last_received_ts = 90.825699
last_seq = 760
current_ts = 90.834282
current_received_ts = 90.833900
current_seq = 761
count = 755
seq_step = 1
[90.719084] (kms_flip:2102) DEBUG: Vblank took 34us
[90.727414] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.834282
last_received_ts = 90.833900
last_seq = 761
current_ts = 90.842606
current_received_ts = 90.842270
current_seq = 762
count = 756
seq_step = 1
[90.727456] (kms_flip:2102) DEBUG: Vblank took 32us
[90.735728] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.842606
last_received_ts = 90.842270
last_seq = 762
current_ts = 90.850945
current_received_ts = 90.850578
current_seq = 763
count = 757
seq_step = 1
[90.735783] (kms_flip:2102) DEBUG: Vblank took 41us
[90.744092] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.850945
last_received_ts = 90.850578
last_seq = 763
current_ts = 90.859283
current_received_ts = 90.858948
current_seq = 764
count = 758
seq_step = 1
[90.744163] (kms_flip:2102) DEBUG: Vblank took 60us
[90.752458] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.859283
last_received_ts = 90.858948
last_seq = 764
current_ts = 90.867615
current_received_ts = 90.867287
current_seq = 765
count = 759
seq_step = 1
[90.752498] (kms_flip:2102) DEBUG: Vblank took 30us
[90.760803] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.867615
last_received_ts = 90.867287
last_seq = 765
current_ts = 90.875946
current_received_ts = 90.875656
current_seq = 766
count = 760
seq_step = 1
[90.760847] (kms_flip:2102) DEBUG: Vblank took 34us
[90.769080] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.875946
last_received_ts = 90.875656
last_seq = 766
current_ts = 90.884285
current_received_ts = 90.883934
current_seq = 767
count = 761
seq_step = 1
[90.769118] (kms_flip:2102) DEBUG: Vblank took 30us
[90.777435] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.884285
last_received_ts = 90.883934
last_seq = 767
current_ts = 90.892616
current_received_ts = 90.892288
current_seq = 768
count = 762
seq_step = 1
[90.777481] (kms_flip:2102) DEBUG: Vblank took 35us
[90.785861] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.892616
last_received_ts = 90.892288
last_seq = 768
current_ts = 90.900955
current_received_ts = 90.900703
current_seq = 769
count = 763
seq_step = 1
[90.785908] (kms_flip:2102) DEBUG: Vblank took 31us
[90.794094] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.900955
last_received_ts = 90.900703
last_seq = 769
current_ts = 90.909286
current_received_ts = 90.908943
current_seq = 770
count = 764
seq_step = 1
[90.794153] (kms_flip:2102) DEBUG: Vblank took 32us
[90.802481] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.909286
last_received_ts = 90.908943
last_seq = 770
current_ts = 90.917618
current_received_ts = 90.917328
current_seq = 771
count = 765
seq_step = 1
[90.802523] (kms_flip:2102) DEBUG: Vblank took 31us
[90.810714] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.917618
last_received_ts = 90.917328
last_seq = 771
current_ts = 90.925949
current_received_ts = 90.925568
current_seq = 772
count = 766
seq_step = 1
[90.810754] (kms_flip:2102) DEBUG: Vblank took 31us
[90.819239] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.925949
last_received_ts = 90.925568
last_seq = 772
current_ts = 90.934288
current_received_ts = 90.934082
current_seq = 773
count = 767
seq_step = 1
[90.819291] (kms_flip:2102) DEBUG: Vblank took 36us
[90.827391] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.934288
last_received_ts = 90.934082
last_seq = 773
current_ts = 90.942619
current_received_ts = 90.942238
current_seq = 774
count = 768
seq_step = 1
[90.827436] (kms_flip:2102) DEBUG: Vblank took 34us
[90.835798] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.942619
last_received_ts = 90.942238
last_seq = 774
current_ts = 90.950951
current_received_ts = 90.950638
current_seq = 775
count = 769
seq_step = 1
[90.835855] (kms_flip:2102) DEBUG: Vblank took 40us
[90.844124] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.950951
last_received_ts = 90.950638
last_seq = 775
current_ts = 90.959290
current_received_ts = 90.958969
current_seq = 776
count = 770
seq_step = 1
[90.844206] (kms_flip:2102) DEBUG: Vblank took 69us
[90.852430] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.959290
last_received_ts = 90.958969
last_seq = 776
current_ts = 90.967621
current_received_ts = 90.967278
current_seq = 777
count = 771
seq_step = 1
[90.852473] (kms_flip:2102) DEBUG: Vblank took 33us
[90.860799] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.967621
last_received_ts = 90.967278
last_seq = 777
current_ts = 90.975960
current_received_ts = 90.975639
current_seq = 778
count = 772
seq_step = 1
[90.860848] (kms_flip:2102) DEBUG: Vblank took 36us
[90.869123] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.975960
last_received_ts = 90.975639
last_seq = 778
current_ts = 90.984283
current_received_ts = 90.983963
current_seq = 779
count = 773
seq_step = 1
[90.869208] (kms_flip:2102) DEBUG: Vblank took 68us
[90.877515] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.984283
last_received_ts = 90.983963
last_seq = 779
current_ts = 90.992622
current_received_ts = 90.992355
current_seq = 780
count = 774
seq_step = 1
[90.877555] (kms_flip:2102) DEBUG: Vblank took 30us
[90.885786] (kms_flip:2102) DEBUG: name = flip
last_ts = 90.992622
last_received_ts = 90.992355
last_seq = 780
current_ts = 91.000954
current_received_ts = 91.000633
current_seq = 781
count = 775
seq_step = 1
[90.885854] (kms_flip:2102) DEBUG: Vblank took 58us
[90.894100] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.000954
last_received_ts = 91.000633
last_seq = 781
current_ts = 91.009293
current_received_ts = 91.008942
current_seq = 782
count = 776
seq_step = 1
[90.894158] (kms_flip:2102) DEBUG: Vblank took 34us
[90.902481] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.009293
last_received_ts = 91.008942
last_seq = 782
current_ts = 91.017624
current_received_ts = 91.017319
current_seq = 783
count = 777
seq_step = 1
[90.902523] (kms_flip:2102) DEBUG: Vblank took 32us
[90.910788] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.017624
last_received_ts = 91.017319
last_seq = 783
current_ts = 91.025955
current_received_ts = 91.025620
current_seq = 784
count = 778
seq_step = 1
[90.910844] (kms_flip:2102) DEBUG: Vblank took 40us
[90.919169] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.025955
last_received_ts = 91.025620
last_seq = 784
current_ts = 91.034294
current_received_ts = 91.033989
current_seq = 785
count = 779
seq_step = 1
[90.919228] (kms_flip:2102) DEBUG: Vblank took 46us
[90.927468] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.034294
last_received_ts = 91.033989
last_seq = 785
current_ts = 91.042625
current_received_ts = 91.042297
current_seq = 786
count = 780
seq_step = 1
[90.927516] (kms_flip:2102) DEBUG: Vblank took 33us
[90.935783] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.042625
last_received_ts = 91.042297
last_seq = 786
current_ts = 91.050957
current_received_ts = 91.050629
current_seq = 787
count = 781
seq_step = 1
[90.935820] (kms_flip:2102) DEBUG: Vblank took 30us
[90.944188] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.050957
last_received_ts = 91.050629
last_seq = 787
current_ts = 91.059296
current_received_ts = 91.058983
current_seq = 788
count = 782
seq_step = 1
[90.944236] (kms_flip:2102) DEBUG: Vblank took 33us
[90.952470] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.059296
last_received_ts = 91.058983
last_seq = 788
current_ts = 91.067635
current_received_ts = 91.067299
current_seq = 789
count = 783
seq_step = 1
[90.952522] (kms_flip:2102) DEBUG: Vblank took 40us
[90.960779] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.067635
last_received_ts = 91.067299
last_seq = 789
current_ts = 91.075958
current_received_ts = 91.075615
current_seq = 790
count = 784
seq_step = 1
[90.960823] (kms_flip:2102) DEBUG: Vblank took 34us
[90.969114] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.075958
last_received_ts = 91.075615
last_seq = 790
current_ts = 91.084297
current_received_ts = 91.083939
current_seq = 791
count = 785
seq_step = 1
[90.969192] (kms_flip:2102) DEBUG: Vblank took 59us
[90.977502] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.084297
last_received_ts = 91.083939
last_seq = 791
current_ts = 91.092628
current_received_ts = 91.092331
current_seq = 792
count = 786
seq_step = 1
[90.977559] (kms_flip:2102) DEBUG: Vblank took 42us
[90.985841] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.092628
last_received_ts = 91.092331
last_seq = 792
current_ts = 91.100960
current_received_ts = 91.100662
current_seq = 793
count = 787
seq_step = 1
[90.985893] (kms_flip:2102) DEBUG: Vblank took 35us
[90.994137] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.100960
last_received_ts = 91.100662
last_seq = 793
current_ts = 91.109299
current_received_ts = 91.108971
current_seq = 794
count = 788
seq_step = 1
[90.994223] (kms_flip:2102) DEBUG: Vblank took 75us
[91.002597] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.109299
last_received_ts = 91.108971
last_seq = 794
current_ts = 91.117630
current_received_ts = 91.117424
current_seq = 795
count = 789
seq_step = 1
[91.002651] (kms_flip:2102) DEBUG: Vblank took 39us
[91.010819] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.117630
last_received_ts = 91.117424
last_seq = 795
current_ts = 91.125961
current_received_ts = 91.125633
current_seq = 796
count = 790
seq_step = 1
[91.010873] (kms_flip:2102) DEBUG: Vblank took 38us
[91.019150] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.125961
last_received_ts = 91.125633
last_seq = 796
current_ts = 91.134300
current_received_ts = 91.133972
current_seq = 797
count = 791
seq_step = 1
[91.019227] (kms_flip:2102) DEBUG: Vblank took 40us
[91.027554] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.134300
last_received_ts = 91.133972
last_seq = 797
current_ts = 91.142632
current_received_ts = 91.142380
current_seq = 798
count = 792
seq_step = 1
[91.027609] (kms_flip:2102) DEBUG: Vblank took 40us
[91.035786] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.142632
last_received_ts = 91.142380
last_seq = 798
current_ts = 91.150970
current_received_ts = 91.150612
current_seq = 799
count = 793
seq_step = 1
[91.035842] (kms_flip:2102) DEBUG: Vblank took 43us
[91.044152] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.150970
last_received_ts = 91.150612
last_seq = 799
current_ts = 91.159302
current_received_ts = 91.158981
current_seq = 800
count = 794
seq_step = 1
[91.044226] (kms_flip:2102) DEBUG: Vblank took 41us
[91.052497] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.159302
last_received_ts = 91.158981
last_seq = 800
current_ts = 91.167633
current_received_ts = 91.167320
current_seq = 801
count = 795
seq_step = 1
[91.052546] (kms_flip:2102) DEBUG: Vblank took 33us
[91.060754] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.167633
last_received_ts = 91.167320
last_seq = 801
current_ts = 91.175964
current_received_ts = 91.175583
current_seq = 802
count = 796
seq_step = 1
[91.060797] (kms_flip:2102) DEBUG: Vblank took 33us
[91.069195] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.175964
last_received_ts = 91.175583
last_seq = 802
current_ts = 91.184303
current_received_ts = 91.183975
current_seq = 803
count = 797
seq_step = 1
[91.069242] (kms_flip:2102) DEBUG: Vblank took 33us
[91.077426] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.184303
last_received_ts = 91.183975
last_seq = 803
current_ts = 91.192635
current_received_ts = 91.192253
current_seq = 804
count = 798
seq_step = 1
[91.077471] (kms_flip:2102) DEBUG: Vblank took 34us
[91.085841] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.192635
last_received_ts = 91.192253
last_seq = 804
current_ts = 91.200974
current_received_ts = 91.200661
current_seq = 805
count = 799
seq_step = 1
[91.085890] (kms_flip:2102) DEBUG: Vblank took 33us
[91.094152] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.200974
last_received_ts = 91.200661
last_seq = 805
current_ts = 91.209305
current_received_ts = 91.208977
current_seq = 806
count = 800
seq_step = 1
[91.094209] (kms_flip:2102) DEBUG: Vblank took 33us
[91.102553] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.209305
last_received_ts = 91.208977
last_seq = 806
current_ts = 91.217636
current_received_ts = 91.217369
current_seq = 807
count = 801
seq_step = 1
[91.102606] (kms_flip:2102) DEBUG: Vblank took 39us
[91.110832] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.217636
last_received_ts = 91.217369
last_seq = 807
current_ts = 91.225975
current_received_ts = 91.225655
current_seq = 808
count = 802
seq_step = 1
[91.110910] (kms_flip:2102) DEBUG: Vblank took 66us
[91.119136] (kms_flip:2102) DEBUG: name = flip
last_ts = 91.225975
last_received_ts = 91.225655
last_seq = 808
current_ts = 91.234306
current_received_ts = 91.233948
current_seq = 809
count = 803
seq_step = 1
[91.119911] (kms_flip:2102) DEBUG: Vblank took 758us
[91.119918] (kms_flip:2102) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[91.119971] (kms_flip:2102) CRITICAL: Failed assertion: end - start < 500
[91.120021] (kms_flip:2102) CRITICAL: Last errno: 4, Interrupted system call
[91.158383] (kms_flip:2102) igt_core-INFO: Stack trace:
[91.171309] (kms_flip:2102) igt_core-INFO:   #0 ../lib/igt_core.c:2074 __igt_fail_assert()
[91.172858] (kms_flip:2102) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
[91.172968] (kms_flip:2102) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
[91.173056] (kms_flip:2102) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
[91.173113] (kms_flip:2102) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
[91.178663] (kms_flip:2102) igt_core-INFO:   #5 [__libc_init_first+0x8a]
[91.180146] (kms_flip:2102) igt_core-INFO:   #6 [__libc_start_main+0x8b]
[91.180474] (kms_flip:2102) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-HDMI-A1: FAIL (6.931s)

Dmesg

<6> [84.426163] [IGT] kms_flip: starting dynamic subtest C-HDMI-A1

<7> [84.426990] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:637]

<7> [84.427308] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:638]

<7> [84.448058] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:171:pipe A]

<7> [84.448370] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:309:pipe B]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [84.455177] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in avi infoframe

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

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

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

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

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

<7> [84.455532] i915 0000:00:02.0: picture aspect: No Data

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

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

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

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

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

<7> [84.455548] i915 0000:00:02.0: video code: 0

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

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

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

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

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

<7> [84.455757] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in spd infoframe

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

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

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

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

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

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

<7> [84.456296] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:309:pipe B] fastset requirement not met in hdmi infoframe

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

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

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

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

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

<7> [84.456933] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:309:pipe B] releasing DPLL 0

<7> [84.457149] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no

<7> [84.457310] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:309:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0

<7> [84.457505] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:303:cursor B] ddb (1993 - 2048) -> ( 0 - 0), size 55 -> 0

<7> [84.457684] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:309:pipe B] min cdclk: 192000 kHz -> 0 kHz

<7> [84.457875] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change

<7> [84.458035] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 172800 kHz, actual 172800 kHz

<7> [84.458214] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0

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

<7> [84.458556] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:173:plane 1B] fb: [NOFB], visible: no

<7> [84.458718] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:203:plane 2B] fb: [NOFB], visible: no

<7> [84.458877] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:233:plane 3B] fb: [NOFB], visible: no

<7> [84.459036] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:263:plane 4B] fb: [NOFB], visible: no

<7> [84.459216] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:273:plane 5B] fb: [NOFB], visible: no

<7> [84.459387] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:283:plane 6B] fb: [NOFB], visible: no

<7> [84.459542] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:293:plane 7B] fb: [NOFB], visible: no

<7> [84.459700] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:303:cursor B] fb: [NOFB], visible: no

<7> [84.459937] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:588:HDMI-A-1][ENCODER:587:DDI B/PHY B] Disable audio codec on [CRTC:309:pipe B]

<7> [84.473127] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port B

<7> [84.476086] i915 0000:00:02.0: [drm:intel_hdmi_handle_sink_scrambling [i915]] [CONNECTOR:588:HDMI-A-1] scrambling=no, TMDS bit clock ratio=1/10

<7> [84.476607] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1)

<7> [84.476761] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK on first message, retry

<7> [84.477346] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1)

<7> [84.477583] i915 0000:00:02.0: [drm:drm_scdc_set_high_tmds_clock_ratio [drm_display_helper]] [CONNECTOR:588:HDMI-A-1] Failed to read TMDS config: -6

<7> [84.477610] i915 0000:00:02.0: [drm:intel_ddi_disable [i915]] [CONNECTOR:588:HDMI-A-1] Failed to reset sink scrambling/TMDS bit clock ratio

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

<7> [84.483100] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B

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

<7> [84.483503] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling DPLL 0

<7> [84.483682] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 172800 kHz, VCO 345600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

<7> [84.483935] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DDI B/PHY B]

<7> [84.484140] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:597:DDI TC1/PHY TC1]

<7> [84.484306] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:599:DP-MST A]

<7> [84.484469] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:600:DP-MST B]

<7> [84.484630] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:601:DP-MST C]

<7> [84.484791] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:602:DP-MST D]

<7> [84.484953] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:607:DDI TC2/PHY TC2]

<7> [84.485194] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:609:DP-MST A]

<7> [84.485353] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST B]

<7> [84.485512] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST C]

<7> [84.485673] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST D]

<7> [84.485855] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:616:DDI TC3/PHY TC3]

<7> [84.486020] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:618:DP-MST A]

<7> [84.486300] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:619:DP-MST B]

<7> [84.486459] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DP-MST C]

<7> [84.486619] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:621:DP-MST D]

<7> [84.486847] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DDI TC4/PHY TC4]

<7> [84.487006] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:627:DP-MST A]

<7> [84.487178] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:628:DP-MST B]

<7> [84.487337] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:629:DP-MST C]

<7> [84.487496] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:630:DP-MST D]

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

<7> [84.487965] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1

<7> [84.488195] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_3

<7> [84.488380] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_2

<7> [84.488566] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:309:pipe B]

<7> [84.489011] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:447:pipe C]

<7> [84.489190] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:585:pipe D]

<7> [84.489333] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:447:pipe C]

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

<7> [84.489430] i915 0000:00:02.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:588:HDMI-A-1] Limiting target display pipe bpp to 24 (EDID bpp 24, max requested bpp 36, max platform bpp 36)

<7> [84.489610] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)

<7> [84.489775] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:447:pipe C] hw max bpp: 24, pipe bpp: 24, dithering: 0

<7> [84.489943] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:587:DDI B/PHY B] [CRTC:447:pipe C]

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

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

<7> [84.490507] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)

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

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

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

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

<7> [84.491434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2080)

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

<7> [84.491752] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2080)

<7> [84.491912] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 1968)

<7> [84.492083] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2000)

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

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

<7> [84.492572] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083)

<7> [84.492731] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088)

<7> [84.492890] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1144)

<7> [84.493048] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1144)

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

<7> [84.493385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2080)

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

<7> [84.493699] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2080)

<7> [84.493856] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 1968)

<7> [84.494013] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2000)

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

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

<7> [84.494507] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083)

<7> [84.494663] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088)

<7> [84.494847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1144)

<7> [84.495082] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1144)

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

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

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

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

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

<7> [84.496465] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in dpll_hw_state

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

<7> [84.496904] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: cfgcr0: 0x0, cfgcr1: 0x0, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0

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

<7> [84.497361] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: cfgcr0: 0x1801be, cfgcr1: 0x488, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0

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

<7> [84.497715] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 285500)

<7> [84.497873] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 285500)

<7> [84.498030] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in port_clock (expected 0, found 285500)

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

<7> [84.498370] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in avi infoframe

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

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

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

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

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

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

<7> [84.498846] i915 0000:00:02.0: picture aspect: No Data

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

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

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

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

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

<7> [84.498854] i915 0000:00:02.0: video code: 0

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

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

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

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

<7> [84.498862] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in spd infoframe

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

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

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

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

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

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

<7> [84.499448] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:447:pipe C] fastset requirement not met in hdmi infoframe

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

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

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

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

<7> [84.499928] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:447:pipe C] fastset requirement not met, forcing full modeset

<7> [84.500145] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no

<7> [84.500326] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:447:pipe C] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4

<7> [84.500525] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:311:plane 1C] ddb ( 0 - 0) -> ( 0 - 1993), size 0 -> 1993

<7> [84.500683] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:441:cursor C] ddb ( 0 - 0) -> (1993 - 2048), size 0 -> 55

<7> [84.500840] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm

<7> [84.501000] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 8, 8, 8, 8, 11, 16, 16, 0, 0, 0

<7> [84.501212] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 129, 129, 129, 129, 177, 257, 257, 30, 0, 0

<7> [84.501434] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:311:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 143, 143, 143, 143, 196, 284, 284, 31, 0, 0

<7> [84.501690] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] [CRTC:447:pipe C] data rate 1142000 num active planes 1

<7> [84.501926] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 14993 required 1142

<7> [84.502163] i915 0000:00:02.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<7> [84.502420] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:447:pipe C] min cdclk: 0 kHz -> 192000 kHz

<7> [84.502728] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change

<7> [84.502947] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz

<7> [84.503183] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0

<7> [84.503408] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:447:pipe C] allocated DPLL 0

<7> [84.503636] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:447:pipe C] reserving DPLL 0

<7> [84.503875] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:447:pipe C] enable: yes [modeset]

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

<7> [84.504288] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: C, pipe bpp: 24, dithering: 0

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

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

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

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

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

<7> [84.505264] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x0

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

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

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

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

<7> [84.505429] i915 0000:00:02.0: picture aspect: No Data

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

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

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

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

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

<7> [84.505437] i915 0000:00:02.0: video code: 0

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

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

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

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

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

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

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

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

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

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

<7> [84.505454] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 0f 00 6d a2 00 7f 00 00 00 00 00 00 00 00

<7> [84.505613] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 0d 82 34 12 66 69 74 48 65 61 64 6c 65 73 73 47

<7> [84.505770] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 53 7f 7f 28 0f 7f 07 17 7f ff 3f 7f ff 47 7f ff

<7> [84.505926] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 5f 7f 82 7f 7f 00 7f 7f 51 7f 7f 30 77 7f 03 00

<7> [84.506091] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2

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

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

<7> [84.506560] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1081, vmax vblank: 1081, vmin vtotal: 1144, vmax vtotal: 1144

<7> [84.506715] 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> [84.506872] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x48 0x5

<7> [84.507028] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x48 0x5

<7> [84.507200] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=285500, hd=1920 hb=1920-2080 hs=1968-2000 ht=2080, vd=1080 vb=1080-1144 vs=1083-1088 vt=1144, flags=0x5

<7> [84.507358] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 120 285500 1920 1968 2000 2080 1080 1083 1088 1144 0x40 0x5

<7> [84.507515] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=285500, hd=1920 hb=1920-2080 hs=1968-2000 ht=2080, vd=1080 vb=1080-1144 vs=1083-1088 vt=1144, flags=0x5

<7> [84.507672] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 285500, pixel rate 285500, min cdclk 192000, min voltage level 0

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

<7> [84.507982] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0

<7> [84.508154] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0

<7> [84.508113] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off

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

<7> [84.508393] i915 0000:00:02.0: [drm:skl_enable_dc6 [i915]] Enabling DC6

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

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

<7> [84.508637] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 02

<7> [84.508825] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x1801be, cfgcr1: 0x488, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0

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

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

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

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

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

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

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

<7> [84.510484] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000

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

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

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

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

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

<7> [84.511789] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:311:plane 1C] fb: [FB:637] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes

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

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

<7> [84.512280] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:341:plane 2C] fb: [NOFB], visible: no

<7> [84.512438] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 3C] fb: [NOFB], visible: no

<7> [84.512596] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:401:plane 4C] fb: [NOFB], visible: no

<7> [84.512752] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:411:plane 5C] fb: [NOFB], visible: no

<7> [84.512908] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:421:plane 6C] fb: [NOFB], visible: no

<7> [84.513064] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:431:plane 7C] fb: [NOFB], visible: no

<7> [84.513296] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:441:cursor C] fb: [NOFB], visible: no

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

<7> [84.514213] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off

<7> [84.514901] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 02 to 00

<7> [84.516099] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_2

<7> [84.516318] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_3

<7> [84.516557] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_4

<7> [84.516837] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 192000 kHz, VCO 384000 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

<7> [84.517171] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:587:DDI B/PHY B]

<7> [84.517396] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:597:DDI TC1/PHY TC1]

<7> [84.517626] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:599:DP-MST A]

<7> [84.517856] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:600:DP-MST B]

<7> [84.518103] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:601:DP-MST C]

<7> [84.518321] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:602:DP-MST D]

<7> [84.518540] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:607:DDI TC2/PHY TC2]

<7> [84.518764] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:609:DP-MST A]

<7> [84.518990] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:610:DP-MST B]

<7> [84.519230] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:611:DP-MST C]

<7> [84.519461] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:612:DP-MST D]

<7> [84.519698] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:616:DDI TC3/PHY TC3]

<7> [84.519931] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:618:DP-MST A]

<7> [84.520182] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:619:DP-MST B]

<7> [84.520409] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:620:DP-MST C]

<7> [84.520606] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:621:DP-MST D]

<7> [84.520766] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:625:DDI TC4/PHY TC4]

<7> [84.520924] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:627:DP-MST A]

<7> [84.521093] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:628:DP-MST B]

<7> [84.521253] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:629:DP-MST C]

<7> [84.521411] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:630:DP-MST D]

<7> [84.521698] i915 0000:00:02.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3

<7> [84.521901] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable DPLL 0 (active 0x4, on? 0) for [CRTC:447:pipe C]

<7> [84.522065] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling DPLL 0

<7> [84.522332] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B

<7> [84.522575] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C

<7> [84.523292] i915 0000:00:02.0: [drm:intel_hdmi_handle_sink_scrambling [i915]] [CONNECTOR:588:HDMI-A-1] scrambling=no, TMDS bit clock ratio=1/10

<7> [84.523855] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1)

<7> [84.524030] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK on first message, retry

<7> [84.524654] i915 0000:00:02.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpb] NAK for addr: 0054 w(1)

<7> [84.524876] i915 0000:00:02.0: [drm:drm_scdc_set_high_tmds_clock_ratio [drm_display_helper]] [CONNECTOR:588:HDMI-A-1] Failed to read TMDS config: -6

<7> [84.524902] i915 0000:00:02.0: [drm:intel_ddi_enable [i915]] [CONNECTOR:588:HDMI-A-1] Failed to configure sink scrambling/TMDS bit clock ratio

<7> [84.541930] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:588:HDMI-A-1][ENCODER:587:DDI B/PHY B] Enable audio codec on [CRTC:447:pipe C], 64 bytes ELD

<7> [84.549064] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x810

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

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

<7> [84.550626] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N

<6> [84.550806] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 5 not expected

<6> [84.550809] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 0 not expected

<6> [84.550811] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 10 not expected

<6> [84.550812] snd_hda_codec_intelhdmi hdaudioC0D2: HDMI: audio coding xtype 6 not expected

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

<7> [84.551248] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:447:pipe C]

<7> [84.553513] azx_init_pci: snd_hda_intel 0000:00:1f.3: Clearing TCSEL

<7> [84.553547] azx_init_pci: snd_hda_intel 0000:00:1f.3: SCH snoop: Enabled

<6> [91.357091] [IGT] kms_flip: finished subtest C-HDMI-A1, FAIL

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