igt@kms_flip@flip-vs-expired-vblank@a-hdmi-a3 on shard-bmg@xe-4642-8527899064372c5c8f4d8db80024412ff3c02128 Test details

Detail	Value
Duration	3.97 seconds
Hostname	shard-bmg-8
Igt-Version	IGT-Version: 2.3-g4e59b8e77 (x86_64) (Linux: 7.0.0-rc2-lgci-xe-xe-4642-8527899064372c5c8-debug+ x86_64)
Out	Starting dynamic subtest: A-HDMI-A3 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043() #4 ../tests/kms_flip.c:2043 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-HDMI-A3: FAIL (3.969s)
Err	Starting dynamic subtest: A-HDMI-A3 (kms_flip:11870) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:11870) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-HDMI-A3 failed. ** DEBUG (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 14: 0x00000200 (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 15: 0x00000614 (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 16: 0x00000000 (reserved) (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 17: 0x00000000 (reserved) (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 18: 0x00000000 (reserved) (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 19: 0x00000000 (reserved) (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 20: 0x0000004c (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 21: 0x0000024c (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 22: 0x0000004e (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 23: 0x0000004f (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 24: 0x0000008c (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 25: 0x0000028c (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 26: 0x0000008e (kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 27: 0x0000008f (kms_flip:11870) intel_allocator_simple-DEBUG: <ial: 0x5fd546794b30, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:11870) intel_allocator_simple-DEBUG: <ial: 0x5fd546794b30, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:11870) igt_kms-INFO: 1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 (kms_flip:11870) DEBUG: No stale events found (kms_flip:11870) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0 (kms_flip:11870) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0 (kms_flip:11870) DEBUG: name = flip last_ts = 0.000000 last_received_ts = 0.000000 last_seq = 0 current_ts = 606.501282 current_received_ts = 606.501099 current_seq = 5668 count = 0 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 45us (kms_flip:11870) DEBUG: name = flip last_ts = 606.501282 last_received_ts = 606.501099 last_seq = 5668 current_ts = 606.517944 current_received_ts = 606.517700 current_seq = 5669 count = 1 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 606.517944 last_received_ts = 606.517700 last_seq = 5669 current_ts = 606.534607 current_received_ts = 606.534241 current_seq = 5670 count = 2 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 32us (kms_flip:11870) DEBUG: name = flip last_ts = 606.534607 last_received_ts = 606.534241 last_seq = 5670 current_ts = 606.551270 current_received_ts = 606.550903 current_seq = 5671 count = 3 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 29us (kms_flip:11870) DEBUG: name = flip last_ts = 606.551270 last_received_ts = 606.550903 last_seq = 5671 current_ts = 606.567932 current_received_ts = 606.567566 current_seq = 5672 count = 4 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 29us (kms_flip:11870) DEBUG: name = flip last_ts = 606.567932 last_received_ts = 606.567566 last_seq = 5672 current_ts = 606.584595 current_received_ts = 606.584229 current_seq = 5673 count = 5 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 29us (kms_flip:11870) DEBUG: name = flip last_ts = 606.584595 last_received_ts = 606.584229 last_seq = 5673 current_ts = 606.601257 current_received_ts = 606.600891 current_seq = 5674 count = 6 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 28us (kms_flip:11870) DEBUG: name = flip last_ts = 606.601257 last_received_ts = 606.600891 last_seq = 5674 current_ts = 606.617920 current_received_ts = 606.617676 current_seq = 5675 count = 7 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 45us (kms_flip:11870) DEBUG: name = flip last_ts = 606.617920 last_received_ts = 606.617676 last_seq = 5675 current_ts = 606.634583 current_received_ts = 606.634338 current_seq = 5676 count = 8 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 43us (kms_flip:11870) DEBUG: name = flip last_ts = 606.634583 last_received_ts = 606.634338 last_seq = 5676 current_ts = 606.651245 current_received_ts = 606.651062 current_seq = 5677 count = 9 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 238us (kms_flip:11870) DEBUG: name = flip last_ts = 606.651245 last_received_ts = 606.651062 last_seq = 5677 current_ts = 606.667908 current_received_ts = 606.667725 current_seq = 5678 count = 10 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 44us (kms_flip:11870) DEBUG: name = flip last_ts = 606.667908 last_received_ts = 606.667725 last_seq = 5678 current_ts = 606.684570 current_received_ts = 606.684387 current_seq = 5679 count = 11 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 42us (kms_flip:11870) DEBUG: name = flip last_ts = 606.684570 last_received_ts = 606.684387 last_seq = 5679 current_ts = 606.701294 current_received_ts = 606.701050 current_seq = 5680 count = 12 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 221us (kms_flip:11870) DEBUG: name = flip last_ts = 606.701294 last_received_ts = 606.701050 last_seq = 5680 current_ts = 606.717957 current_received_ts = 606.717590 current_seq = 5681 count = 13 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 43us (kms_flip:11870) DEBUG: name = flip last_ts = 606.717957 last_received_ts = 606.717590 last_seq = 5681 current_ts = 606.734619 current_received_ts = 606.734253 current_seq = 5682 count = 14 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 34us (kms_flip:11870) DEBUG: name = flip last_ts = 606.734619 last_received_ts = 606.734253 last_seq = 5682 current_ts = 606.751282 current_received_ts = 606.750916 current_seq = 5683 count = 15 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 34us (kms_flip:11870) DEBUG: name = flip last_ts = 606.751282 last_received_ts = 606.750916 last_seq = 5683 current_ts = 606.767944 current_received_ts = 606.767578 current_seq = 5684 count = 16 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 33us (kms_flip:11870) DEBUG: name = flip last_ts = 606.767944 last_received_ts = 606.767578 last_seq = 5684 current_ts = 606.784607 current_received_ts = 606.784241 current_seq = 5685 count = 17 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 33us (kms_flip:11870) DEBUG: name = flip last_ts = 606.784607 last_received_ts = 606.784241 last_seq = 5685 current_ts = 606.801270 current_received_ts = 606.800903 current_seq = 5686 count = 18 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 31us (kms_flip:11870) DEBUG: name = flip last_ts = 606.801270 last_received_ts = 606.800903 last_seq = 5686 current_ts = 606.817932 current_received_ts = 606.817688 current_seq = 5687 count = 19 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 606.817932 last_received_ts = 606.817688 last_seq = 5687 current_ts = 606.834595 current_received_ts = 606.834351 current_seq = 5688 count = 20 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 40us (kms_flip:11870) DEBUG: name = flip last_ts = 606.834595 last_received_ts = 606.834351 last_seq = 5688 current_ts = 606.851257 current_received_ts = 606.851074 current_seq = 5689 count = 21 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 606.851257 last_received_ts = 606.851074 last_seq = 5689 current_ts = 606.867920 current_received_ts = 606.867676 current_seq = 5690 count = 22 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 606.867920 last_received_ts = 606.867676 last_seq = 5690 current_ts = 606.884583 current_received_ts = 606.884338 current_seq = 5691 count = 23 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 606.884583 last_received_ts = 606.884338 last_seq = 5691 current_ts = 606.901245 current_received_ts = 606.901062 current_seq = 5692 count = 24 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 126us (kms_flip:11870) DEBUG: name = flip last_ts = 606.901245 last_received_ts = 606.901062 last_seq = 5692 current_ts = 606.917969 current_received_ts = 606.917725 current_seq = 5693 count = 25 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 151us (kms_flip:11870) DEBUG: name = flip last_ts = 606.917969 last_received_ts = 606.917725 last_seq = 5693 current_ts = 606.934631 current_received_ts = 606.934753 current_seq = 5694 count = 26 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 163us (kms_flip:11870) DEBUG: name = flip last_ts = 606.934631 last_received_ts = 606.934753 last_seq = 5694 current_ts = 606.951294 current_received_ts = 606.951355 current_seq = 5695 count = 27 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 173us (kms_flip:11870) DEBUG: name = flip last_ts = 606.951294 last_received_ts = 606.951355 last_seq = 5695 current_ts = 606.967957 current_received_ts = 606.967896 current_seq = 5696 count = 28 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 237us (kms_flip:11870) DEBUG: name = flip last_ts = 606.967957 last_received_ts = 606.967896 last_seq = 5696 current_ts = 606.984619 current_received_ts = 606.984375 current_seq = 5697 count = 29 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 33us (kms_flip:11870) DEBUG: name = flip last_ts = 606.984619 last_received_ts = 606.984375 last_seq = 5697 current_ts = 607.001282 current_received_ts = 607.001099 current_seq = 5698 count = 30 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 35us (kms_flip:11870) DEBUG: name = flip last_ts = 607.001282 last_received_ts = 607.001099 last_seq = 5698 current_ts = 607.017944 current_received_ts = 607.017700 current_seq = 5699 count = 31 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 33us (kms_flip:11870) DEBUG: name = flip last_ts = 607.017944 last_received_ts = 607.017700 last_seq = 5699 current_ts = 607.034607 current_received_ts = 607.034302 current_seq = 5700 count = 32 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.034607 last_received_ts = 607.034302 last_seq = 5700 current_ts = 607.051270 current_received_ts = 607.050964 current_seq = 5701 count = 33 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 26us (kms_flip:11870) DEBUG: name = flip last_ts = 607.051270 last_received_ts = 607.050964 last_seq = 5701 current_ts = 607.067932 current_received_ts = 607.067566 current_seq = 5702 count = 34 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 607.067932 last_received_ts = 607.067566 last_seq = 5702 current_ts = 607.084595 current_received_ts = 607.084229 current_seq = 5703 count = 35 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 25us (kms_flip:11870) DEBUG: name = flip last_ts = 607.084595 last_received_ts = 607.084229 last_seq = 5703 current_ts = 607.101257 current_received_ts = 607.100891 current_seq = 5704 count = 36 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 28us (kms_flip:11870) DEBUG: name = flip last_ts = 607.101257 last_received_ts = 607.100891 last_seq = 5704 current_ts = 607.117981 current_received_ts = 607.117615 current_seq = 5705 count = 37 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 26us (kms_flip:11870) DEBUG: name = flip last_ts = 607.117981 last_received_ts = 607.117615 last_seq = 5705 current_ts = 607.134644 current_received_ts = 607.134277 current_seq = 5706 count = 38 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 26us (kms_flip:11870) DEBUG: name = flip last_ts = 607.134644 last_received_ts = 607.134277 last_seq = 5706 current_ts = 607.151306 current_received_ts = 607.150940 current_seq = 5707 count = 39 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 607.151306 last_received_ts = 607.150940 last_seq = 5707 current_ts = 607.167969 current_received_ts = 607.167603 current_seq = 5708 count = 40 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 24us (kms_flip:11870) DEBUG: name = flip last_ts = 607.167969 last_received_ts = 607.167603 last_seq = 5708 current_ts = 607.184631 current_received_ts = 607.184265 current_seq = 5709 count = 41 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 607.184631 last_received_ts = 607.184265 last_seq = 5709 current_ts = 607.201294 current_received_ts = 607.200928 current_seq = 5710 count = 42 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 24us (kms_flip:11870) DEBUG: name = flip last_ts = 607.201294 last_received_ts = 607.200928 last_seq = 5710 current_ts = 607.217957 current_received_ts = 607.217651 current_seq = 5711 count = 43 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 32us (kms_flip:11870) DEBUG: name = flip last_ts = 607.217957 last_received_ts = 607.217651 last_seq = 5711 current_ts = 607.234619 current_received_ts = 607.234375 current_seq = 5712 count = 44 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 33us (kms_flip:11870) DEBUG: name = flip last_ts = 607.234619 last_received_ts = 607.234375 last_seq = 5712 current_ts = 607.251282 current_received_ts = 607.251099 current_seq = 5713 count = 45 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 34us (kms_flip:11870) DEBUG: name = flip last_ts = 607.251282 last_received_ts = 607.251099 last_seq = 5713 current_ts = 607.267944 current_received_ts = 607.267700 current_seq = 5714 count = 46 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 33us (kms_flip:11870) DEBUG: name = flip last_ts = 607.267944 last_received_ts = 607.267700 last_seq = 5714 current_ts = 607.284607 current_received_ts = 607.284363 current_seq = 5715 count = 47 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 33us (kms_flip:11870) DEBUG: name = flip last_ts = 607.284607 last_received_ts = 607.284363 last_seq = 5715 current_ts = 607.301270 current_received_ts = 607.300964 current_seq = 5716 count = 48 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 35us (kms_flip:11870) DEBUG: name = flip last_ts = 607.301270 last_received_ts = 607.300964 last_seq = 5716 current_ts = 607.317993 current_received_ts = 607.317749 current_seq = 5717 count = 49 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 40us (kms_flip:11870) DEBUG: name = flip last_ts = 607.317993 last_received_ts = 607.317749 last_seq = 5717 current_ts = 607.334656 current_received_ts = 607.334351 current_seq = 5718 count = 50 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 43us (kms_flip:11870) DEBUG: name = flip last_ts = 607.334656 last_received_ts = 607.334351 last_seq = 5718 current_ts = 607.351318 current_received_ts = 607.351074 current_seq = 5719 count = 51 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.351318 last_received_ts = 607.351074 last_seq = 5719 current_ts = 607.367981 current_received_ts = 607.367737 current_seq = 5720 count = 52 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 607.367981 last_received_ts = 607.367737 last_seq = 5720 current_ts = 607.384644 current_received_ts = 607.384338 current_seq = 5721 count = 53 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.384644 last_received_ts = 607.384338 last_seq = 5721 current_ts = 607.401306 current_received_ts = 607.401001 current_seq = 5722 count = 54 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.401306 last_received_ts = 607.401001 last_seq = 5722 current_ts = 607.417969 current_received_ts = 607.417725 current_seq = 5723 count = 55 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.417969 last_received_ts = 607.417725 last_seq = 5723 current_ts = 607.434631 current_received_ts = 607.434326 current_seq = 5724 count = 56 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.434631 last_received_ts = 607.434326 last_seq = 5724 current_ts = 607.451294 current_received_ts = 607.450989 current_seq = 5725 count = 57 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.451294 last_received_ts = 607.450989 last_seq = 5725 current_ts = 607.467957 current_received_ts = 607.467651 current_seq = 5726 count = 58 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 31us (kms_flip:11870) DEBUG: name = flip last_ts = 607.467957 last_received_ts = 607.467651 last_seq = 5726 current_ts = 607.484619 current_received_ts = 607.484314 current_seq = 5727 count = 59 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 28us (kms_flip:11870) DEBUG: name = flip last_ts = 607.484619 last_received_ts = 607.484314 last_seq = 5727 current_ts = 607.501282 current_received_ts = 607.500916 current_seq = 5728 count = 60 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 26us (kms_flip:11870) DEBUG: name = flip last_ts = 607.501282 last_received_ts = 607.500916 last_seq = 5728 current_ts = 607.517944 current_received_ts = 607.517639 current_seq = 5729 count = 61 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 28us (kms_flip:11870) DEBUG: name = flip last_ts = 607.517944 last_received_ts = 607.517639 last_seq = 5729 current_ts = 607.534668 current_received_ts = 607.534302 current_seq = 5730 count = 62 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 25us (kms_flip:11870) DEBUG: name = flip last_ts = 607.534668 last_received_ts = 607.534302 last_seq = 5730 current_ts = 607.551331 current_received_ts = 607.551086 current_seq = 5731 count = 63 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.551331 last_received_ts = 607.551086 last_seq = 5731 current_ts = 607.567993 current_received_ts = 607.567688 current_seq = 5732 count = 64 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.567993 last_received_ts = 607.567688 last_seq = 5732 current_ts = 607.584656 current_received_ts = 607.584351 current_seq = 5733 count = 65 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 607.584656 last_received_ts = 607.584351 last_seq = 5733 current_ts = 607.601318 current_received_ts = 607.601013 current_seq = 5734 count = 66 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 607.601318 last_received_ts = 607.601013 last_seq = 5734 current_ts = 607.617981 current_received_ts = 607.617676 current_seq = 5735 count = 67 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 36us (kms_flip:11870) DEBUG: name = flip last_ts = 607.617981 last_received_ts = 607.617676 last_seq = 5735 current_ts = 607.634644 current_received_ts = 607.634338 current_seq = 5736 count = 68 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.634644 last_received_ts = 607.634338 last_seq = 5736 current_ts = 607.651306 current_received_ts = 607.651123 current_seq = 5737 count = 69 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.651306 last_received_ts = 607.651123 last_seq = 5737 current_ts = 607.667969 current_received_ts = 607.667725 current_seq = 5738 count = 70 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.667969 last_received_ts = 607.667725 last_seq = 5738 current_ts = 607.684631 current_received_ts = 607.684387 current_seq = 5739 count = 71 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.684631 last_received_ts = 607.684387 last_seq = 5739 current_ts = 607.701294 current_received_ts = 607.701111 current_seq = 5740 count = 72 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.701294 last_received_ts = 607.701111 last_seq = 5740 current_ts = 607.717957 current_received_ts = 607.717773 current_seq = 5741 count = 73 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 36us (kms_flip:11870) DEBUG: name = flip last_ts = 607.717957 last_received_ts = 607.717773 last_seq = 5741 current_ts = 607.734680 current_received_ts = 607.734375 current_seq = 5742 count = 74 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.734680 last_received_ts = 607.734375 last_seq = 5742 current_ts = 607.751343 current_received_ts = 607.751099 current_seq = 5743 count = 75 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 607.751343 last_received_ts = 607.751099 last_seq = 5743 current_ts = 607.768005 current_received_ts = 607.767700 current_seq = 5744 count = 76 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.768005 last_received_ts = 607.767700 last_seq = 5744 current_ts = 607.784668 current_received_ts = 607.784363 current_seq = 5745 count = 77 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.784668 last_received_ts = 607.784363 last_seq = 5745 current_ts = 607.801331 current_received_ts = 607.801025 current_seq = 5746 count = 78 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 607.801331 last_received_ts = 607.801025 last_seq = 5746 current_ts = 607.817993 current_received_ts = 607.817688 current_seq = 5747 count = 79 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 607.817993 last_received_ts = 607.817688 last_seq = 5747 current_ts = 607.834656 current_received_ts = 607.834290 current_seq = 5748 count = 80 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 31us (kms_flip:11870) DEBUG: name = flip last_ts = 607.834656 last_received_ts = 607.834290 last_seq = 5748 current_ts = 607.851318 current_received_ts = 607.850952 current_seq = 5749 count = 81 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 61us (kms_flip:11870) DEBUG: name = flip last_ts = 607.851318 last_received_ts = 607.850952 last_seq = 5749 current_ts = 607.867981 current_received_ts = 607.867737 current_seq = 5750 count = 82 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 607.867981 last_received_ts = 607.867737 last_seq = 5750 current_ts = 607.884644 current_received_ts = 607.884399 current_seq = 5751 count = 83 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 607.884644 last_received_ts = 607.884399 last_seq = 5751 current_ts = 607.901306 current_received_ts = 607.901123 current_seq = 5752 count = 84 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 38us (kms_flip:11870) DEBUG: name = flip last_ts = 607.901306 last_received_ts = 607.901123 last_seq = 5752 current_ts = 607.917969 current_received_ts = 607.917664 current_seq = 5753 count = 85 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 36us (kms_flip:11870) DEBUG: name = flip last_ts = 607.917969 last_received_ts = 607.917664 last_seq = 5753 current_ts = 607.934692 current_received_ts = 607.934326 current_seq = 5754 count = 86 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 29us (kms_flip:11870) DEBUG: name = flip last_ts = 607.934692 last_received_ts = 607.934326 last_seq = 5754 current_ts = 607.951355 current_received_ts = 607.950989 current_seq = 5755 count = 87 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 62us (kms_flip:11870) DEBUG: name = flip last_ts = 607.951355 last_received_ts = 607.950989 last_seq = 5755 current_ts = 607.968018 current_received_ts = 607.967712 current_seq = 5756 count = 88 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 43us (kms_flip:11870) DEBUG: name = flip last_ts = 607.968018 last_received_ts = 607.967712 last_seq = 5756 current_ts = 607.984680 current_received_ts = 607.984375 current_seq = 5757 count = 89 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 36us (kms_flip:11870) DEBUG: name = flip last_ts = 607.984680 last_received_ts = 607.984375 last_seq = 5757 current_ts = 608.001343 current_received_ts = 608.001038 current_seq = 5758 count = 90 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 608.001343 last_received_ts = 608.001038 last_seq = 5758 current_ts = 608.018005 current_received_ts = 608.017700 current_seq = 5759 count = 91 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 42us (kms_flip:11870) DEBUG: name = flip last_ts = 608.018005 last_received_ts = 608.017700 last_seq = 5759 current_ts = 608.034668 current_received_ts = 608.034302 current_seq = 5760 count = 92 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 608.034668 last_received_ts = 608.034302 last_seq = 5760 current_ts = 608.051331 current_received_ts = 608.050964 current_seq = 5761 count = 93 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 53us (kms_flip:11870) DEBUG: name = flip last_ts = 608.051331 last_received_ts = 608.050964 last_seq = 5761 current_ts = 608.067993 current_received_ts = 608.067749 current_seq = 5762 count = 94 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 39us (kms_flip:11870) DEBUG: name = flip last_ts = 608.067993 last_received_ts = 608.067749 last_seq = 5762 current_ts = 608.084656 current_received_ts = 608.084351 current_seq = 5763 count = 95 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 608.084656 last_received_ts = 608.084351 last_seq = 5763 current_ts = 608.101318 current_received_ts = 608.101135 current_seq = 5764 count = 96 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 608.101318 last_received_ts = 608.101135 last_seq = 5764 current_ts = 608.117981 current_received_ts = 608.117676 current_seq = 5765 count = 97 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 37us (kms_flip:11870) DEBUG: name = flip last_ts = 608.117981 last_received_ts = 608.117676 last_seq = 5765 current_ts = 608.134705 current_received_ts = 608.134338 current_seq = 5766 count = 98 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 31us (kms_flip:11870) DEBUG: name = flip last_ts = 608.134705 last_received_ts = 608.134338 last_seq = 5766 current_ts = 608.151367 current_received_ts = 608.151001 current_seq = 5767 count = 99 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 29us (kms_flip:11870) DEBUG: name = flip last_ts = 608.151367 last_received_ts = 608.151001 last_seq = 5767 current_ts = 608.168030 current_received_ts = 608.167664 current_seq = 5768 count = 100 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 608.168030 last_received_ts = 608.167664 last_seq = 5768 current_ts = 608.184692 current_received_ts = 608.184326 current_seq = 5769 count = 101 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 25us (kms_flip:11870) DEBUG: name = flip last_ts = 608.184692 last_received_ts = 608.184326 last_seq = 5769 current_ts = 608.201355 current_received_ts = 608.200989 current_seq = 5770 count = 102 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 65us (kms_flip:11870) DEBUG: name = flip last_ts = 608.201355 last_received_ts = 608.200989 last_seq = 5770 current_ts = 608.218018 current_received_ts = 608.217651 current_seq = 5771 count = 103 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 28us (kms_flip:11870) DEBUG: name = flip last_ts = 608.218018 last_received_ts = 608.217651 last_seq = 5771 current_ts = 608.234680 current_received_ts = 608.234314 current_seq = 5772 count = 104 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 28us (kms_flip:11870) DEBUG: name = flip last_ts = 608.234680 last_received_ts = 608.234314 last_seq = 5772 current_ts = 608.251343 current_received_ts = 608.250977 current_seq = 5773 count = 105 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 28us (kms_flip:11870) DEBUG: name = flip last_ts = 608.251343 last_received_ts = 608.250977 last_seq = 5773 current_ts = 608.268005 current_received_ts = 608.267639 current_seq = 5774 count = 106 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 25us (kms_flip:11870) DEBUG: name = flip last_ts = 608.268005 last_received_ts = 608.267639 last_seq = 5774 current_ts = 608.284668 current_received_ts = 608.284302 current_seq = 5775 count = 107 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 608.284668 last_received_ts = 608.284302 last_seq = 5775 current_ts = 608.301331 current_received_ts = 608.300964 current_seq = 5776 count = 108 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 29us (kms_flip:11870) DEBUG: name = flip last_ts = 608.301331 last_received_ts = 608.300964 last_seq = 5776 current_ts = 608.317993 current_received_ts = 608.317627 current_seq = 5777 count = 109 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 608.317993 last_received_ts = 608.317627 last_seq = 5777 current_ts = 608.334656 current_received_ts = 608.334290 current_seq = 5778 count = 110 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 27us (kms_flip:11870) DEBUG: name = flip last_ts = 608.334656 last_received_ts = 608.334290 last_seq = 5778 current_ts = 608.351379 current_received_ts = 608.351013 current_seq = 5779 count = 111 seq_step = 1 (kms_flip:11870) DEBUG: Vblank took 537us (kms_flip:11870) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:11870) CRITICAL: Failed assertion: end - start < 500 (kms_flip:11870) igt_core-INFO: Stack trace: (kms_flip:11870) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:11870) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:11870) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:11870) igt_core-INFO: #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043() (kms_flip:11870) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:11870) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:11870) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:11870) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-HDMI-A3: FAIL (3.969s)
Dmesg	<6> [606.494134] [IGT] kms_flip: starting dynamic subtest A-HDMI-A3 <7> [606.494632] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:555] <7> [606.494892] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:557] <7> [606.558666] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [606.559551] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B] <7> [606.559768] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C] <7> [606.559968] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:504:pipe D] <7> [606.560107] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.enable (expected yes, found no) <7> [606.560419] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.active (expected yes, found no) <7> [606.560648] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in cpu_transcoder (expected 3, found -1) <7> [606.560861] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in lane_count (expected 4, found 0) <7> [606.561067] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in dp_m_n (expected tu 64 data 5190451/8388608 link 288358/524288, found tu 0, data 0/0 link 0/0) <7> [606.561272] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000) <7> [606.561508] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [606.561706] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [606.561898] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [606.562081] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [606.562264] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [606.562466] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [606.562641] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [606.562815] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [606.562989] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [606.563162] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [606.563347] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [606.563522] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [606.563680] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [606.563836] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [606.563988] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [606.564139] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [606.564305] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [606.564455] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [606.564600] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [606.564725] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [606.564818] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [606.564909] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [606.565002] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [606.565095] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [606.565187] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [606.565284] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [606.565379] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [606.565472] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [606.565565] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in enhanced_framing (expected yes, found no) <7> [606.565658] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in pipe_bpp (expected 36, found 0) <7> [606.565751] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [606.565843] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [606.565935] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in port_clock (expected 270000, found 0) <7> [606.566029] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:504:pipe D] fastset requirement not met, forcing full modeset <7> [606.566122] xe 0000:03:00.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:504:pipe D] releasing TC PLL 2 <7> [606.566232] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no <7> [606.566323] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:504:pipe D] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x8 -> 0x0 <7> [606.566423] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:498:cursor D] ddb (1989 - 2048) -> ( 0 - 0), size 59 -> 0 <7> [606.566524] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:504:pipe D] min cdclk: 192000 kHz -> 0 kHz <7> [606.566640] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:504:pipe D] enable: no [modeset] <7> [606.566738] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:388:plane 1D] fb: [NOFB], visible: no <7> [606.566837] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:418:plane 2D] fb: [NOFB], visible: no <7> [606.566932] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:448:plane 3D] fb: [NOFB], visible: no <7> [606.567025] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:478:plane 4D] fb: [NOFB], visible: no <7> [606.567118] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:488:plane 5D] fb: [NOFB], visible: no <7> [606.567210] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:498:cursor D] fb: [NOFB], visible: no <7> [606.567612] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:526:DP-2][ENCODER:525:DDI TC2/PHY G] Disable audio codec on [CRTC:504:pipe D] <7> [606.588451] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe D <7> [606.609387] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2 <7> [606.612855] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disable TC PLL 2 (active 0x8, on? 1) for [CRTC:504:pipe D] <7> [606.615597] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disabling TC PLL 2 <7> [606.616451] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:506:DDI TC1/PHY F] <7> [606.616923] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:508:DP-MST A] <7> [606.617410] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST B] <7> [606.617870] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST C] <7> [606.618348] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST D] <7> [606.618784] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:525:DDI TC2/PHY G] <7> [606.619458] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:527:DP-MST A] <7> [606.619911] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST B] <7> [606.620368] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST C] <7> [606.620746] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST D] <7> [606.621128] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:537:DDI TC3/PHY H] <7> [606.621532] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:541:DDI TC4/PHY I] <7> [606.621876] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:543:DP-MST A] <7> [606.622218] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST B] <7> [606.622581] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST C] <7> [606.622906] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST D] <7> [606.623225] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:526:DP-2] <7> [606.623812] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no) <7> [606.624303] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [606.624893] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_D <7> [606.625400] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x8 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [606.625914] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2 <7> [606.626420] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:504:pipe D] <7> [606.627076] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [606.627134] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:538:HDMI-A-3] <7> [606.627301] xe 0000:03:00.0: [drm:intel_hdmi_compute_clock [xe]] picking 12 bpc for HDMI output (pipe bpp: 36) <7> [606.627525] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [606.627739] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:537:DDI TC3/PHY H] [CRTC:150:pipe A] <7> [606.627942] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [606.628143] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [606.628345] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [606.628529] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [606.628700] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [606.628870] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [606.629039] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [606.629208] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [606.629380] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [606.629540] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [606.629686] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [606.629828] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [606.629967] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [606.630106] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [606.630243] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083) <7> [606.630389] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088) <7> [606.630519] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [606.630646] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [606.630770] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [606.630892] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [606.631012] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [606.631132] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [606.631258] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [606.631386] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [606.631501] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [606.631610] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [606.631719] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083) <7> [606.631824] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088) <7> [606.631935] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [606.632040] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [606.632144] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [606.632245] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [606.632350] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [606.632449] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes) <7> [606.632542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in has_infoframe (expected no, found yes) <7> [606.632637] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dpll_hw_state <7> [606.632726] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected: <7> [606.632815] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [606.632903] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state: <7> [606.632989] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x4800, tx[2] = 0x0000 <7> [606.633075] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [606.633161] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x308c <7> [606.633245] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x2110 <7> [606.633339] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0xcc9c <7> [606.633425] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0xbfc1 <7> [606.633509] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x4b9a <7> [606.633593] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x3f81 <7> [606.633678] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2000 <7> [606.633762] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0x0001 <7> [606.633846] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x5000 <7> [606.633930] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000 <7> [606.634012] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000 <7> [606.634097] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x42, hdmi rate: 0x00 <7> [606.634184] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found: <7> [606.634280] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [606.634370] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state: <7> [606.634457] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000 <7> [606.634542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [606.634627] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x40e8 <7> [606.634712] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x7d20 <7> [606.634797] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0x0a06 <7> [606.634882] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0x8f1c <7> [606.634967] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x0000 <7> [606.635052] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x0000 <7> [606.635137] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2200 <7> [606.635222] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0xffff <7> [606.635317] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x0400 <7> [606.635401] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000 <7> [606.635490] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0001 <7> [606.635578] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00 <7> [606.635666] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [606.635754] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [606.635840] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [606.635925] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 222750) <7> [606.636010] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071) <7> [606.636093] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006) <7> [606.636178] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in avi infoframe <7> [606.636262] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected: <7> [606.636356] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found: <7> [606.636441] xe 0000:03:00.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [606.636443] xe 0000:03:00.0: colorspace: RGB <7> [606.636444] xe 0000:03:00.0: scan mode: Underscan <7> [606.636445] xe 0000:03:00.0: colorimetry: No Data <7> [606.636446] xe 0000:03:00.0: picture aspect: No Data <7> [606.636447] xe 0000:03:00.0: active aspect: Same as Picture <7> [606.636448] xe 0000:03:00.0: itc: No Data <7> [606.636449] xe 0000:03:00.0: extended colorimetry: xvYCC 601 <7> [606.636450] xe 0000:03:00.0: quantization range: Full <7> [606.636451] xe 0000:03:00.0: nups: Unknown Non-uniform Scaling <7> [606.636452] xe 0000:03:00.0: video code: 0 <7> [606.636453] xe 0000:03:00.0: ycc quantization range: Full <7> [606.636454] xe 0000:03:00.0: hdmi content type: Graphics <7> [606.636455] xe 0000:03:00.0: pixel repeat: 0 <7> [606.636456] xe 0000:03:00.0: bar top 0, bottom 0, left 0, right 0 <7> [606.636458] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in spd infoframe <7> [606.636542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected: <7> [606.636627] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found: <7> [606.636711] xe 0000:03:00.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [606.636712] xe 0000:03:00.0: vendor: Intel <7> [606.636713] xe 0000:03:00.0: product: Discrete gfx <7> [606.636714] xe 0000:03:00.0: source device information: PC General (0x9) <7> [606.636715] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hdmi infoframe <7> [606.636800] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected: <7> [606.636884] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found: <7> [606.636970] xe 0000:03:00.0: HDMI infoframe: Vendor, version 1, length 4 <7> [606.636971] xe 0000:03:00.0: empty frame <7> [606.636972] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [606.637087] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [606.637161] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [606.637255] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4037), size 0 -> 4037 <7> [606.637342] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4037 - 4096), size 0 -> 59 <7> [606.637412] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [606.637482] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 9, 9, 17, 17, 17, 17, 0, 15, 0 <7> [606.637551] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 139, 139, 261, 261, 261, 261, 137, 230, 244 <7> [606.637619] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 245, 245, 367, 367, 0, 0, 138, 306, 306 <7> [606.637699] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 594000 num active planes 1 <7> [606.637791] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 624 qgv_peak_bw: 48000 <7> [606.637881] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 624 qgv_peak_bw: 48000 <7> [606.637968] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 624 <7> [606.638054] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 192000 kHz <7> [606.638165] xe 0000:03:00.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated TC PLL 3 <7> [606.638256] xe 0000:03:00.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving TC PLL 3 <7> [606.638354] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset] <7> [606.638444] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [606.638534] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 36, dithering: 0 <7> [606.638621] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [606.638709] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [606.638792] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [606.638879] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [606.638964] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 1, infoframes enabled: 0x71 <7> [606.639048] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] GCP: 0x6 <7> [606.639135] xe 0000:03:00.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13 <7> [606.639137] xe 0000:03:00.0: colorspace: RGB <7> [606.639138] xe 0000:03:00.0: scan mode: Underscan <7> [606.639139] xe 0000:03:00.0: colorimetry: No Data <7> [606.639140] xe 0000:03:00.0: picture aspect: No Data <7> [606.639141] xe 0000:03:00.0: active aspect: Same as Picture <7> [606.639142] xe 0000:03:00.0: itc: No Data <7> [606.639143] xe 0000:03:00.0: extended colorimetry: xvYCC 601 <7> [606.639144] xe 0000:03:00.0: quantization range: Full <7> [606.639145] xe 0000:03:00.0: nups: Unknown Non-uniform Scaling <7> [606.639146] xe 0000:03:00.0: video code: 0 <7> [606.639147] xe 0000:03:00.0: ycc quantization range: Full <7> [606.639148] xe 0000:03:00.0: hdmi content type: Graphics <7> [606.639149] xe 0000:03:00.0: pixel repeat: 0 <7> [606.639150] xe 0000:03:00.0: bar top 0, bottom 0, left 0, right 0 <7> [606.639151] xe 0000:03:00.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25 <7> [606.639152] xe 0000:03:00.0: vendor: Intel <7> [606.639153] xe 0000:03:00.0: product: Discrete gfx <7> [606.639154] xe 0000:03:00.0: source device information: PC General (0x9) <7> [606.639155] xe 0000:03:00.0: HDMI infoframe: Vendor, version 1, length 4 <7> [606.639156] xe 0000:03:00.0: empty frame <7> [606.639157] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00 <7> [606.639246] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00 <7> [606.639342] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [606.639427] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [606.639511] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 42, vsync end: 37 <7> [606.639595] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125 <7> [606.639679] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [606.639764] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [606.639848] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 <7> [606.639932] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [606.640017] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9 <7> [606.640100] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9 <7> [606.640181] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 222750, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000 <7> [606.640264] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0 <7> [606.640359] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [606.640444] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [606.640526] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [606.640609] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [606.640694] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] c20pll_hw_state: <7> [606.640781] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000 <7> [606.640868] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [606.640953] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[0] = 0x40e8 <7> [606.641038] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[1] = 0x7d20 <7> [606.641123] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[2] = 0x0a06 <7> [606.641207] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[3] = 0x8f1c <7> [606.641294] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[4] = 0x0000 <7> [606.641383] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[5] = 0x0000 <7> [606.641467] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[6] = 0x2200 <7> [606.641549] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[7] = 0xffff <7> [606.641633] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[8] = 0x0400 <7> [606.641716] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[9] = 0x0000 <7> [606.641799] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[10] = 0x0001 <7> [606.641881] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00 <7> [606.641964] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [606.642048] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [606.642129] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [606.642211] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [606.642302] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [606.642385] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [606.642467] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [606.642554] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [606.642641] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [606.642725] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [606.642810] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [606.642894] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [606.642980] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [606.643064] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:555] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [606.643148] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 1 <7> [606.643232] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [606.643343] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [606.643427] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [606.643510] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [606.643593] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [606.643676] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [606.644288] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [606.644423] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000) <7> [606.644517] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2 <7> [606.644645] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:506:DDI TC1/PHY F] <7> [606.644729] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:508:DP-MST A] <7> [606.644808] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST B] <7> [606.644887] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST C] <7> [606.644966] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST D] <7> [606.645044] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:525:DDI TC2/PHY G] <7> [606.645121] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:527:DP-MST A] <7> [606.645198] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST B] <7> [606.645282] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST C] <7> [606.645362] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST D] <7> [606.645441] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:537:DDI TC3/PHY H] <7> [606.645520] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:541:DDI TC4/PHY I] <7> [606.645597] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:543:DP-MST A] <7> [606.645673] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST B] <7> [606.645749] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST C] <7> [606.645825] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST D] <7> [606.645911] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [606.646065] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [606.646137] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: yes) <7> [606.646233] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enable TC PLL 3 (active 0x1, on? 0) for [CRTC:150:pipe A] <7> [606.646327] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enabling TC PLL 3 <7> [606.648806] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [606.667182] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:538:HDMI-A-3][ENCODER:537:DDI TC3/PHY H] Enable audio codec on [CRTC:150:pipe A], 32 bytes ELD <7> [606.683808] xe 0000:03:00.0: [drm:audio_config_hdmi_pixel_clock [xe]] Configuring HDMI audio for pixel clock 148500 (0x00090000) <7> [606.683973] xe 0000:03:00.0: [drm:hsw_audio_config_update [xe]] using automatic N <7> [606.684542] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:538:HDMI-A-3] <7> [606.684964] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A] <7> [606.718533] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2 <7> [610.294263] xe 0000:03:00.0: [drm:xe_hwmon_read [xe]] thermal data for group 0 val 0x21201f21 <7> [610.294456] xe 0000:03:00.0: [drm:xe_hwmon_read [xe]] thermal data for group 1 val 0x23222121 <6> [610.464856] [IGT] kms_flip: finished subtest A-HDMI-A3, FAIL

Detail

Value

Duration

3.97 seconds

Hostname

shard-bmg-8

Igt-Version

IGT-Version: 2.3-g4e59b8e77 (x86_64) (Linux: 7.0.0-rc2-lgci-xe-xe-4642-8527899064372c5c8-debug+ x86_64)

Out

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

Err

Starting dynamic subtest: A-HDMI-A3
(kms_flip:11870) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:11870) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 14: 0x00000200
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 15: 0x00000614
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 16: 0x00000000 (reserved)
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 17: 0x00000000 (reserved)
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 18: 0x00000000 (reserved)
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 19: 0x00000000 (reserved)
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 20: 0x0000004c
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 21: 0x0000024c
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 22: 0x0000004e
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 23: 0x0000004f
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 24: 0x0000008c
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 25: 0x0000028c
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 26: 0x0000008e
(kms_flip:11870) intel_pat-DEBUG: Parsed PAT entry 27: 0x0000008f
(kms_flip:11870) intel_allocator_simple-DEBUG: <ial: 0x5fd546794b30, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:11870) intel_allocator_simple-DEBUG: <ial: 0x5fd546794b30, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:11870) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
(kms_flip:11870) DEBUG: No stale events found
(kms_flip:11870) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:11870) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:11870) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 606.501282
current_received_ts = 606.501099
current_seq = 5668
count = 0
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 45us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.501282
last_received_ts = 606.501099
last_seq = 5668
current_ts = 606.517944
current_received_ts = 606.517700
current_seq = 5669
count = 1
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.517944
last_received_ts = 606.517700
last_seq = 5669
current_ts = 606.534607
current_received_ts = 606.534241
current_seq = 5670
count = 2
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 32us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.534607
last_received_ts = 606.534241
last_seq = 5670
current_ts = 606.551270
current_received_ts = 606.550903
current_seq = 5671
count = 3
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 29us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.551270
last_received_ts = 606.550903
last_seq = 5671
current_ts = 606.567932
current_received_ts = 606.567566
current_seq = 5672
count = 4
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 29us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.567932
last_received_ts = 606.567566
last_seq = 5672
current_ts = 606.584595
current_received_ts = 606.584229
current_seq = 5673
count = 5
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 29us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.584595
last_received_ts = 606.584229
last_seq = 5673
current_ts = 606.601257
current_received_ts = 606.600891
current_seq = 5674
count = 6
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 28us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.601257
last_received_ts = 606.600891
last_seq = 5674
current_ts = 606.617920
current_received_ts = 606.617676
current_seq = 5675
count = 7
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 45us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.617920
last_received_ts = 606.617676
last_seq = 5675
current_ts = 606.634583
current_received_ts = 606.634338
current_seq = 5676
count = 8
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 43us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.634583
last_received_ts = 606.634338
last_seq = 5676
current_ts = 606.651245
current_received_ts = 606.651062
current_seq = 5677
count = 9
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 238us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.651245
last_received_ts = 606.651062
last_seq = 5677
current_ts = 606.667908
current_received_ts = 606.667725
current_seq = 5678
count = 10
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 44us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.667908
last_received_ts = 606.667725
last_seq = 5678
current_ts = 606.684570
current_received_ts = 606.684387
current_seq = 5679
count = 11
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 42us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.684570
last_received_ts = 606.684387
last_seq = 5679
current_ts = 606.701294
current_received_ts = 606.701050
current_seq = 5680
count = 12
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 221us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.701294
last_received_ts = 606.701050
last_seq = 5680
current_ts = 606.717957
current_received_ts = 606.717590
current_seq = 5681
count = 13
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 43us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.717957
last_received_ts = 606.717590
last_seq = 5681
current_ts = 606.734619
current_received_ts = 606.734253
current_seq = 5682
count = 14
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 34us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.734619
last_received_ts = 606.734253
last_seq = 5682
current_ts = 606.751282
current_received_ts = 606.750916
current_seq = 5683
count = 15
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 34us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.751282
last_received_ts = 606.750916
last_seq = 5683
current_ts = 606.767944
current_received_ts = 606.767578
current_seq = 5684
count = 16
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 33us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.767944
last_received_ts = 606.767578
last_seq = 5684
current_ts = 606.784607
current_received_ts = 606.784241
current_seq = 5685
count = 17
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 33us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.784607
last_received_ts = 606.784241
last_seq = 5685
current_ts = 606.801270
current_received_ts = 606.800903
current_seq = 5686
count = 18
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 31us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.801270
last_received_ts = 606.800903
last_seq = 5686
current_ts = 606.817932
current_received_ts = 606.817688
current_seq = 5687
count = 19
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.817932
last_received_ts = 606.817688
last_seq = 5687
current_ts = 606.834595
current_received_ts = 606.834351
current_seq = 5688
count = 20
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 40us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.834595
last_received_ts = 606.834351
last_seq = 5688
current_ts = 606.851257
current_received_ts = 606.851074
current_seq = 5689
count = 21
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.851257
last_received_ts = 606.851074
last_seq = 5689
current_ts = 606.867920
current_received_ts = 606.867676
current_seq = 5690
count = 22
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.867920
last_received_ts = 606.867676
last_seq = 5690
current_ts = 606.884583
current_received_ts = 606.884338
current_seq = 5691
count = 23
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.884583
last_received_ts = 606.884338
last_seq = 5691
current_ts = 606.901245
current_received_ts = 606.901062
current_seq = 5692
count = 24
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 126us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.901245
last_received_ts = 606.901062
last_seq = 5692
current_ts = 606.917969
current_received_ts = 606.917725
current_seq = 5693
count = 25
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 151us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.917969
last_received_ts = 606.917725
last_seq = 5693
current_ts = 606.934631
current_received_ts = 606.934753
current_seq = 5694
count = 26
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 163us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.934631
last_received_ts = 606.934753
last_seq = 5694
current_ts = 606.951294
current_received_ts = 606.951355
current_seq = 5695
count = 27
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 173us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.951294
last_received_ts = 606.951355
last_seq = 5695
current_ts = 606.967957
current_received_ts = 606.967896
current_seq = 5696
count = 28
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 237us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.967957
last_received_ts = 606.967896
last_seq = 5696
current_ts = 606.984619
current_received_ts = 606.984375
current_seq = 5697
count = 29
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 33us
(kms_flip:11870) DEBUG: name = flip
last_ts = 606.984619
last_received_ts = 606.984375
last_seq = 5697
current_ts = 607.001282
current_received_ts = 607.001099
current_seq = 5698
count = 30
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 35us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.001282
last_received_ts = 607.001099
last_seq = 5698
current_ts = 607.017944
current_received_ts = 607.017700
current_seq = 5699
count = 31
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 33us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.017944
last_received_ts = 607.017700
last_seq = 5699
current_ts = 607.034607
current_received_ts = 607.034302
current_seq = 5700
count = 32
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.034607
last_received_ts = 607.034302
last_seq = 5700
current_ts = 607.051270
current_received_ts = 607.050964
current_seq = 5701
count = 33
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 26us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.051270
last_received_ts = 607.050964
last_seq = 5701
current_ts = 607.067932
current_received_ts = 607.067566
current_seq = 5702
count = 34
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.067932
last_received_ts = 607.067566
last_seq = 5702
current_ts = 607.084595
current_received_ts = 607.084229
current_seq = 5703
count = 35
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 25us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.084595
last_received_ts = 607.084229
last_seq = 5703
current_ts = 607.101257
current_received_ts = 607.100891
current_seq = 5704
count = 36
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 28us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.101257
last_received_ts = 607.100891
last_seq = 5704
current_ts = 607.117981
current_received_ts = 607.117615
current_seq = 5705
count = 37
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 26us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.117981
last_received_ts = 607.117615
last_seq = 5705
current_ts = 607.134644
current_received_ts = 607.134277
current_seq = 5706
count = 38
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 26us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.134644
last_received_ts = 607.134277
last_seq = 5706
current_ts = 607.151306
current_received_ts = 607.150940
current_seq = 5707
count = 39
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.151306
last_received_ts = 607.150940
last_seq = 5707
current_ts = 607.167969
current_received_ts = 607.167603
current_seq = 5708
count = 40
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 24us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.167969
last_received_ts = 607.167603
last_seq = 5708
current_ts = 607.184631
current_received_ts = 607.184265
current_seq = 5709
count = 41
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.184631
last_received_ts = 607.184265
last_seq = 5709
current_ts = 607.201294
current_received_ts = 607.200928
current_seq = 5710
count = 42
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 24us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.201294
last_received_ts = 607.200928
last_seq = 5710
current_ts = 607.217957
current_received_ts = 607.217651
current_seq = 5711
count = 43
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 32us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.217957
last_received_ts = 607.217651
last_seq = 5711
current_ts = 607.234619
current_received_ts = 607.234375
current_seq = 5712
count = 44
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 33us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.234619
last_received_ts = 607.234375
last_seq = 5712
current_ts = 607.251282
current_received_ts = 607.251099
current_seq = 5713
count = 45
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 34us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.251282
last_received_ts = 607.251099
last_seq = 5713
current_ts = 607.267944
current_received_ts = 607.267700
current_seq = 5714
count = 46
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 33us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.267944
last_received_ts = 607.267700
last_seq = 5714
current_ts = 607.284607
current_received_ts = 607.284363
current_seq = 5715
count = 47
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 33us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.284607
last_received_ts = 607.284363
last_seq = 5715
current_ts = 607.301270
current_received_ts = 607.300964
current_seq = 5716
count = 48
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 35us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.301270
last_received_ts = 607.300964
last_seq = 5716
current_ts = 607.317993
current_received_ts = 607.317749
current_seq = 5717
count = 49
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 40us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.317993
last_received_ts = 607.317749
last_seq = 5717
current_ts = 607.334656
current_received_ts = 607.334351
current_seq = 5718
count = 50
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 43us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.334656
last_received_ts = 607.334351
last_seq = 5718
current_ts = 607.351318
current_received_ts = 607.351074
current_seq = 5719
count = 51
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.351318
last_received_ts = 607.351074
last_seq = 5719
current_ts = 607.367981
current_received_ts = 607.367737
current_seq = 5720
count = 52
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.367981
last_received_ts = 607.367737
last_seq = 5720
current_ts = 607.384644
current_received_ts = 607.384338
current_seq = 5721
count = 53
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.384644
last_received_ts = 607.384338
last_seq = 5721
current_ts = 607.401306
current_received_ts = 607.401001
current_seq = 5722
count = 54
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.401306
last_received_ts = 607.401001
last_seq = 5722
current_ts = 607.417969
current_received_ts = 607.417725
current_seq = 5723
count = 55
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.417969
last_received_ts = 607.417725
last_seq = 5723
current_ts = 607.434631
current_received_ts = 607.434326
current_seq = 5724
count = 56
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.434631
last_received_ts = 607.434326
last_seq = 5724
current_ts = 607.451294
current_received_ts = 607.450989
current_seq = 5725
count = 57
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.451294
last_received_ts = 607.450989
last_seq = 5725
current_ts = 607.467957
current_received_ts = 607.467651
current_seq = 5726
count = 58
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 31us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.467957
last_received_ts = 607.467651
last_seq = 5726
current_ts = 607.484619
current_received_ts = 607.484314
current_seq = 5727
count = 59
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 28us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.484619
last_received_ts = 607.484314
last_seq = 5727
current_ts = 607.501282
current_received_ts = 607.500916
current_seq = 5728
count = 60
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 26us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.501282
last_received_ts = 607.500916
last_seq = 5728
current_ts = 607.517944
current_received_ts = 607.517639
current_seq = 5729
count = 61
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 28us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.517944
last_received_ts = 607.517639
last_seq = 5729
current_ts = 607.534668
current_received_ts = 607.534302
current_seq = 5730
count = 62
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 25us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.534668
last_received_ts = 607.534302
last_seq = 5730
current_ts = 607.551331
current_received_ts = 607.551086
current_seq = 5731
count = 63
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.551331
last_received_ts = 607.551086
last_seq = 5731
current_ts = 607.567993
current_received_ts = 607.567688
current_seq = 5732
count = 64
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.567993
last_received_ts = 607.567688
last_seq = 5732
current_ts = 607.584656
current_received_ts = 607.584351
current_seq = 5733
count = 65
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.584656
last_received_ts = 607.584351
last_seq = 5733
current_ts = 607.601318
current_received_ts = 607.601013
current_seq = 5734
count = 66
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.601318
last_received_ts = 607.601013
last_seq = 5734
current_ts = 607.617981
current_received_ts = 607.617676
current_seq = 5735
count = 67
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 36us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.617981
last_received_ts = 607.617676
last_seq = 5735
current_ts = 607.634644
current_received_ts = 607.634338
current_seq = 5736
count = 68
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.634644
last_received_ts = 607.634338
last_seq = 5736
current_ts = 607.651306
current_received_ts = 607.651123
current_seq = 5737
count = 69
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.651306
last_received_ts = 607.651123
last_seq = 5737
current_ts = 607.667969
current_received_ts = 607.667725
current_seq = 5738
count = 70
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.667969
last_received_ts = 607.667725
last_seq = 5738
current_ts = 607.684631
current_received_ts = 607.684387
current_seq = 5739
count = 71
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.684631
last_received_ts = 607.684387
last_seq = 5739
current_ts = 607.701294
current_received_ts = 607.701111
current_seq = 5740
count = 72
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.701294
last_received_ts = 607.701111
last_seq = 5740
current_ts = 607.717957
current_received_ts = 607.717773
current_seq = 5741
count = 73
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 36us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.717957
last_received_ts = 607.717773
last_seq = 5741
current_ts = 607.734680
current_received_ts = 607.734375
current_seq = 5742
count = 74
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.734680
last_received_ts = 607.734375
last_seq = 5742
current_ts = 607.751343
current_received_ts = 607.751099
current_seq = 5743
count = 75
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.751343
last_received_ts = 607.751099
last_seq = 5743
current_ts = 607.768005
current_received_ts = 607.767700
current_seq = 5744
count = 76
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.768005
last_received_ts = 607.767700
last_seq = 5744
current_ts = 607.784668
current_received_ts = 607.784363
current_seq = 5745
count = 77
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.784668
last_received_ts = 607.784363
last_seq = 5745
current_ts = 607.801331
current_received_ts = 607.801025
current_seq = 5746
count = 78
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.801331
last_received_ts = 607.801025
last_seq = 5746
current_ts = 607.817993
current_received_ts = 607.817688
current_seq = 5747
count = 79
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.817993
last_received_ts = 607.817688
last_seq = 5747
current_ts = 607.834656
current_received_ts = 607.834290
current_seq = 5748
count = 80
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 31us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.834656
last_received_ts = 607.834290
last_seq = 5748
current_ts = 607.851318
current_received_ts = 607.850952
current_seq = 5749
count = 81
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 61us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.851318
last_received_ts = 607.850952
last_seq = 5749
current_ts = 607.867981
current_received_ts = 607.867737
current_seq = 5750
count = 82
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.867981
last_received_ts = 607.867737
last_seq = 5750
current_ts = 607.884644
current_received_ts = 607.884399
current_seq = 5751
count = 83
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.884644
last_received_ts = 607.884399
last_seq = 5751
current_ts = 607.901306
current_received_ts = 607.901123
current_seq = 5752
count = 84
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 38us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.901306
last_received_ts = 607.901123
last_seq = 5752
current_ts = 607.917969
current_received_ts = 607.917664
current_seq = 5753
count = 85
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 36us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.917969
last_received_ts = 607.917664
last_seq = 5753
current_ts = 607.934692
current_received_ts = 607.934326
current_seq = 5754
count = 86
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 29us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.934692
last_received_ts = 607.934326
last_seq = 5754
current_ts = 607.951355
current_received_ts = 607.950989
current_seq = 5755
count = 87
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 62us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.951355
last_received_ts = 607.950989
last_seq = 5755
current_ts = 607.968018
current_received_ts = 607.967712
current_seq = 5756
count = 88
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 43us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.968018
last_received_ts = 607.967712
last_seq = 5756
current_ts = 607.984680
current_received_ts = 607.984375
current_seq = 5757
count = 89
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 36us
(kms_flip:11870) DEBUG: name = flip
last_ts = 607.984680
last_received_ts = 607.984375
last_seq = 5757
current_ts = 608.001343
current_received_ts = 608.001038
current_seq = 5758
count = 90
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.001343
last_received_ts = 608.001038
last_seq = 5758
current_ts = 608.018005
current_received_ts = 608.017700
current_seq = 5759
count = 91
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 42us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.018005
last_received_ts = 608.017700
last_seq = 5759
current_ts = 608.034668
current_received_ts = 608.034302
current_seq = 5760
count = 92
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.034668
last_received_ts = 608.034302
last_seq = 5760
current_ts = 608.051331
current_received_ts = 608.050964
current_seq = 5761
count = 93
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 53us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.051331
last_received_ts = 608.050964
last_seq = 5761
current_ts = 608.067993
current_received_ts = 608.067749
current_seq = 5762
count = 94
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 39us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.067993
last_received_ts = 608.067749
last_seq = 5762
current_ts = 608.084656
current_received_ts = 608.084351
current_seq = 5763
count = 95
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.084656
last_received_ts = 608.084351
last_seq = 5763
current_ts = 608.101318
current_received_ts = 608.101135
current_seq = 5764
count = 96
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.101318
last_received_ts = 608.101135
last_seq = 5764
current_ts = 608.117981
current_received_ts = 608.117676
current_seq = 5765
count = 97
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 37us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.117981
last_received_ts = 608.117676
last_seq = 5765
current_ts = 608.134705
current_received_ts = 608.134338
current_seq = 5766
count = 98
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 31us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.134705
last_received_ts = 608.134338
last_seq = 5766
current_ts = 608.151367
current_received_ts = 608.151001
current_seq = 5767
count = 99
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 29us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.151367
last_received_ts = 608.151001
last_seq = 5767
current_ts = 608.168030
current_received_ts = 608.167664
current_seq = 5768
count = 100
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.168030
last_received_ts = 608.167664
last_seq = 5768
current_ts = 608.184692
current_received_ts = 608.184326
current_seq = 5769
count = 101
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 25us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.184692
last_received_ts = 608.184326
last_seq = 5769
current_ts = 608.201355
current_received_ts = 608.200989
current_seq = 5770
count = 102
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 65us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.201355
last_received_ts = 608.200989
last_seq = 5770
current_ts = 608.218018
current_received_ts = 608.217651
current_seq = 5771
count = 103
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 28us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.218018
last_received_ts = 608.217651
last_seq = 5771
current_ts = 608.234680
current_received_ts = 608.234314
current_seq = 5772
count = 104
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 28us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.234680
last_received_ts = 608.234314
last_seq = 5772
current_ts = 608.251343
current_received_ts = 608.250977
current_seq = 5773
count = 105
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 28us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.251343
last_received_ts = 608.250977
last_seq = 5773
current_ts = 608.268005
current_received_ts = 608.267639
current_seq = 5774
count = 106
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 25us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.268005
last_received_ts = 608.267639
last_seq = 5774
current_ts = 608.284668
current_received_ts = 608.284302
current_seq = 5775
count = 107
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.284668
last_received_ts = 608.284302
last_seq = 5775
current_ts = 608.301331
current_received_ts = 608.300964
current_seq = 5776
count = 108
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 29us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.301331
last_received_ts = 608.300964
last_seq = 5776
current_ts = 608.317993
current_received_ts = 608.317627
current_seq = 5777
count = 109
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.317993
last_received_ts = 608.317627
last_seq = 5777
current_ts = 608.334656
current_received_ts = 608.334290
current_seq = 5778
count = 110
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 27us
(kms_flip:11870) DEBUG: name = flip
last_ts = 608.334656
last_received_ts = 608.334290
last_seq = 5778
current_ts = 608.351379
current_received_ts = 608.351013
current_seq = 5779
count = 111
seq_step = 1
(kms_flip:11870) DEBUG: Vblank took 537us
(kms_flip:11870) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:11870) CRITICAL: Failed assertion: end - start < 500
(kms_flip:11870) igt_core-INFO: Stack trace:
(kms_flip:11870) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:11870) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:11870) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:11870) igt_core-INFO:   #3 ../tests/kms_flip.c:2120 __igt_unique____real_main2043()
(kms_flip:11870) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:11870) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:11870) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:11870) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A3: FAIL (3.969s)

Dmesg

<6> [606.494134] [IGT] kms_flip: starting dynamic subtest A-HDMI-A3

<7> [606.494632] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:555]

<7> [606.494892] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:557]

<7> [606.558666] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

<7> [606.559551] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]

<7> [606.559768] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C]

<7> [606.559968] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:504:pipe D]

<7> [606.560107] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.enable (expected yes, found no)

<7> [606.560419] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.active (expected yes, found no)

<7> [606.560648] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in cpu_transcoder (expected 3, found -1)

<7> [606.560861] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in lane_count (expected 4, found 0)

<7> [606.561067] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in dp_m_n (expected tu 64 data 5190451/8388608 link 288358/524288, found tu 0, data 0/0 link 0/0)

<7> [606.561272] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000)

<7> [606.561508] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in framestart_delay (expected 1, found 0)

<7> [606.561706] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)

<7> [606.561898] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)

<7> [606.562081] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)

<7> [606.562264] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)

<7> [606.562466] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)

<7> [606.562641] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)

<7> [606.562815] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)

<7> [606.562989] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)

<7> [606.563162] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)

<7> [606.563347] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)

<7> [606.563522] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)

<7> [606.563680] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)

<7> [606.563836] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)

<7> [606.563988] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)

<7> [606.564139] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)

<7> [606.564305] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)

<7> [606.564455] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)

<7> [606.564600] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)

<7> [606.564725] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)

<7> [606.564818] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)

<7> [606.564909] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)

<7> [606.565002] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)

<7> [606.565095] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)

<7> [606.565187] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)

<7> [606.565284] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in pixel_multiplier (expected 1, found 0)

<7> [606.565379] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)

<7> [606.565472] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)

<7> [606.565565] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in enhanced_framing (expected yes, found no)

<7> [606.565658] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in pipe_bpp (expected 36, found 0)

<7> [606.565751] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)

<7> [606.565843] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)

<7> [606.565935] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:504:pipe D] fastset requirement not met in port_clock (expected 270000, found 0)

<7> [606.566029] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:504:pipe D] fastset requirement not met, forcing full modeset

<7> [606.566122] xe 0000:03:00.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:504:pipe D] releasing TC PLL 2

<7> [606.566232] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no

<7> [606.566323] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:504:pipe D] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x8 -> 0x0

<7> [606.566423] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:498:cursor D] ddb (1989 - 2048) -> ( 0 - 0), size 59 -> 0

<7> [606.566524] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:504:pipe D] min cdclk: 192000 kHz -> 0 kHz

<7> [606.566640] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:504:pipe D] enable: no [modeset]

<7> [606.566738] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:388:plane 1D] fb: [NOFB], visible: no

<7> [606.566837] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:418:plane 2D] fb: [NOFB], visible: no

<7> [606.566932] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:448:plane 3D] fb: [NOFB], visible: no

<7> [606.567025] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:478:plane 4D] fb: [NOFB], visible: no

<7> [606.567118] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:488:plane 5D] fb: [NOFB], visible: no

<7> [606.567210] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:498:cursor D] fb: [NOFB], visible: no

<7> [606.567612] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:526:DP-2][ENCODER:525:DDI TC2/PHY G] Disable audio codec on [CRTC:504:pipe D]

<7> [606.588451] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe D

<7> [606.609387] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2

<7> [606.612855] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disable TC PLL 2 (active 0x8, on? 1) for [CRTC:504:pipe D]

<7> [606.615597] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disabling TC PLL 2

<7> [606.616451] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:506:DDI TC1/PHY F]

<7> [606.616923] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:508:DP-MST A]

<7> [606.617410] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST B]

<7> [606.617870] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST C]

<7> [606.618348] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST D]

<7> [606.618784] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:525:DDI TC2/PHY G]

<7> [606.619458] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:527:DP-MST A]

<7> [606.619911] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST B]

<7> [606.620368] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST C]

<7> [606.620746] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST D]

<7> [606.621128] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:537:DDI TC3/PHY H]

<7> [606.621532] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:541:DDI TC4/PHY I]

<7> [606.621876] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:543:DP-MST A]

<7> [606.622218] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST B]

<7> [606.622581] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST C]

<7> [606.622906] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST D]

<7> [606.623225] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:526:DP-2]

<7> [606.623812] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)

<7> [606.624303] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1

<7> [606.624893] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_D

<7> [606.625400] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x8 (CLKGATE_DIS_DSSDSC=0xaa000000)

<7> [606.625914] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2

<7> [606.626420] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:504:pipe D]

<7> [606.627076] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

<7> [606.627134] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:538:HDMI-A-3]

<7> [606.627301] xe 0000:03:00.0: [drm:intel_hdmi_compute_clock [xe]] picking 12 bpc for HDMI output (pipe bpp: 36)

<7> [606.627525] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0

<7> [606.627739] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:537:DDI TC3/PHY H] [CRTC:150:pipe A]

<7> [606.627942] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes)

<7> [606.628143] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes)

<7> [606.628345] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)

<7> [606.628529] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4)

<7> [606.628700] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)

<7> [606.628870] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)

<7> [606.629039] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)

<7> [606.629208] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)

<7> [606.629380] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)

<7> [606.629540] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)

<7> [606.629686] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)

<7> [606.629828] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)

<7> [606.629967] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)

<7> [606.630106] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)

<7> [606.630243] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083)

<7> [606.630389] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088)

<7> [606.630519] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)

<7> [606.630646] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)

<7> [606.630770] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)

<7> [606.630892] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)

<7> [606.631012] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)

<7> [606.631132] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)

<7> [606.631258] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)

<7> [606.631386] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)

<7> [606.631501] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)

<7> [606.631610] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)

<7> [606.631719] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083)

<7> [606.631824] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088)

<7> [606.631935] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)

<7> [606.632040] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)

<7> [606.632144] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)

<7> [606.632245] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)

<7> [606.632350] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)

<7> [606.632449] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)

<7> [606.632542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)

<7> [606.632637] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dpll_hw_state

<7> [606.632726] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:

<7> [606.632815] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no

<7> [606.632903] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:

<7> [606.632989] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x4800, tx[2] = 0x0000

<7> [606.633075] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000

<7> [606.633161] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x308c

<7> [606.633245] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x2110

<7> [606.633339] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0xcc9c

<7> [606.633425] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0xbfc1

<7> [606.633509] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x4b9a

<7> [606.633593] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x3f81

<7> [606.633678] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2000

<7> [606.633762] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0x0001

<7> [606.633846] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x5000

<7> [606.633930] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000

<7> [606.634012] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000

<7> [606.634097] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x42, hdmi rate: 0x00

<7> [606.634184] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:

<7> [606.634280] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no

<7> [606.634370] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:

<7> [606.634457] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000

<7> [606.634542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000

<7> [606.634627] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x40e8

<7> [606.634712] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x7d20

<7> [606.634797] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0x0a06

<7> [606.634882] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0x8f1c

<7> [606.634967] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x0000

<7> [606.635052] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x0000

<7> [606.635137] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2200

<7> [606.635222] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0xffff

<7> [606.635317] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x0400

<7> [606.635401] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000

<7> [606.635490] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0001

<7> [606.635578] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00

<7> [606.635666] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)

<7> [606.635754] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)

<7> [606.635840] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)

<7> [606.635925] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 222750)

<7> [606.636010] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)

<7> [606.636093] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)

<7> [606.636178] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in avi infoframe

<7> [606.636262] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:

<7> [606.636356] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:

<7> [606.636441] xe 0000:03:00.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13

<7> [606.636443] xe 0000:03:00.0: colorspace: RGB

<7> [606.636444] xe 0000:03:00.0: scan mode: Underscan

<7> [606.636445] xe 0000:03:00.0: colorimetry: No Data

<7> [606.636446] xe 0000:03:00.0: picture aspect: No Data

<7> [606.636447] xe 0000:03:00.0: active aspect: Same as Picture

<7> [606.636448] xe 0000:03:00.0: itc: No Data

<7> [606.636449] xe 0000:03:00.0: extended colorimetry: xvYCC 601

<7> [606.636450] xe 0000:03:00.0: quantization range: Full

<7> [606.636451] xe 0000:03:00.0: nups: Unknown Non-uniform Scaling

<7> [606.636452] xe 0000:03:00.0: video code: 0

<7> [606.636453] xe 0000:03:00.0: ycc quantization range: Full

<7> [606.636454] xe 0000:03:00.0: hdmi content type: Graphics

<7> [606.636455] xe 0000:03:00.0: pixel repeat: 0

<7> [606.636456] xe 0000:03:00.0: bar top 0, bottom 0, left 0, right 0

<7> [606.636458] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in spd infoframe

<7> [606.636542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:

<7> [606.636627] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:

<7> [606.636711] xe 0000:03:00.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25

<7> [606.636712] xe 0000:03:00.0: vendor: Intel

<7> [606.636713] xe 0000:03:00.0: product: Discrete gfx

<7> [606.636714] xe 0000:03:00.0: source device information: PC General (0x9)

<7> [606.636715] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hdmi infoframe

<7> [606.636800] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:

<7> [606.636884] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:

<7> [606.636970] xe 0000:03:00.0: HDMI infoframe: Vendor, version 1, length 4

<7> [606.636971] xe 0000:03:00.0: empty frame

<7> [606.636972] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset

<7> [606.637087] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes

<7> [606.637161] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1

<7> [606.637255] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4037), size 0 -> 4037

<7> [606.637342] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4037 - 4096), size 0 -> 59

<7> [606.637412] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm

<7> [606.637482] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 9, 9, 17, 17, 17, 17, 0, 15, 0

<7> [606.637551] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 139, 139, 261, 261, 261, 261, 137, 230, 244

<7> [606.637619] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 245, 245, 367, 367, 0, 0, 138, 306, 306

<7> [606.637699] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 594000 num active planes 1

<7> [606.637791] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 624 qgv_peak_bw: 48000

<7> [606.637881] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 624 qgv_peak_bw: 48000

<7> [606.637968] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 624

<7> [606.638054] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 192000 kHz

<7> [606.638165] xe 0000:03:00.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated TC PLL 3

<7> [606.638256] xe 0000:03:00.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving TC PLL 3

<7> [606.638354] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset]

<7> [606.638444] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB

<7> [606.638534] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 36, dithering: 0

<7> [606.638621] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>

<7> [606.638709] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0

<7> [606.638792] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0

<7> [606.638879] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0

<7> [606.638964] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 1, infoframes enabled: 0x71

<7> [606.639048] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] GCP: 0x6

<7> [606.639135] xe 0000:03:00.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13

<7> [606.639137] xe 0000:03:00.0: colorspace: RGB

<7> [606.639138] xe 0000:03:00.0: scan mode: Underscan

<7> [606.639139] xe 0000:03:00.0: colorimetry: No Data

<7> [606.639140] xe 0000:03:00.0: picture aspect: No Data

<7> [606.639141] xe 0000:03:00.0: active aspect: Same as Picture

<7> [606.639142] xe 0000:03:00.0: itc: No Data

<7> [606.639143] xe 0000:03:00.0: extended colorimetry: xvYCC 601

<7> [606.639144] xe 0000:03:00.0: quantization range: Full

<7> [606.639145] xe 0000:03:00.0: nups: Unknown Non-uniform Scaling

<7> [606.639146] xe 0000:03:00.0: video code: 0

<7> [606.639147] xe 0000:03:00.0: ycc quantization range: Full

<7> [606.639148] xe 0000:03:00.0: hdmi content type: Graphics

<7> [606.639149] xe 0000:03:00.0: pixel repeat: 0

<7> [606.639150] xe 0000:03:00.0: bar top 0, bottom 0, left 0, right 0

<7> [606.639151] xe 0000:03:00.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25

<7> [606.639152] xe 0000:03:00.0: vendor: Intel

<7> [606.639153] xe 0000:03:00.0: product: Discrete gfx

<7> [606.639154] xe 0000:03:00.0: source device information: PC General (0x9)

<7> [606.639155] xe 0000:03:00.0: HDMI infoframe: Vendor, version 1, length 4

<7> [606.639156] xe 0000:03:00.0: empty frame

<7> [606.639157] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00

<7> [606.639246] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00

<7> [606.639342] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1

<7> [606.639427] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0

<7> [606.639511] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 42, vsync end: 37

<7> [606.639595] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125

<7> [606.639679] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0

<7> [606.639764] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9

<7> [606.639848] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9

<7> [606.639932] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

<7> [606.640017] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9

<7> [606.640100] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9

<7> [606.640181] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 222750, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000

<7> [606.640264] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0

<7> [606.640359] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0

<7> [606.640444] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no

<7> [606.640526] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0

<7> [606.640609] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no

<7> [606.640694] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] c20pll_hw_state:

<7> [606.640781] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000

<7> [606.640868] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000

<7> [606.640953] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[0] = 0x40e8

<7> [606.641038] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[1] = 0x7d20

<7> [606.641123] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[2] = 0x0a06

<7> [606.641207] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[3] = 0x8f1c

<7> [606.641294] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[4] = 0x0000

<7> [606.641383] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[5] = 0x0000

<7> [606.641467] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[6] = 0x2200

<7> [606.641549] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[7] = 0xffff

<7> [606.641633] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[8] = 0x0400

<7> [606.641716] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[9] = 0x0000

<7> [606.641799] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[10] = 0x0001

<7> [606.641881] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00

<7> [606.641964] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

<7> [606.642048] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries

<7> [606.642129] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000

<7> [606.642211] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [606.642302] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [606.642385] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [606.642467] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000

<7> [606.642554] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000

<7> [606.642641] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [606.642725] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [606.642810] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [606.642894] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000

<7> [606.642980] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0

<7> [606.643064] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:555] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

<7> [606.643148] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 1

<7> [606.643232] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0

<7> [606.643343] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no

<7> [606.643427] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no

<7> [606.643510] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no

<7> [606.643593] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no

<7> [606.643676] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no

<7> [606.644288] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_A

<7> [606.644423] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)

<7> [606.644517] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2

<7> [606.644645] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:506:DDI TC1/PHY F]

<7> [606.644729] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:508:DP-MST A]

<7> [606.644808] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST B]

<7> [606.644887] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST C]

<7> [606.644966] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST D]

<7> [606.645044] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:525:DDI TC2/PHY G]

<7> [606.645121] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:527:DP-MST A]

<7> [606.645198] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST B]

<7> [606.645282] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST C]

<7> [606.645362] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST D]

<7> [606.645441] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:537:DDI TC3/PHY H]

<7> [606.645520] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:541:DDI TC4/PHY I]

<7> [606.645597] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:543:DP-MST A]

<7> [606.645673] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST B]

<7> [606.645749] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST C]

<7> [606.645825] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST D]

<7> [606.645911] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf

<7> [606.646065] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)

<7> [606.646137] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: yes)

<7> [606.646233] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enable TC PLL 3 (active 0x1, on? 0) for [CRTC:150:pipe A]

<7> [606.646327] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enabling TC PLL 3

<7> [606.648806] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe A

<7> [606.667182] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:538:HDMI-A-3][ENCODER:537:DDI TC3/PHY H] Enable audio codec on [CRTC:150:pipe A], 32 bytes ELD

<7> [606.683808] xe 0000:03:00.0: [drm:audio_config_hdmi_pixel_clock [xe]] Configuring HDMI audio for pixel clock 148500 (0x00090000)

<7> [606.683973] xe 0000:03:00.0: [drm:hsw_audio_config_update [xe]] using automatic N

<7> [606.684542] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:538:HDMI-A-3]

<7> [606.684964] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]

<7> [606.718533] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2

<7> [610.294263] xe 0000:03:00.0: [drm:xe_hwmon_read [xe]] thermal data for group 0 val 0x21201f21

<7> [610.294456] xe 0000:03:00.0: [drm:xe_hwmon_read [xe]] thermal data for group 1 val 0x23222121

<6> [610.464856] [IGT] kms_flip: finished subtest A-HDMI-A3, FAIL

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