igt@kms_flip@flip-vs-expired-vblank-interruptible@a-edp1 on shard-lnl@IGT

Detail	Value
Duration	4.30 seconds
Hostname	shard-lnl-2
Igt-Version	IGT-Version: 2.3-gc623172fd (x86_64) (Linux: 7.0.0-rc3-lgci-xe-xe-4699-215a6363df58623db-debug+ x86_64)
Out	Using IGT_SRANDOM=1773285122 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-eDP1 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043() #4 ../tests/kms_flip.c:2043 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (4.301s)
Err	Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-eDP1 (kms_flip:6378) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:6378) CRITICAL: Failed assertion: end - start < 500 (kms_flip:6378) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:6378) DEBUG: Vblank took 56us (kms_flip:6378) DEBUG: name = flip last_ts = 333.352203 last_received_ts = 333.351654 last_seq = 3494 current_ts = 333.368866 current_received_ts = 333.368195 current_seq = 3495 count = 64 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.368866 last_received_ts = 333.368195 last_seq = 3495 current_ts = 333.385529 current_received_ts = 333.384949 current_seq = 3496 count = 65 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 89us (kms_flip:6378) DEBUG: name = flip last_ts = 333.385529 last_received_ts = 333.384949 last_seq = 3496 current_ts = 333.402191 current_received_ts = 333.401642 current_seq = 3497 count = 66 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 54us (kms_flip:6378) DEBUG: name = flip last_ts = 333.402191 last_received_ts = 333.401642 last_seq = 3497 current_ts = 333.418854 current_received_ts = 333.418274 current_seq = 3498 count = 67 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 56us (kms_flip:6378) DEBUG: name = flip last_ts = 333.418854 last_received_ts = 333.418274 last_seq = 3498 current_ts = 333.435516 current_received_ts = 333.434845 current_seq = 3499 count = 68 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.435516 last_received_ts = 333.434845 last_seq = 3499 current_ts = 333.452179 current_received_ts = 333.451599 current_seq = 3500 count = 69 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.452179 last_received_ts = 333.451599 last_seq = 3500 current_ts = 333.468842 current_received_ts = 333.468262 current_seq = 3501 count = 70 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 333.468842 last_received_ts = 333.468262 last_seq = 3501 current_ts = 333.485504 current_received_ts = 333.484924 current_seq = 3502 count = 71 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.485504 last_received_ts = 333.484924 last_seq = 3502 current_ts = 333.502167 current_received_ts = 333.501617 current_seq = 3503 count = 72 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.502167 last_received_ts = 333.501617 last_seq = 3503 current_ts = 333.518829 current_received_ts = 333.518250 current_seq = 3504 count = 73 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 40us (kms_flip:6378) DEBUG: name = flip last_ts = 333.518829 last_received_ts = 333.518250 last_seq = 3504 current_ts = 333.535522 current_received_ts = 333.534912 current_seq = 3505 count = 74 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 57us (kms_flip:6378) DEBUG: name = flip last_ts = 333.535522 last_received_ts = 333.534912 last_seq = 3505 current_ts = 333.552185 current_received_ts = 333.551605 current_seq = 3506 count = 75 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 54us (kms_flip:6378) DEBUG: name = flip last_ts = 333.552185 last_received_ts = 333.551605 last_seq = 3506 current_ts = 333.568848 current_received_ts = 333.568237 current_seq = 3507 count = 76 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 333.568848 last_received_ts = 333.568237 last_seq = 3507 current_ts = 333.585510 current_received_ts = 333.584930 current_seq = 3508 count = 77 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.585510 last_received_ts = 333.584930 last_seq = 3508 current_ts = 333.602173 current_received_ts = 333.601593 current_seq = 3509 count = 78 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.602173 last_received_ts = 333.601593 last_seq = 3509 current_ts = 333.618835 current_received_ts = 333.618164 current_seq = 3510 count = 79 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 56us (kms_flip:6378) DEBUG: name = flip last_ts = 333.618835 last_received_ts = 333.618164 last_seq = 3510 current_ts = 333.635498 current_received_ts = 333.634796 current_seq = 3511 count = 80 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 54us (kms_flip:6378) DEBUG: name = flip last_ts = 333.635498 last_received_ts = 333.634796 last_seq = 3511 current_ts = 333.652161 current_received_ts = 333.651581 current_seq = 3512 count = 81 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 54us (kms_flip:6378) DEBUG: name = flip last_ts = 333.652161 last_received_ts = 333.651581 last_seq = 3512 current_ts = 333.668823 current_received_ts = 333.668243 current_seq = 3513 count = 82 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 40us (kms_flip:6378) DEBUG: name = flip last_ts = 333.668823 last_received_ts = 333.668243 last_seq = 3513 current_ts = 333.685486 current_received_ts = 333.684845 current_seq = 3514 count = 83 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.685486 last_received_ts = 333.684845 last_seq = 3514 current_ts = 333.702148 current_received_ts = 333.701569 current_seq = 3515 count = 84 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.702148 last_received_ts = 333.701569 last_seq = 3515 current_ts = 333.718811 current_received_ts = 333.718231 current_seq = 3516 count = 85 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.718811 last_received_ts = 333.718231 last_seq = 3516 current_ts = 333.735474 current_received_ts = 333.734802 current_seq = 3517 count = 86 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 333.735474 last_received_ts = 333.734802 last_seq = 3517 current_ts = 333.752136 current_received_ts = 333.751556 current_seq = 3518 count = 87 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 53us (kms_flip:6378) DEBUG: name = flip last_ts = 333.752136 last_received_ts = 333.751556 last_seq = 3518 current_ts = 333.768829 current_received_ts = 333.768219 current_seq = 3519 count = 88 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 38us (kms_flip:6378) DEBUG: name = flip last_ts = 333.768829 last_received_ts = 333.768219 last_seq = 3519 current_ts = 333.785461 current_received_ts = 333.784790 current_seq = 3520 count = 89 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 39us (kms_flip:6378) DEBUG: name = flip last_ts = 333.785461 last_received_ts = 333.784790 last_seq = 3520 current_ts = 333.802155 current_received_ts = 333.801544 current_seq = 3521 count = 90 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 39us (kms_flip:6378) DEBUG: name = flip last_ts = 333.802155 last_received_ts = 333.801544 last_seq = 3521 current_ts = 333.818817 current_received_ts = 333.818207 current_seq = 3522 count = 91 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 82us (kms_flip:6378) DEBUG: name = flip last_ts = 333.818817 last_received_ts = 333.818207 last_seq = 3522 current_ts = 333.835480 current_received_ts = 333.834808 current_seq = 3523 count = 92 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 44us (kms_flip:6378) DEBUG: name = flip last_ts = 333.835480 last_received_ts = 333.834808 last_seq = 3523 current_ts = 333.852142 current_received_ts = 333.851562 current_seq = 3524 count = 93 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 69us (kms_flip:6378) DEBUG: name = flip last_ts = 333.852142 last_received_ts = 333.851562 last_seq = 3524 current_ts = 333.868805 current_received_ts = 333.868134 current_seq = 3525 count = 94 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 64us (kms_flip:6378) DEBUG: name = flip last_ts = 333.868805 last_received_ts = 333.868134 last_seq = 3525 current_ts = 333.885468 current_received_ts = 333.884888 current_seq = 3526 count = 95 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 333.885468 last_received_ts = 333.884888 last_seq = 3526 current_ts = 333.902130 current_received_ts = 333.901489 current_seq = 3527 count = 96 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 333.902130 last_received_ts = 333.901489 last_seq = 3527 current_ts = 333.918793 current_received_ts = 333.918060 current_seq = 3528 count = 97 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 333.918793 last_received_ts = 333.918060 last_seq = 3528 current_ts = 333.935455 current_received_ts = 333.934784 current_seq = 3529 count = 98 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 333.935455 last_received_ts = 333.934784 last_seq = 3529 current_ts = 333.952118 current_received_ts = 333.951508 current_seq = 3530 count = 99 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 333.952118 last_received_ts = 333.951508 last_seq = 3530 current_ts = 333.968781 current_received_ts = 333.968140 current_seq = 3531 count = 100 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 42us (kms_flip:6378) DEBUG: name = flip last_ts = 333.968781 last_received_ts = 333.968140 last_seq = 3531 current_ts = 333.985443 current_received_ts = 333.984894 current_seq = 3532 count = 101 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 333.985443 last_received_ts = 333.984894 last_seq = 3532 current_ts = 334.002106 current_received_ts = 334.001495 current_seq = 3533 count = 102 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.002106 last_received_ts = 334.001495 last_seq = 3533 current_ts = 334.018768 current_received_ts = 334.018188 current_seq = 3534 count = 103 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.018768 last_received_ts = 334.018188 last_seq = 3534 current_ts = 334.035461 current_received_ts = 334.034790 current_seq = 3535 count = 104 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.035461 last_received_ts = 334.034790 last_seq = 3535 current_ts = 334.052094 current_received_ts = 334.051544 current_seq = 3536 count = 105 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 56us (kms_flip:6378) DEBUG: name = flip last_ts = 334.052094 last_received_ts = 334.051544 last_seq = 3536 current_ts = 334.068787 current_received_ts = 334.068054 current_seq = 3537 count = 106 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 55us (kms_flip:6378) DEBUG: name = flip last_ts = 334.068787 last_received_ts = 334.068054 last_seq = 3537 current_ts = 334.085449 current_received_ts = 334.084808 current_seq = 3538 count = 107 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.085449 last_received_ts = 334.084808 last_seq = 3538 current_ts = 334.102112 current_received_ts = 334.101471 current_seq = 3539 count = 108 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.102112 last_received_ts = 334.101471 last_seq = 3539 current_ts = 334.118774 current_received_ts = 334.118073 current_seq = 3540 count = 109 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.118774 last_received_ts = 334.118073 last_seq = 3540 current_ts = 334.135437 current_received_ts = 334.134766 current_seq = 3541 count = 110 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.135437 last_received_ts = 334.134766 last_seq = 3541 current_ts = 334.152100 current_received_ts = 334.151520 current_seq = 3542 count = 111 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.152100 last_received_ts = 334.151520 last_seq = 3542 current_ts = 334.168762 current_received_ts = 334.168091 current_seq = 3543 count = 112 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.168762 last_received_ts = 334.168091 last_seq = 3543 current_ts = 334.185425 current_received_ts = 334.184784 current_seq = 3544 count = 113 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 57us (kms_flip:6378) DEBUG: name = flip last_ts = 334.185425 last_received_ts = 334.184784 last_seq = 3544 current_ts = 334.202087 current_received_ts = 334.201538 current_seq = 3545 count = 114 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 54us (kms_flip:6378) DEBUG: name = flip last_ts = 334.202087 last_received_ts = 334.201538 last_seq = 3545 current_ts = 334.218750 current_received_ts = 334.218109 current_seq = 3546 count = 115 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.218750 last_received_ts = 334.218109 last_seq = 3546 current_ts = 334.235413 current_received_ts = 334.234772 current_seq = 3547 count = 116 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 334.235413 last_received_ts = 334.234772 last_seq = 3547 current_ts = 334.252075 current_received_ts = 334.251465 current_seq = 3548 count = 117 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 41us (kms_flip:6378) DEBUG: name = flip last_ts = 334.252075 last_received_ts = 334.251465 last_seq = 3548 current_ts = 334.268738 current_received_ts = 334.268158 current_seq = 3549 count = 118 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 334.268738 last_received_ts = 334.268158 last_seq = 3549 current_ts = 334.285431 current_received_ts = 334.284729 current_seq = 3550 count = 119 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.285431 last_received_ts = 334.284729 last_seq = 3550 current_ts = 334.302063 current_received_ts = 334.301483 current_seq = 3551 count = 120 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.302063 last_received_ts = 334.301483 last_seq = 3551 current_ts = 334.318756 current_received_ts = 334.318115 current_seq = 3552 count = 121 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.318756 last_received_ts = 334.318115 last_seq = 3552 current_ts = 334.335419 current_received_ts = 334.334656 current_seq = 3553 count = 122 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 334.335419 last_received_ts = 334.334656 last_seq = 3553 current_ts = 334.352081 current_received_ts = 334.351501 current_seq = 3554 count = 123 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 61us (kms_flip:6378) DEBUG: name = flip last_ts = 334.352081 last_received_ts = 334.351501 last_seq = 3554 current_ts = 334.368744 current_received_ts = 334.368042 current_seq = 3555 count = 124 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 61us (kms_flip:6378) DEBUG: name = flip last_ts = 334.368744 last_received_ts = 334.368042 last_seq = 3555 current_ts = 334.385406 current_received_ts = 334.384857 current_seq = 3556 count = 125 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.385406 last_received_ts = 334.384857 last_seq = 3556 current_ts = 334.402069 current_received_ts = 334.401489 current_seq = 3557 count = 126 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.402069 last_received_ts = 334.401489 last_seq = 3557 current_ts = 334.418732 current_received_ts = 334.417999 current_seq = 3558 count = 127 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.418732 last_received_ts = 334.417999 last_seq = 3558 current_ts = 334.435394 current_received_ts = 334.434753 current_seq = 3559 count = 128 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.435394 last_received_ts = 334.434753 last_seq = 3559 current_ts = 334.452057 current_received_ts = 334.451477 current_seq = 3560 count = 129 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 54us (kms_flip:6378) DEBUG: name = flip last_ts = 334.452057 last_received_ts = 334.451477 last_seq = 3560 current_ts = 334.468719 current_received_ts = 334.468079 current_seq = 3561 count = 130 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 39us (kms_flip:6378) DEBUG: name = flip last_ts = 334.468719 last_received_ts = 334.468079 last_seq = 3561 current_ts = 334.485382 current_received_ts = 334.484772 current_seq = 3562 count = 131 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 37us (kms_flip:6378) DEBUG: name = flip last_ts = 334.485382 last_received_ts = 334.484772 last_seq = 3562 current_ts = 334.502045 current_received_ts = 334.501465 current_seq = 3563 count = 132 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 73us (kms_flip:6378) DEBUG: name = flip last_ts = 334.502045 last_received_ts = 334.501465 last_seq = 3563 current_ts = 334.518707 current_received_ts = 334.518127 current_seq = 3564 count = 133 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.518707 last_received_ts = 334.518127 last_seq = 3564 current_ts = 334.535370 current_received_ts = 334.534729 current_seq = 3565 count = 134 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.535370 last_received_ts = 334.534729 last_seq = 3565 current_ts = 334.552063 current_received_ts = 334.551483 current_seq = 3566 count = 135 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.552063 last_received_ts = 334.551483 last_seq = 3566 current_ts = 334.568695 current_received_ts = 334.568085 current_seq = 3567 count = 136 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 334.568695 last_received_ts = 334.568085 last_seq = 3567 current_ts = 334.585388 current_received_ts = 334.584717 current_seq = 3568 count = 137 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.585388 last_received_ts = 334.584717 last_seq = 3568 current_ts = 334.602051 current_received_ts = 334.601471 current_seq = 3569 count = 138 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.602051 last_received_ts = 334.601471 last_seq = 3569 current_ts = 334.618713 current_received_ts = 334.618073 current_seq = 3570 count = 139 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.618713 last_received_ts = 334.618073 last_seq = 3570 current_ts = 334.635376 current_received_ts = 334.634796 current_seq = 3571 count = 140 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.635376 last_received_ts = 334.634796 last_seq = 3571 current_ts = 334.652039 current_received_ts = 334.651428 current_seq = 3572 count = 141 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 143us (kms_flip:6378) DEBUG: name = flip last_ts = 334.652039 last_received_ts = 334.651428 last_seq = 3572 current_ts = 334.668701 current_received_ts = 334.668060 current_seq = 3573 count = 142 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 67us (kms_flip:6378) DEBUG: name = flip last_ts = 334.668701 last_received_ts = 334.668060 last_seq = 3573 current_ts = 334.685364 current_received_ts = 334.684631 current_seq = 3574 count = 143 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 63us (kms_flip:6378) DEBUG: name = flip last_ts = 334.685364 last_received_ts = 334.684631 last_seq = 3574 current_ts = 334.702026 current_received_ts = 334.701385 current_seq = 3575 count = 144 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 334.702026 last_received_ts = 334.701385 last_seq = 3575 current_ts = 334.718689 current_received_ts = 334.718079 current_seq = 3576 count = 145 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 334.718689 last_received_ts = 334.718079 last_seq = 3576 current_ts = 334.735352 current_received_ts = 334.734619 current_seq = 3577 count = 146 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.735352 last_received_ts = 334.734619 last_seq = 3577 current_ts = 334.752014 current_received_ts = 334.751465 current_seq = 3578 count = 147 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 44us (kms_flip:6378) DEBUG: name = flip last_ts = 334.752014 last_received_ts = 334.751465 last_seq = 3578 current_ts = 334.768677 current_received_ts = 334.768036 current_seq = 3579 count = 148 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 43us (kms_flip:6378) DEBUG: name = flip last_ts = 334.768677 last_received_ts = 334.768036 last_seq = 3579 current_ts = 334.785339 current_received_ts = 334.784821 current_seq = 3580 count = 149 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 334.785339 last_received_ts = 334.784821 last_seq = 3580 current_ts = 334.802002 current_received_ts = 334.801392 current_seq = 3581 count = 150 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 54us (kms_flip:6378) DEBUG: name = flip last_ts = 334.802002 last_received_ts = 334.801392 last_seq = 3581 current_ts = 334.818695 current_received_ts = 334.818054 current_seq = 3582 count = 151 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 68us (kms_flip:6378) DEBUG: name = flip last_ts = 334.818695 last_received_ts = 334.818054 last_seq = 3582 current_ts = 334.835358 current_received_ts = 334.834595 current_seq = 3583 count = 152 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 64us (kms_flip:6378) DEBUG: name = flip last_ts = 334.835358 last_received_ts = 334.834595 last_seq = 3583 current_ts = 334.852020 current_received_ts = 334.851349 current_seq = 3584 count = 153 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 49us (kms_flip:6378) DEBUG: name = flip last_ts = 334.852020 last_received_ts = 334.851349 last_seq = 3584 current_ts = 334.868683 current_received_ts = 334.868042 current_seq = 3585 count = 154 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 49us (kms_flip:6378) DEBUG: name = flip last_ts = 334.868683 last_received_ts = 334.868042 last_seq = 3585 current_ts = 334.885345 current_received_ts = 334.884766 current_seq = 3586 count = 155 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 65us (kms_flip:6378) DEBUG: name = flip last_ts = 334.885345 last_received_ts = 334.884766 last_seq = 3586 current_ts = 334.902008 current_received_ts = 334.901367 current_seq = 3587 count = 156 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 84us (kms_flip:6378) DEBUG: name = flip last_ts = 334.902008 last_received_ts = 334.901367 last_seq = 3587 current_ts = 334.918671 current_received_ts = 334.918121 current_seq = 3588 count = 157 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 64us (kms_flip:6378) DEBUG: name = flip last_ts = 334.918671 last_received_ts = 334.918121 last_seq = 3588 current_ts = 334.935333 current_received_ts = 334.934692 current_seq = 3589 count = 158 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 334.935333 last_received_ts = 334.934692 last_seq = 3589 current_ts = 334.951996 current_received_ts = 334.951447 current_seq = 3590 count = 159 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 63us (kms_flip:6378) DEBUG: name = flip last_ts = 334.951996 last_received_ts = 334.951447 last_seq = 3590 current_ts = 334.968658 current_received_ts = 334.968109 current_seq = 3591 count = 160 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 63us (kms_flip:6378) DEBUG: name = flip last_ts = 334.968658 last_received_ts = 334.968109 last_seq = 3591 current_ts = 334.985321 current_received_ts = 334.984741 current_seq = 3592 count = 161 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 63us (kms_flip:6378) DEBUG: name = flip last_ts = 334.985321 last_received_ts = 334.984741 last_seq = 3592 current_ts = 335.001984 current_received_ts = 335.001343 current_seq = 3593 count = 162 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 43us (kms_flip:6378) DEBUG: name = flip last_ts = 335.001984 last_received_ts = 335.001343 last_seq = 3593 current_ts = 335.018646 current_received_ts = 335.018066 current_seq = 3594 count = 163 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 335.018646 last_received_ts = 335.018066 last_seq = 3594 current_ts = 335.035309 current_received_ts = 335.034729 current_seq = 3595 count = 164 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 335.035309 last_received_ts = 335.034729 last_seq = 3595 current_ts = 335.052002 current_received_ts = 335.051422 current_seq = 3596 count = 165 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 58us (kms_flip:6378) DEBUG: name = flip last_ts = 335.052002 last_received_ts = 335.051422 last_seq = 3596 current_ts = 335.068634 current_received_ts = 335.068024 current_seq = 3597 count = 166 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 43us (kms_flip:6378) DEBUG: name = flip last_ts = 335.068634 last_received_ts = 335.068024 last_seq = 3597 current_ts = 335.085297 current_received_ts = 335.084656 current_seq = 3598 count = 167 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 44us (kms_flip:6378) DEBUG: name = flip last_ts = 335.085297 last_received_ts = 335.084656 last_seq = 3598 current_ts = 335.101990 current_received_ts = 335.101318 current_seq = 3599 count = 168 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 43us (kms_flip:6378) DEBUG: name = flip last_ts = 335.101990 last_received_ts = 335.101318 last_seq = 3599 current_ts = 335.118652 current_received_ts = 335.118011 current_seq = 3600 count = 169 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 41us (kms_flip:6378) DEBUG: name = flip last_ts = 335.118652 last_received_ts = 335.118011 last_seq = 3600 current_ts = 335.135315 current_received_ts = 335.134552 current_seq = 3601 count = 170 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 61us (kms_flip:6378) DEBUG: name = flip last_ts = 335.135315 last_received_ts = 335.134552 last_seq = 3601 current_ts = 335.151978 current_received_ts = 335.151306 current_seq = 3602 count = 171 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 41us (kms_flip:6378) DEBUG: name = flip last_ts = 335.151978 last_received_ts = 335.151306 last_seq = 3602 current_ts = 335.168640 current_received_ts = 335.167999 current_seq = 3603 count = 172 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 64us (kms_flip:6378) DEBUG: name = flip last_ts = 335.168640 last_received_ts = 335.167999 last_seq = 3603 current_ts = 335.185303 current_received_ts = 335.184570 current_seq = 3604 count = 173 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 335.185303 last_received_ts = 335.184570 last_seq = 3604 current_ts = 335.201965 current_received_ts = 335.201385 current_seq = 3605 count = 174 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 60us (kms_flip:6378) DEBUG: name = flip last_ts = 335.201965 last_received_ts = 335.201385 last_seq = 3605 current_ts = 335.218628 current_received_ts = 335.218109 current_seq = 3606 count = 175 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 59us (kms_flip:6378) DEBUG: name = flip last_ts = 335.218628 last_received_ts = 335.218109 last_seq = 3606 current_ts = 335.235291 current_received_ts = 335.234650 current_seq = 3607 count = 176 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 62us (kms_flip:6378) DEBUG: name = flip last_ts = 335.235291 last_received_ts = 335.234650 last_seq = 3607 current_ts = 335.251953 current_received_ts = 335.251404 current_seq = 3608 count = 177 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 62us (kms_flip:6378) DEBUG: name = flip last_ts = 335.251953 last_received_ts = 335.251404 last_seq = 3608 current_ts = 335.268616 current_received_ts = 335.268005 current_seq = 3609 count = 178 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 47us (kms_flip:6378) DEBUG: name = flip last_ts = 335.268616 last_received_ts = 335.268005 last_seq = 3609 current_ts = 335.285278 current_received_ts = 335.284668 current_seq = 3610 count = 179 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 62us (kms_flip:6378) DEBUG: name = flip last_ts = 335.285278 last_received_ts = 335.284668 last_seq = 3610 current_ts = 335.301941 current_received_ts = 335.301331 current_seq = 3611 count = 180 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 63us (kms_flip:6378) DEBUG: name = flip last_ts = 335.301941 last_received_ts = 335.301331 last_seq = 3611 current_ts = 335.318604 current_received_ts = 335.317963 current_seq = 3612 count = 181 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 70us (kms_flip:6378) DEBUG: name = flip last_ts = 335.318604 last_received_ts = 335.317963 last_seq = 3612 current_ts = 335.335266 current_received_ts = 335.334534 current_seq = 3613 count = 182 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 65us (kms_flip:6378) DEBUG: name = flip last_ts = 335.335266 last_received_ts = 335.334534 last_seq = 3613 current_ts = 335.351959 current_received_ts = 335.351288 current_seq = 3614 count = 183 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 63us (kms_flip:6378) DEBUG: name = flip last_ts = 335.351959 last_received_ts = 335.351288 last_seq = 3614 current_ts = 335.368622 current_received_ts = 335.367950 current_seq = 3615 count = 184 seq_step = 1 (kms_flip:6378) DEBUG: Vblank took 880us (kms_flip:6378) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:6378) CRITICAL: Failed assertion: end - start < 500 (kms_flip:6378) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:6378) igt_core-INFO: Stack trace: (kms_flip:6378) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:6378) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:6378) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:6378) igt_core-INFO: #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043() (kms_flip:6378) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:6378) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:6378) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:6378) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (4.301s)
Dmesg	<6> [331.080896] Console: switching to colour dummy device 80x25 <6> [331.081227] [IGT] kms_flip: executing <7> [331.087055] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] <7> [331.087065] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1] <7> [331.087214] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected <7> [331.087426] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] <7> [331.087429] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2] <7> [331.087541] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected <7> [331.087759] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] <7> [331.087762] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3] <7> [331.087902] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected <7> [331.088171] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] <7> [331.088173] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:392:eDP-1] <7> [331.088620] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00 <7> [331.089026] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [331.089134] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [331.089238] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [331.089358] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [331.089363] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [331.089364] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [331.089365] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [331.089368] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [331.089370] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [331.089371] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD monitor <5> [331.089374] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [331.089375] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD size 20, SAD count 0 <5> [331.089378] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [331.089389] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] VRR capable: yes <7> [331.089482] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [331.089572] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [331.089888] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [331.089890] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [331.089892] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [331.089954] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] probed modes: <7> [331.089957] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [331.089961] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [331.089973] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] <7> [331.089976] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1] <7> [331.090136] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected <7> [331.090146] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] <7> [331.090148] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2] <7> [331.090283] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected <7> [331.090293] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] <7> [331.090295] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3] <7> [331.090422] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected <6> [331.094094] [IGT] kms_flip: starting subtest flip-vs-expired-vblank-interruptible <6> [331.095457] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [331.096167] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430] <7> [331.096688] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:431] <7> [331.152258] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [331.152351] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [331.152478] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [331.152580] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [331.152677] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [331.152792] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0) <7> [331.152903] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [331.153011] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [331.153101] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [331.153187] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [331.153275] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [331.153364] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [331.153463] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [331.153565] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [331.153666] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [331.153768] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [331.153869] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [331.153969] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [331.154060] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [331.154144] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [331.154231] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [331.154315] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [331.154399] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [331.154482] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [331.154564] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [331.154645] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [331.154742] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [331.154837] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [331.154932] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [331.155029] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [331.155112] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [331.155184] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [331.155262] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [331.155355] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [331.155448] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [331.155538] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [331.155610] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [331.155681] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [331.155773] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [331.155866] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [331.155959] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:150:pipe A] releasing DPLL 0 <7> [331.156078] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [331.156143] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [331.156236] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [331.156311] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [331.156375] xe 0000:00:02.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> [331.156437] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [331.156499] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [331.156559] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [331.156629] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 0 num active planes 0 <7> [331.156720] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [331.156821] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [331.156920] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [331.157016] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [331.157114] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [331.157212] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [331.157320] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [331.157412] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [331.157490] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [331.157566] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [331.157664] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: no [modeset] <7> [331.157762] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [NOFB], visible: no <7> [331.157864] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [331.157966] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [331.158059] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [331.158146] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [331.158227] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [331.158338] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [331.158434] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [331.158575] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [331.168281] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [331.168392] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [331.373888] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 0 <7> [331.374597] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [331.385228] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power off <7> [331.385595] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power off time <7> [331.385998] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [331.437891] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [331.438313] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short <7> [331.447030] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [331.447438] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:150:pipe A] <7> [331.447490] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [331.448999] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [331.449479] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [331.450009] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A] <7> [331.450380] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1] <7> [331.450729] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A] <7> [331.451099] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B] <7> [331.451423] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C] <7> [331.451736] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2] <7> [331.452035] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A] <7> [331.452333] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B] <7> [331.452627] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C] <7> [331.452955] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3] <7> [331.453247] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A] <7> [331.453535] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B] <7> [331.453909] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C] <7> [331.454198] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1] <7> [331.454565] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [331.454881] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [331.455256] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [331.455741] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [331.456119] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [331.456568] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A] <7> [331.456952] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [331.457341] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [331.457657] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [331.458595] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B] <7> [331.459023] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C] <7> [331.459331] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [331.459406] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:392:eDP-1] <7> [331.459586] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:392:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [331.460006] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:150:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000 <7> [331.460366] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000 <7> [331.460683] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [331.461029] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:150:pipe A] <7> [331.461372] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [331.461632] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [331.461974] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [331.462243] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [331.462484] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288) <7> [331.462734] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [331.462959] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [331.463168] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [331.463374] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [331.463576] xe 0000:00:02.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 2880) <7> [331.463794] xe 0000:00:02.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 3040) <7> [331.463997] xe 0000:00:02.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 2928) <7> [331.464190] xe 0000:00:02.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 2960) <7> [331.464366] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [331.464563] xe 0000:00:02.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 1800) <7> [331.464763] xe 0000:00:02.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 1803) <7> [331.464933] xe 0000:00:02.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 1809) <7> [331.465097] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [331.465254] xe 0000:00:02.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 1906) <7> [331.465399] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [331.465542] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [331.465678] xe 0000:00:02.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 2880) <7> [331.465841] xe 0000:00:02.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 3040) <7> [331.465982] xe 0000:00:02.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 2928) <7> [331.466120] xe 0000:00:02.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 2960) <7> [331.466251] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [331.466374] xe 0000:00:02.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 1800) <7> [331.466495] xe 0000:00:02.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 1803) <7> [331.466615] xe 0000:00:02.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 1809) <7> [331.466788] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [331.466906] xe 0000:00:02.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 1906) <7> [331.467022] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [331.467137] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [331.467251] xe 0000:00:02.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> [331.467360] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [331.467466] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [331.467568] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [331.467667] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 432000) <7> [331.467778] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [331.467922] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [331.468024] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:150:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [331.468153] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [331.468248] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [331.468323] xe 0000:00:02.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> [331.468395] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 <7> [331.468463] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 <7> [331.468530] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 <7> [331.468618] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 1390840 num active planes 1 <7> [331.468720] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [331.468822] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [331.468921] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [331.469020] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [331.469111] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [331.469203] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [331.469312] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [331.469411] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [331.469511] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [331.469607] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [331.469717] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated DPLL 0 <7> [331.469815] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving DPLL 0 <7> [331.469917] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset] <7> [331.470020] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [331.470103] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0 <7> [331.470198] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [331.470288] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [331.470368] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [331.470443] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [331.470522] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64 <7> [331.470600] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0 <7> [331.470687] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [331.470796] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [331.470890] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [331.470984] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0 <7> [331.471066] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [331.471146] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [331.471220] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [331.471295] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [331.471387] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [331.471478] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [331.471564] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [331.471637] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [331.471708] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [331.471799] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97 <7> [331.471895] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906 <7> [331.471987] xe 0000:00:02.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> [331.472068] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [331.472146] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [331.472224] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [331.472302] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [331.472380] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [331.472457] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855 <7> [331.472530] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [331.472598] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [331.472667] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [331.472758] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [331.472854] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no <7> [331.472948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no, <7> [331.473037] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [331.473106] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [331.473176] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [331.473260] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [331.473348] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [331.473437] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [331.473515] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [331.473588] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [331.473659] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [331.473745] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [331.473839] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [331.473929] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [331.474017] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [331.474084] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [331.474157] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [331.474229] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [331.474302] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [331.474377] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [331.474390] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [331.474464] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [331.474514] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long <7> [331.474550] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [331.474613] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [331.474631] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [331.474722] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [331.474725] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [331.474814] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [331.474902] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [331.474991] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [331.475066] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [331.475154] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [331.475244] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [331.475333] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [331.475753] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [331.475935] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000) <7> [331.476049] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [331.476144] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [331.476235] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [331.476317] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A] <7> [331.476385] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1] <7> [331.476452] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A] <7> [331.476521] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B] <7> [331.476596] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C] <7> [331.476671] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2] <7> [331.476768] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A] <7> [331.476854] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B] <7> [331.476939] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C] <7> [331.477024] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3] <7> [331.477108] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A] <7> [331.477180] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B] <7> [331.477243] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C] <7> [331.477325] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [331.477489] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [331.477563] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [331.477673] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [331.478801] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A] <7> [331.478949] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [331.480919] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power on <7> [331.481021] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining) <7> [331.949888] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [332.001013] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [332.001422] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power on <7> [332.001846] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [332.037506] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [332.037902] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long <7> [332.038297] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [332.038740] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A] <7> [332.141738] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [332.141876] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [332.141996] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [332.213860] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [332.214250] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on <7> [332.214575] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [332.216751] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80 <7> [332.218320] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [332.219128] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [332.220229] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [332.221654] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [332.222752] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Clock recovery OK <7> [332.223077] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [332.224465] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [332.224805] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [332.225593] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [332.226086] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [332.226451] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [332.226880] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 192000 <7> [332.243068] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [332.244884] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1] <7> [332.245307] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A] <7> [334.765696] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD off <7> [334.766234] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [335.359674] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [335.360041] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [335.360273] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [335.400135] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

4.30 seconds

Hostname

shard-lnl-2

Igt-Version

IGT-Version: 2.3-gc623172fd (x86_64) (Linux: 7.0.0-rc3-lgci-xe-xe-4699-215a6363df58623db-debug+ x86_64)

Out

Using IGT_SRANDOM=1773285122 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (4.301s)

Err

Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-eDP1
(kms_flip:6378) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:6378) CRITICAL: Failed assertion: end - start < 500
(kms_flip:6378) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:6378) DEBUG: Vblank took 56us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.352203
last_received_ts = 333.351654
last_seq = 3494
current_ts = 333.368866
current_received_ts = 333.368195
current_seq = 3495
count = 64
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.368866
last_received_ts = 333.368195
last_seq = 3495
current_ts = 333.385529
current_received_ts = 333.384949
current_seq = 3496
count = 65
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 89us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.385529
last_received_ts = 333.384949
last_seq = 3496
current_ts = 333.402191
current_received_ts = 333.401642
current_seq = 3497
count = 66
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 54us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.402191
last_received_ts = 333.401642
last_seq = 3497
current_ts = 333.418854
current_received_ts = 333.418274
current_seq = 3498
count = 67
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 56us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.418854
last_received_ts = 333.418274
last_seq = 3498
current_ts = 333.435516
current_received_ts = 333.434845
current_seq = 3499
count = 68
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.435516
last_received_ts = 333.434845
last_seq = 3499
current_ts = 333.452179
current_received_ts = 333.451599
current_seq = 3500
count = 69
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.452179
last_received_ts = 333.451599
last_seq = 3500
current_ts = 333.468842
current_received_ts = 333.468262
current_seq = 3501
count = 70
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.468842
last_received_ts = 333.468262
last_seq = 3501
current_ts = 333.485504
current_received_ts = 333.484924
current_seq = 3502
count = 71
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.485504
last_received_ts = 333.484924
last_seq = 3502
current_ts = 333.502167
current_received_ts = 333.501617
current_seq = 3503
count = 72
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.502167
last_received_ts = 333.501617
last_seq = 3503
current_ts = 333.518829
current_received_ts = 333.518250
current_seq = 3504
count = 73
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 40us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.518829
last_received_ts = 333.518250
last_seq = 3504
current_ts = 333.535522
current_received_ts = 333.534912
current_seq = 3505
count = 74
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 57us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.535522
last_received_ts = 333.534912
last_seq = 3505
current_ts = 333.552185
current_received_ts = 333.551605
current_seq = 3506
count = 75
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 54us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.552185
last_received_ts = 333.551605
last_seq = 3506
current_ts = 333.568848
current_received_ts = 333.568237
current_seq = 3507
count = 76
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.568848
last_received_ts = 333.568237
last_seq = 3507
current_ts = 333.585510
current_received_ts = 333.584930
current_seq = 3508
count = 77
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.585510
last_received_ts = 333.584930
last_seq = 3508
current_ts = 333.602173
current_received_ts = 333.601593
current_seq = 3509
count = 78
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.602173
last_received_ts = 333.601593
last_seq = 3509
current_ts = 333.618835
current_received_ts = 333.618164
current_seq = 3510
count = 79
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 56us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.618835
last_received_ts = 333.618164
last_seq = 3510
current_ts = 333.635498
current_received_ts = 333.634796
current_seq = 3511
count = 80
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 54us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.635498
last_received_ts = 333.634796
last_seq = 3511
current_ts = 333.652161
current_received_ts = 333.651581
current_seq = 3512
count = 81
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 54us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.652161
last_received_ts = 333.651581
last_seq = 3512
current_ts = 333.668823
current_received_ts = 333.668243
current_seq = 3513
count = 82
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 40us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.668823
last_received_ts = 333.668243
last_seq = 3513
current_ts = 333.685486
current_received_ts = 333.684845
current_seq = 3514
count = 83
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.685486
last_received_ts = 333.684845
last_seq = 3514
current_ts = 333.702148
current_received_ts = 333.701569
current_seq = 3515
count = 84
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.702148
last_received_ts = 333.701569
last_seq = 3515
current_ts = 333.718811
current_received_ts = 333.718231
current_seq = 3516
count = 85
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.718811
last_received_ts = 333.718231
last_seq = 3516
current_ts = 333.735474
current_received_ts = 333.734802
current_seq = 3517
count = 86
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.735474
last_received_ts = 333.734802
last_seq = 3517
current_ts = 333.752136
current_received_ts = 333.751556
current_seq = 3518
count = 87
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 53us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.752136
last_received_ts = 333.751556
last_seq = 3518
current_ts = 333.768829
current_received_ts = 333.768219
current_seq = 3519
count = 88
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 38us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.768829
last_received_ts = 333.768219
last_seq = 3519
current_ts = 333.785461
current_received_ts = 333.784790
current_seq = 3520
count = 89
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 39us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.785461
last_received_ts = 333.784790
last_seq = 3520
current_ts = 333.802155
current_received_ts = 333.801544
current_seq = 3521
count = 90
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 39us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.802155
last_received_ts = 333.801544
last_seq = 3521
current_ts = 333.818817
current_received_ts = 333.818207
current_seq = 3522
count = 91
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 82us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.818817
last_received_ts = 333.818207
last_seq = 3522
current_ts = 333.835480
current_received_ts = 333.834808
current_seq = 3523
count = 92
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 44us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.835480
last_received_ts = 333.834808
last_seq = 3523
current_ts = 333.852142
current_received_ts = 333.851562
current_seq = 3524
count = 93
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 69us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.852142
last_received_ts = 333.851562
last_seq = 3524
current_ts = 333.868805
current_received_ts = 333.868134
current_seq = 3525
count = 94
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 64us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.868805
last_received_ts = 333.868134
last_seq = 3525
current_ts = 333.885468
current_received_ts = 333.884888
current_seq = 3526
count = 95
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.885468
last_received_ts = 333.884888
last_seq = 3526
current_ts = 333.902130
current_received_ts = 333.901489
current_seq = 3527
count = 96
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.902130
last_received_ts = 333.901489
last_seq = 3527
current_ts = 333.918793
current_received_ts = 333.918060
current_seq = 3528
count = 97
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.918793
last_received_ts = 333.918060
last_seq = 3528
current_ts = 333.935455
current_received_ts = 333.934784
current_seq = 3529
count = 98
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.935455
last_received_ts = 333.934784
last_seq = 3529
current_ts = 333.952118
current_received_ts = 333.951508
current_seq = 3530
count = 99
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.952118
last_received_ts = 333.951508
last_seq = 3530
current_ts = 333.968781
current_received_ts = 333.968140
current_seq = 3531
count = 100
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 42us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.968781
last_received_ts = 333.968140
last_seq = 3531
current_ts = 333.985443
current_received_ts = 333.984894
current_seq = 3532
count = 101
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 333.985443
last_received_ts = 333.984894
last_seq = 3532
current_ts = 334.002106
current_received_ts = 334.001495
current_seq = 3533
count = 102
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.002106
last_received_ts = 334.001495
last_seq = 3533
current_ts = 334.018768
current_received_ts = 334.018188
current_seq = 3534
count = 103
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.018768
last_received_ts = 334.018188
last_seq = 3534
current_ts = 334.035461
current_received_ts = 334.034790
current_seq = 3535
count = 104
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.035461
last_received_ts = 334.034790
last_seq = 3535
current_ts = 334.052094
current_received_ts = 334.051544
current_seq = 3536
count = 105
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 56us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.052094
last_received_ts = 334.051544
last_seq = 3536
current_ts = 334.068787
current_received_ts = 334.068054
current_seq = 3537
count = 106
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 55us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.068787
last_received_ts = 334.068054
last_seq = 3537
current_ts = 334.085449
current_received_ts = 334.084808
current_seq = 3538
count = 107
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.085449
last_received_ts = 334.084808
last_seq = 3538
current_ts = 334.102112
current_received_ts = 334.101471
current_seq = 3539
count = 108
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.102112
last_received_ts = 334.101471
last_seq = 3539
current_ts = 334.118774
current_received_ts = 334.118073
current_seq = 3540
count = 109
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.118774
last_received_ts = 334.118073
last_seq = 3540
current_ts = 334.135437
current_received_ts = 334.134766
current_seq = 3541
count = 110
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.135437
last_received_ts = 334.134766
last_seq = 3541
current_ts = 334.152100
current_received_ts = 334.151520
current_seq = 3542
count = 111
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.152100
last_received_ts = 334.151520
last_seq = 3542
current_ts = 334.168762
current_received_ts = 334.168091
current_seq = 3543
count = 112
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.168762
last_received_ts = 334.168091
last_seq = 3543
current_ts = 334.185425
current_received_ts = 334.184784
current_seq = 3544
count = 113
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 57us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.185425
last_received_ts = 334.184784
last_seq = 3544
current_ts = 334.202087
current_received_ts = 334.201538
current_seq = 3545
count = 114
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 54us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.202087
last_received_ts = 334.201538
last_seq = 3545
current_ts = 334.218750
current_received_ts = 334.218109
current_seq = 3546
count = 115
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.218750
last_received_ts = 334.218109
last_seq = 3546
current_ts = 334.235413
current_received_ts = 334.234772
current_seq = 3547
count = 116
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.235413
last_received_ts = 334.234772
last_seq = 3547
current_ts = 334.252075
current_received_ts = 334.251465
current_seq = 3548
count = 117
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 41us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.252075
last_received_ts = 334.251465
last_seq = 3548
current_ts = 334.268738
current_received_ts = 334.268158
current_seq = 3549
count = 118
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.268738
last_received_ts = 334.268158
last_seq = 3549
current_ts = 334.285431
current_received_ts = 334.284729
current_seq = 3550
count = 119
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.285431
last_received_ts = 334.284729
last_seq = 3550
current_ts = 334.302063
current_received_ts = 334.301483
current_seq = 3551
count = 120
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.302063
last_received_ts = 334.301483
last_seq = 3551
current_ts = 334.318756
current_received_ts = 334.318115
current_seq = 3552
count = 121
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.318756
last_received_ts = 334.318115
last_seq = 3552
current_ts = 334.335419
current_received_ts = 334.334656
current_seq = 3553
count = 122
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.335419
last_received_ts = 334.334656
last_seq = 3553
current_ts = 334.352081
current_received_ts = 334.351501
current_seq = 3554
count = 123
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 61us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.352081
last_received_ts = 334.351501
last_seq = 3554
current_ts = 334.368744
current_received_ts = 334.368042
current_seq = 3555
count = 124
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 61us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.368744
last_received_ts = 334.368042
last_seq = 3555
current_ts = 334.385406
current_received_ts = 334.384857
current_seq = 3556
count = 125
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.385406
last_received_ts = 334.384857
last_seq = 3556
current_ts = 334.402069
current_received_ts = 334.401489
current_seq = 3557
count = 126
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.402069
last_received_ts = 334.401489
last_seq = 3557
current_ts = 334.418732
current_received_ts = 334.417999
current_seq = 3558
count = 127
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.418732
last_received_ts = 334.417999
last_seq = 3558
current_ts = 334.435394
current_received_ts = 334.434753
current_seq = 3559
count = 128
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.435394
last_received_ts = 334.434753
last_seq = 3559
current_ts = 334.452057
current_received_ts = 334.451477
current_seq = 3560
count = 129
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 54us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.452057
last_received_ts = 334.451477
last_seq = 3560
current_ts = 334.468719
current_received_ts = 334.468079
current_seq = 3561
count = 130
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 39us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.468719
last_received_ts = 334.468079
last_seq = 3561
current_ts = 334.485382
current_received_ts = 334.484772
current_seq = 3562
count = 131
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 37us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.485382
last_received_ts = 334.484772
last_seq = 3562
current_ts = 334.502045
current_received_ts = 334.501465
current_seq = 3563
count = 132
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 73us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.502045
last_received_ts = 334.501465
last_seq = 3563
current_ts = 334.518707
current_received_ts = 334.518127
current_seq = 3564
count = 133
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.518707
last_received_ts = 334.518127
last_seq = 3564
current_ts = 334.535370
current_received_ts = 334.534729
current_seq = 3565
count = 134
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.535370
last_received_ts = 334.534729
last_seq = 3565
current_ts = 334.552063
current_received_ts = 334.551483
current_seq = 3566
count = 135
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.552063
last_received_ts = 334.551483
last_seq = 3566
current_ts = 334.568695
current_received_ts = 334.568085
current_seq = 3567
count = 136
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.568695
last_received_ts = 334.568085
last_seq = 3567
current_ts = 334.585388
current_received_ts = 334.584717
current_seq = 3568
count = 137
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.585388
last_received_ts = 334.584717
last_seq = 3568
current_ts = 334.602051
current_received_ts = 334.601471
current_seq = 3569
count = 138
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.602051
last_received_ts = 334.601471
last_seq = 3569
current_ts = 334.618713
current_received_ts = 334.618073
current_seq = 3570
count = 139
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.618713
last_received_ts = 334.618073
last_seq = 3570
current_ts = 334.635376
current_received_ts = 334.634796
current_seq = 3571
count = 140
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.635376
last_received_ts = 334.634796
last_seq = 3571
current_ts = 334.652039
current_received_ts = 334.651428
current_seq = 3572
count = 141
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 143us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.652039
last_received_ts = 334.651428
last_seq = 3572
current_ts = 334.668701
current_received_ts = 334.668060
current_seq = 3573
count = 142
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 67us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.668701
last_received_ts = 334.668060
last_seq = 3573
current_ts = 334.685364
current_received_ts = 334.684631
current_seq = 3574
count = 143
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 63us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.685364
last_received_ts = 334.684631
last_seq = 3574
current_ts = 334.702026
current_received_ts = 334.701385
current_seq = 3575
count = 144
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.702026
last_received_ts = 334.701385
last_seq = 3575
current_ts = 334.718689
current_received_ts = 334.718079
current_seq = 3576
count = 145
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.718689
last_received_ts = 334.718079
last_seq = 3576
current_ts = 334.735352
current_received_ts = 334.734619
current_seq = 3577
count = 146
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.735352
last_received_ts = 334.734619
last_seq = 3577
current_ts = 334.752014
current_received_ts = 334.751465
current_seq = 3578
count = 147
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 44us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.752014
last_received_ts = 334.751465
last_seq = 3578
current_ts = 334.768677
current_received_ts = 334.768036
current_seq = 3579
count = 148
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 43us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.768677
last_received_ts = 334.768036
last_seq = 3579
current_ts = 334.785339
current_received_ts = 334.784821
current_seq = 3580
count = 149
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.785339
last_received_ts = 334.784821
last_seq = 3580
current_ts = 334.802002
current_received_ts = 334.801392
current_seq = 3581
count = 150
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 54us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.802002
last_received_ts = 334.801392
last_seq = 3581
current_ts = 334.818695
current_received_ts = 334.818054
current_seq = 3582
count = 151
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 68us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.818695
last_received_ts = 334.818054
last_seq = 3582
current_ts = 334.835358
current_received_ts = 334.834595
current_seq = 3583
count = 152
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 64us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.835358
last_received_ts = 334.834595
last_seq = 3583
current_ts = 334.852020
current_received_ts = 334.851349
current_seq = 3584
count = 153
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 49us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.852020
last_received_ts = 334.851349
last_seq = 3584
current_ts = 334.868683
current_received_ts = 334.868042
current_seq = 3585
count = 154
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 49us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.868683
last_received_ts = 334.868042
last_seq = 3585
current_ts = 334.885345
current_received_ts = 334.884766
current_seq = 3586
count = 155
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 65us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.885345
last_received_ts = 334.884766
last_seq = 3586
current_ts = 334.902008
current_received_ts = 334.901367
current_seq = 3587
count = 156
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 84us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.902008
last_received_ts = 334.901367
last_seq = 3587
current_ts = 334.918671
current_received_ts = 334.918121
current_seq = 3588
count = 157
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 64us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.918671
last_received_ts = 334.918121
last_seq = 3588
current_ts = 334.935333
current_received_ts = 334.934692
current_seq = 3589
count = 158
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.935333
last_received_ts = 334.934692
last_seq = 3589
current_ts = 334.951996
current_received_ts = 334.951447
current_seq = 3590
count = 159
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 63us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.951996
last_received_ts = 334.951447
last_seq = 3590
current_ts = 334.968658
current_received_ts = 334.968109
current_seq = 3591
count = 160
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 63us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.968658
last_received_ts = 334.968109
last_seq = 3591
current_ts = 334.985321
current_received_ts = 334.984741
current_seq = 3592
count = 161
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 63us
(kms_flip:6378) DEBUG: name = flip
last_ts = 334.985321
last_received_ts = 334.984741
last_seq = 3592
current_ts = 335.001984
current_received_ts = 335.001343
current_seq = 3593
count = 162
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 43us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.001984
last_received_ts = 335.001343
last_seq = 3593
current_ts = 335.018646
current_received_ts = 335.018066
current_seq = 3594
count = 163
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.018646
last_received_ts = 335.018066
last_seq = 3594
current_ts = 335.035309
current_received_ts = 335.034729
current_seq = 3595
count = 164
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.035309
last_received_ts = 335.034729
last_seq = 3595
current_ts = 335.052002
current_received_ts = 335.051422
current_seq = 3596
count = 165
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 58us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.052002
last_received_ts = 335.051422
last_seq = 3596
current_ts = 335.068634
current_received_ts = 335.068024
current_seq = 3597
count = 166
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 43us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.068634
last_received_ts = 335.068024
last_seq = 3597
current_ts = 335.085297
current_received_ts = 335.084656
current_seq = 3598
count = 167
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 44us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.085297
last_received_ts = 335.084656
last_seq = 3598
current_ts = 335.101990
current_received_ts = 335.101318
current_seq = 3599
count = 168
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 43us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.101990
last_received_ts = 335.101318
last_seq = 3599
current_ts = 335.118652
current_received_ts = 335.118011
current_seq = 3600
count = 169
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 41us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.118652
last_received_ts = 335.118011
last_seq = 3600
current_ts = 335.135315
current_received_ts = 335.134552
current_seq = 3601
count = 170
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 61us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.135315
last_received_ts = 335.134552
last_seq = 3601
current_ts = 335.151978
current_received_ts = 335.151306
current_seq = 3602
count = 171
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 41us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.151978
last_received_ts = 335.151306
last_seq = 3602
current_ts = 335.168640
current_received_ts = 335.167999
current_seq = 3603
count = 172
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 64us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.168640
last_received_ts = 335.167999
last_seq = 3603
current_ts = 335.185303
current_received_ts = 335.184570
current_seq = 3604
count = 173
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.185303
last_received_ts = 335.184570
last_seq = 3604
current_ts = 335.201965
current_received_ts = 335.201385
current_seq = 3605
count = 174
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 60us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.201965
last_received_ts = 335.201385
last_seq = 3605
current_ts = 335.218628
current_received_ts = 335.218109
current_seq = 3606
count = 175
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 59us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.218628
last_received_ts = 335.218109
last_seq = 3606
current_ts = 335.235291
current_received_ts = 335.234650
current_seq = 3607
count = 176
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 62us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.235291
last_received_ts = 335.234650
last_seq = 3607
current_ts = 335.251953
current_received_ts = 335.251404
current_seq = 3608
count = 177
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 62us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.251953
last_received_ts = 335.251404
last_seq = 3608
current_ts = 335.268616
current_received_ts = 335.268005
current_seq = 3609
count = 178
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 47us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.268616
last_received_ts = 335.268005
last_seq = 3609
current_ts = 335.285278
current_received_ts = 335.284668
current_seq = 3610
count = 179
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 62us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.285278
last_received_ts = 335.284668
last_seq = 3610
current_ts = 335.301941
current_received_ts = 335.301331
current_seq = 3611
count = 180
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 63us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.301941
last_received_ts = 335.301331
last_seq = 3611
current_ts = 335.318604
current_received_ts = 335.317963
current_seq = 3612
count = 181
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 70us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.318604
last_received_ts = 335.317963
last_seq = 3612
current_ts = 335.335266
current_received_ts = 335.334534
current_seq = 3613
count = 182
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 65us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.335266
last_received_ts = 335.334534
last_seq = 3613
current_ts = 335.351959
current_received_ts = 335.351288
current_seq = 3614
count = 183
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 63us
(kms_flip:6378) DEBUG: name = flip
last_ts = 335.351959
last_received_ts = 335.351288
last_seq = 3614
current_ts = 335.368622
current_received_ts = 335.367950
current_seq = 3615
count = 184
seq_step = 1
(kms_flip:6378) DEBUG: Vblank took 880us
(kms_flip:6378) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:6378) CRITICAL: Failed assertion: end - start < 500
(kms_flip:6378) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:6378) igt_core-INFO: Stack trace:
(kms_flip:6378) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:6378) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:6378) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:6378) igt_core-INFO:   #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
(kms_flip:6378) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:6378) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:6378) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:6378) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (4.301s)

Dmesg

<6> [331.080896] Console: switching to colour dummy device 80x25

<6> [331.081227] [IGT] kms_flip: executing

<7> [331.087055] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1]

<7> [331.087065] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1]

<7> [331.087214] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected

<7> [331.087426] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2]

<7> [331.087429] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2]

<7> [331.087541] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected

<7> [331.087759] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3]

<7> [331.087762] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3]

<7> [331.087902] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected

<7> [331.088171] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1]

<7> [331.088173] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:392:eDP-1]

<7> [331.088620] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00

<7> [331.089026] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000

<7> [331.089134] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [331.089238] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [331.089358] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz

<5> [331.089363] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [331.089364] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [331.089365] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] DisplayID extension version 0x13, primary use 0x00

<7> [331.089368] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc.

<5> [331.089370] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [331.089371] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD monitor

<5> [331.089374] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [331.089375] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:392:eDP-1] ELD size 20, SAD count 0

<5> [331.089378] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [331.089389] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] VRR capable: yes

<7> [331.089482] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps

<7> [331.089572] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:392:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no

<5> [331.089888] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [331.089890] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [331.089892] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [331.089954] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:392:eDP-1] probed modes:

<7> [331.089957] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [331.089961] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

<7> [331.089973] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1]

<7> [331.089976] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:401:DP-1]

<7> [331.090136] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:401:DP-1] disconnected

<7> [331.090146] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2]

<7> [331.090148] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:413:DP-2]

<7> [331.090283] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:413:DP-2] disconnected

<7> [331.090293] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3]

<7> [331.090295] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:421:DP-3]

<7> [331.090422] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:421:DP-3] disconnected

<6> [331.094094] [IGT] kms_flip: starting subtest flip-vs-expired-vblank-interruptible

<6> [331.095457] [IGT] kms_flip: starting dynamic subtest A-eDP1

<7> [331.096167] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]

<7> [331.096688] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:431]

<7> [331.152258] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

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

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

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

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

<7> [331.152792] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)

<7> [331.152903] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)

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

<7> [331.153101] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)

<7> [331.153187] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)

<7> [331.153275] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)

<7> [331.153364] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)

<7> [331.153463] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)

<7> [331.153565] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)

<7> [331.153666] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)

<7> [331.153768] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)

<7> [331.153869] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)

<7> [331.153969] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)

<7> [331.154060] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)

<7> [331.154144] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)

<7> [331.154231] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)

<7> [331.154315] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)

<7> [331.154399] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)

<7> [331.154482] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)

<7> [331.154564] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)

<7> [331.154645] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)

<7> [331.154742] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)

<7> [331.154837] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)

<7> [331.154932] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)

<7> [331.155029] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)

<7> [331.155112] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)

<7> [331.155184] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)

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

<7> [331.155355] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)

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

<7> [331.155538] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)

<7> [331.155610] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)

<7> [331.155681] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)

<7> [331.155773] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)

<7> [331.155866] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset

<7> [331.155959] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:150:pipe A] releasing DPLL 0

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

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

<7> [331.156236] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

<7> [331.156311] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0

<7> [331.156375] xe 0000:00:02.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> [331.156437] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [331.156499] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [331.156559] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [331.156629] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 0 num active planes 0

<7> [331.156720] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400

<7> [331.156821] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400

<7> [331.156920] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [331.157016] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [331.157114] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0

<7> [331.157212] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 173855 kHz -> 0 kHz

<7> [331.157320] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz

<7> [331.157412] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing

<7> [331.157490] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz

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

<7> [331.157664] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: no [modeset]

<7> [331.157762] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [NOFB], visible: no

<7> [331.157864] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no

<7> [331.157966] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no

<7> [331.158059] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no

<7> [331.158146] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no

<7> [331.158227] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no

<7> [331.158338] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off

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

<7> [331.158575] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2

<7> [331.168281] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM

<7> [331.168392] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]

<7> [331.373888] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 0

<7> [331.374597] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A

<7> [331.385228] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power off

<7> [331.385595] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power off time

<7> [331.385998] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060

<7> [331.437891] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000

<7> [331.438313] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - short

<7> [331.447030] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [331.447438] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:150:pipe A]

<7> [331.447490] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:391:DDI A/PHY A]

<7> [331.448999] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0

<7> [331.449479] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A

<7> [331.450009] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A]

<7> [331.450380] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1]

<7> [331.450729] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A]

<7> [331.451099] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B]

<7> [331.451423] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C]

<7> [331.451736] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2]

<7> [331.452035] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A]

<7> [331.452333] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B]

<7> [331.452627] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C]

<7> [331.452955] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3]

<7> [331.453247] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A]

<7> [331.453535] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B]

<7> [331.453909] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C]

<7> [331.454198] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1]

<7> [331.454565] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [331.454881] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)

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

<7> [331.455741] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A

<7> [331.456119] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)

<7> [331.456568] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]

<7> [331.456952] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

<7> [331.457341] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [331.457657] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384

<7> [331.458595] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe B]

<7> [331.459023] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:388:pipe C]

<7> [331.459331] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

<7> [331.459406] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:392:eDP-1]

<7> [331.459586] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:392:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)

<7> [331.460006] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:391:DDI A/PHY A][CRTC:150:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000

<7> [331.460366] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000

<7> [331.460683] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0

<7> [331.461029] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:391:DDI A/PHY A] [CRTC:150:pipe A]

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

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

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

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

<7> [331.462484] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)

<7> [331.462734] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)

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

<7> [331.463168] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)

<7> [331.463374] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)

<7> [331.463576] xe 0000:00:02.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 2880)

<7> [331.463794] xe 0000:00:02.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 3040)

<7> [331.463997] xe 0000:00:02.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 2928)

<7> [331.464190] xe 0000:00:02.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 2960)

<7> [331.464366] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)

<7> [331.464563] xe 0000:00:02.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 1800)

<7> [331.464763] xe 0000:00:02.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 1803)

<7> [331.464933] xe 0000:00:02.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 1809)

<7> [331.465097] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)

<7> [331.465254] xe 0000:00:02.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 1906)

<7> [331.465399] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)

<7> [331.465542] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)

<7> [331.465678] xe 0000:00:02.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 2880)

<7> [331.465841] xe 0000:00:02.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 3040)

<7> [331.465982] xe 0000:00:02.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 2928)

<7> [331.466120] xe 0000:00:02.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 2960)

<7> [331.466251] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)

<7> [331.466374] xe 0000:00:02.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 1800)

<7> [331.466495] xe 0000:00:02.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 1803)

<7> [331.466615] xe 0000:00:02.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 1809)

<7> [331.466788] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)

<7> [331.466906] xe 0000:00:02.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 1906)

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

<7> [331.467137] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)

<7> [331.467251] xe 0000:00:02.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> [331.467360] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30)

<7> [331.467466] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)

<7> [331.467568] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)

<7> [331.467667] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 0, found 432000)

<7> [331.467778] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset

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

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

<7> [331.468153] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:34:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

<7> [331.468248] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:144:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45

<7> [331.468323] xe 0000:00:02.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> [331.468395] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0

<7> [331.468463] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197

<7> [331.468530] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:34:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198

<7> [331.468618] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:150:pipe A] data rate 1390840 num active planes 1

<7> [331.468720] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400

<7> [331.468822] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400

<7> [331.468921] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [331.469020] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [331.469111] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461

<7> [331.469203] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:150:pipe A] min cdclk: 0 kHz -> 173855 kHz

<7> [331.469312] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz

<7> [331.469411] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing

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

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

<7> [331.469717] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:150:pipe A] allocated DPLL 0

<7> [331.469815] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:150:pipe A] reserving DPLL 0

<7> [331.469917] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:150:pipe A] enable: yes [modeset]

<7> [331.470020] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB

<7> [331.470103] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0

<7> [331.470198] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>

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

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

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

<7> [331.470522] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64

<7> [331.470600] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0

<7> [331.470687] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

<7> [331.470796] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled

<7> [331.470890] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled

<7> [331.470984] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0

<7> [331.471066] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4

<7> [331.471146] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14

<7> [331.471220] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB

<7> [331.471295] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB

<7> [331.471387] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0

<7> [331.471478] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range

<7> [331.471564] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined

<7> [331.471637] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1

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

<7> [331.471799] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97

<7> [331.471895] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906

<7> [331.471987] xe 0000:00:02.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> [331.472068] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [331.472146] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [331.472224] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [331.472302] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

<7> [331.472380] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [331.472457] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855

<7> [331.472530] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0

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

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

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

<7> [331.472854] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no

<7> [331.472948] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,

<7> [331.473037] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.

<7> [331.473106] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:

<7> [331.473176] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21

<7> [331.473260] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1

<7> [331.473348] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0

<7> [331.473437] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0

<7> [331.473515] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1

<7> [331.473588] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23

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

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

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

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

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

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

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

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

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

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

<7> [331.474390] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

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

<7> [331.474514] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long

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

<7> [331.474613] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10

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

<7> [331.474722] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:34:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

<7> [331.474725] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]

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

<7> [331.474902] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0

<7> [331.474991] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:64:plane 2A] fb: [NOFB], visible: no

<7> [331.475066] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:94:plane 3A] fb: [NOFB], visible: no

<7> [331.475154] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:124:plane 4A] fb: [NOFB], visible: no

<7> [331.475244] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:134:plane 5A] fb: [NOFB], visible: no

<7> [331.475333] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:144:cursor A] fb: [NOFB], visible: no

<7> [331.475753] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A

<7> [331.475935] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)

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

<7> [331.476144] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [331.476235] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480

<7> [331.476317] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:391:DDI A/PHY A]

<7> [331.476385] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:400:DDI TC1/PHY TC1]

<7> [331.476452] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST A]

<7> [331.476521] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST B]

<7> [331.476596] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST C]

<7> [331.476671] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:412:DDI TC2/PHY TC2]

<7> [331.476768] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST A]

<7> [331.476854] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST B]

<7> [331.476939] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST C]

<7> [331.477024] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:420:DDI TC3/PHY TC3]

<7> [331.477108] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST A]

<7> [331.477180] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST B]

<7> [331.477243] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST C]

<7> [331.477325] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf

<7> [331.477489] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)

<7> [331.477563] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)

<7> [331.477673] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A

<7> [331.478801] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:150:pipe A]

<7> [331.478949] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0

<7> [331.480919] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turn panel power on

<7> [331.481021] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining)

<7> [331.949888] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060

<7> [332.001013] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [332.001422] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 wait for panel power on

<7> [332.001846] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063

<7> [332.037506] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

<7> [332.037902] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:391:DDI A/PHY A] - long

<7> [332.038297] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20

<7> [332.038740] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:391:DDI A/PHY A]

<7> [332.141738] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [332.141876] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [332.141996] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [332.213860] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [332.214250] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD on

<7> [332.214575] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b

<7> [332.216751] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80

<7> [332.218320] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Reloading eDP link rates

<7> [332.219128] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05

<7> [332.220229] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0

<7> [332.221654] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS1

<7> [332.222752] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Clock recovery OK

<7> [332.223077] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Using DP training pattern TPS4

<7> [332.224465] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful

<7> [332.224805] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:392:eDP-1][ENCODER:391:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4

<7> [332.225593] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A

<7> [332.226086] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]

<7> [332.226451] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A

<7> [332.226880] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:392:eDP-1] set backlight PWM = 192000

<7> [332.243068] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2

<7> [332.244884] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:392:eDP-1]

<7> [332.245307] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:150:pipe A]

<7> [334.765696] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 turning VDD off

<7> [334.766234] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:391:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067

<7> [335.359674] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off

<7> [335.360041] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6

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

<6> [335.400135] [IGT] kms_flip: finished subtest A-eDP1, FAIL

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