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

Detail	Value
Duration	4.29 seconds
Hostname	shard-lnl-7
Igt-Version	IGT-Version: 2.4-g0f0afe46c (x86_64) (Linux: 7.1.0-rc1-lgci-xe-xe-4949-1db870ffb55b6414a-debug+ x86_64)
Out	Using IGT_SRANDOM=1777490128 for randomisation Opened device: /dev/dri/card1 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:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (4.293s)
Err	Starting subtest: flip-vs-expired-vblank-interruptible Starting dynamic subtest: A-eDP1 (kms_flip:13908) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:13908) CRITICAL: Failed assertion: end - start < 500 (kms_flip:13908) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:13908) DEBUG: Vblank took 89us (kms_flip:13908) DEBUG: name = flip last_ts = 272.496063 last_received_ts = 272.495270 last_seq = 1477 current_ts = 272.512756 current_received_ts = 272.512085 current_seq = 1478 count = 64 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 272.512756 last_received_ts = 272.512085 last_seq = 1478 current_ts = 272.529419 current_received_ts = 272.528717 current_seq = 1479 count = 65 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 96us (kms_flip:13908) DEBUG: name = flip last_ts = 272.529419 last_received_ts = 272.528717 last_seq = 1479 current_ts = 272.546082 current_received_ts = 272.545258 current_seq = 1480 count = 66 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 272.546082 last_received_ts = 272.545258 last_seq = 1480 current_ts = 272.562744 current_received_ts = 272.561951 current_seq = 1481 count = 67 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 99us (kms_flip:13908) DEBUG: name = flip last_ts = 272.562744 last_received_ts = 272.561951 last_seq = 1481 current_ts = 272.579407 current_received_ts = 272.578644 current_seq = 1482 count = 68 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 61us (kms_flip:13908) DEBUG: name = flip last_ts = 272.579407 last_received_ts = 272.578644 last_seq = 1482 current_ts = 272.596069 current_received_ts = 272.595276 current_seq = 1483 count = 69 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 272.596069 last_received_ts = 272.595276 last_seq = 1483 current_ts = 272.612732 current_received_ts = 272.611969 current_seq = 1484 count = 70 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 84us (kms_flip:13908) DEBUG: name = flip last_ts = 272.612732 last_received_ts = 272.611969 last_seq = 1484 current_ts = 272.629425 current_received_ts = 272.628632 current_seq = 1485 count = 71 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 60us (kms_flip:13908) DEBUG: name = flip last_ts = 272.629425 last_received_ts = 272.628632 last_seq = 1485 current_ts = 272.646088 current_received_ts = 272.645264 current_seq = 1486 count = 72 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 272.646088 last_received_ts = 272.645264 last_seq = 1486 current_ts = 272.662750 current_received_ts = 272.661957 current_seq = 1487 count = 73 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 92us (kms_flip:13908) DEBUG: name = flip last_ts = 272.662750 last_received_ts = 272.661957 last_seq = 1487 current_ts = 272.679413 current_received_ts = 272.678711 current_seq = 1488 count = 74 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 272.679413 last_received_ts = 272.678711 last_seq = 1488 current_ts = 272.696075 current_received_ts = 272.695282 current_seq = 1489 count = 75 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 272.696075 last_received_ts = 272.695282 last_seq = 1489 current_ts = 272.712738 current_received_ts = 272.711975 current_seq = 1490 count = 76 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 86us (kms_flip:13908) DEBUG: name = flip last_ts = 272.712738 last_received_ts = 272.711975 last_seq = 1490 current_ts = 272.729431 current_received_ts = 272.728607 current_seq = 1491 count = 77 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 67us (kms_flip:13908) DEBUG: name = flip last_ts = 272.729431 last_received_ts = 272.728607 last_seq = 1491 current_ts = 272.746094 current_received_ts = 272.745270 current_seq = 1492 count = 78 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 272.746094 last_received_ts = 272.745270 last_seq = 1492 current_ts = 272.762756 current_received_ts = 272.762054 current_seq = 1493 count = 79 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 272.762756 last_received_ts = 272.762054 last_seq = 1493 current_ts = 272.779419 current_received_ts = 272.778625 current_seq = 1494 count = 80 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 272.779419 last_received_ts = 272.778625 last_seq = 1494 current_ts = 272.796082 current_received_ts = 272.795380 current_seq = 1495 count = 81 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 272.796082 last_received_ts = 272.795380 last_seq = 1495 current_ts = 272.812744 current_received_ts = 272.812042 current_seq = 1496 count = 82 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 272.812744 last_received_ts = 272.812042 last_seq = 1496 current_ts = 272.829407 current_received_ts = 272.828705 current_seq = 1497 count = 83 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 272.829407 last_received_ts = 272.828705 last_seq = 1497 current_ts = 272.846100 current_received_ts = 272.845398 current_seq = 1498 count = 84 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 272.846100 last_received_ts = 272.845398 last_seq = 1498 current_ts = 272.862762 current_received_ts = 272.862061 current_seq = 1499 count = 85 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 272.862762 last_received_ts = 272.862061 last_seq = 1499 current_ts = 272.879425 current_received_ts = 272.878784 current_seq = 1500 count = 86 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 95us (kms_flip:13908) DEBUG: name = flip last_ts = 272.879425 last_received_ts = 272.878784 last_seq = 1500 current_ts = 272.896088 current_received_ts = 272.895416 current_seq = 1501 count = 87 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 94us (kms_flip:13908) DEBUG: name = flip last_ts = 272.896088 last_received_ts = 272.895416 last_seq = 1501 current_ts = 272.912750 current_received_ts = 272.912079 current_seq = 1502 count = 88 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 77us (kms_flip:13908) DEBUG: name = flip last_ts = 272.912750 last_received_ts = 272.912079 last_seq = 1502 current_ts = 272.929413 current_received_ts = 272.928741 current_seq = 1503 count = 89 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 67us (kms_flip:13908) DEBUG: name = flip last_ts = 272.929413 last_received_ts = 272.928741 last_seq = 1503 current_ts = 272.946075 current_received_ts = 272.945404 current_seq = 1504 count = 90 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 74us (kms_flip:13908) DEBUG: name = flip last_ts = 272.946075 last_received_ts = 272.945404 last_seq = 1504 current_ts = 272.962769 current_received_ts = 272.962067 current_seq = 1505 count = 91 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 272.962769 last_received_ts = 272.962067 last_seq = 1505 current_ts = 272.979431 current_received_ts = 272.978729 current_seq = 1506 count = 92 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 272.979431 last_received_ts = 272.978729 last_seq = 1506 current_ts = 272.996094 current_received_ts = 272.995392 current_seq = 1507 count = 93 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 67us (kms_flip:13908) DEBUG: name = flip last_ts = 272.996094 last_received_ts = 272.995392 last_seq = 1507 current_ts = 273.012756 current_received_ts = 273.012054 current_seq = 1508 count = 94 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 63us (kms_flip:13908) DEBUG: name = flip last_ts = 273.012756 last_received_ts = 273.012054 last_seq = 1508 current_ts = 273.029419 current_received_ts = 273.028717 current_seq = 1509 count = 95 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.029419 last_received_ts = 273.028717 last_seq = 1509 current_ts = 273.046082 current_received_ts = 273.045380 current_seq = 1510 count = 96 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.046082 last_received_ts = 273.045380 last_seq = 1510 current_ts = 273.062744 current_received_ts = 273.062073 current_seq = 1511 count = 97 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.062744 last_received_ts = 273.062073 last_seq = 1511 current_ts = 273.079437 current_received_ts = 273.078644 current_seq = 1512 count = 98 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.079437 last_received_ts = 273.078644 last_seq = 1512 current_ts = 273.096100 current_received_ts = 273.095398 current_seq = 1513 count = 99 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 273.096100 last_received_ts = 273.095398 last_seq = 1513 current_ts = 273.112762 current_received_ts = 273.112091 current_seq = 1514 count = 100 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.112762 last_received_ts = 273.112091 last_seq = 1514 current_ts = 273.129425 current_received_ts = 273.128723 current_seq = 1515 count = 101 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.129425 last_received_ts = 273.128723 last_seq = 1515 current_ts = 273.146088 current_received_ts = 273.145416 current_seq = 1516 count = 102 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.146088 last_received_ts = 273.145416 last_seq = 1516 current_ts = 273.162750 current_received_ts = 273.162079 current_seq = 1517 count = 103 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.162750 last_received_ts = 273.162079 last_seq = 1517 current_ts = 273.179413 current_received_ts = 273.178650 current_seq = 1518 count = 104 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.179413 last_received_ts = 273.178650 last_seq = 1518 current_ts = 273.196106 current_received_ts = 273.195374 current_seq = 1519 count = 105 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.196106 last_received_ts = 273.195374 last_seq = 1519 current_ts = 273.212769 current_received_ts = 273.212036 current_seq = 1520 count = 106 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.212769 last_received_ts = 273.212036 last_seq = 1520 current_ts = 273.229431 current_received_ts = 273.228729 current_seq = 1521 count = 107 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.229431 last_received_ts = 273.228729 last_seq = 1521 current_ts = 273.246094 current_received_ts = 273.245392 current_seq = 1522 count = 108 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 63us (kms_flip:13908) DEBUG: name = flip last_ts = 273.246094 last_received_ts = 273.245392 last_seq = 1522 current_ts = 273.262756 current_received_ts = 273.262054 current_seq = 1523 count = 109 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 72us (kms_flip:13908) DEBUG: name = flip last_ts = 273.262756 last_received_ts = 273.262054 last_seq = 1523 current_ts = 273.279419 current_received_ts = 273.278717 current_seq = 1524 count = 110 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 273.279419 last_received_ts = 273.278717 last_seq = 1524 current_ts = 273.296112 current_received_ts = 273.295380 current_seq = 1525 count = 111 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.296112 last_received_ts = 273.295380 last_seq = 1525 current_ts = 273.312775 current_received_ts = 273.312042 current_seq = 1526 count = 112 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 69us (kms_flip:13908) DEBUG: name = flip last_ts = 273.312775 last_received_ts = 273.312042 last_seq = 1526 current_ts = 273.329437 current_received_ts = 273.328674 current_seq = 1527 count = 113 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.329437 last_received_ts = 273.328674 last_seq = 1527 current_ts = 273.346100 current_received_ts = 273.345428 current_seq = 1528 count = 114 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 273.346100 last_received_ts = 273.345428 last_seq = 1528 current_ts = 273.362762 current_received_ts = 273.362061 current_seq = 1529 count = 115 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 96us (kms_flip:13908) DEBUG: name = flip last_ts = 273.362762 last_received_ts = 273.362061 last_seq = 1529 current_ts = 273.379425 current_received_ts = 273.378662 current_seq = 1530 count = 116 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 45us (kms_flip:13908) DEBUG: name = flip last_ts = 273.379425 last_received_ts = 273.378662 last_seq = 1530 current_ts = 273.396088 current_received_ts = 273.395477 current_seq = 1531 count = 117 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 80us (kms_flip:13908) DEBUG: name = flip last_ts = 273.396088 last_received_ts = 273.395477 last_seq = 1531 current_ts = 273.412781 current_received_ts = 273.412079 current_seq = 1532 count = 118 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 108us (kms_flip:13908) DEBUG: name = flip last_ts = 273.412781 last_received_ts = 273.412079 last_seq = 1532 current_ts = 273.429443 current_received_ts = 273.428772 current_seq = 1533 count = 119 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 71us (kms_flip:13908) DEBUG: name = flip last_ts = 273.429443 last_received_ts = 273.428772 last_seq = 1533 current_ts = 273.446106 current_received_ts = 273.445404 current_seq = 1534 count = 120 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 71us (kms_flip:13908) DEBUG: name = flip last_ts = 273.446106 last_received_ts = 273.445404 last_seq = 1534 current_ts = 273.462769 current_received_ts = 273.462097 current_seq = 1535 count = 121 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.462769 last_received_ts = 273.462097 last_seq = 1535 current_ts = 273.479431 current_received_ts = 273.478729 current_seq = 1536 count = 122 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.479431 last_received_ts = 273.478729 last_seq = 1536 current_ts = 273.496094 current_received_ts = 273.495392 current_seq = 1537 count = 123 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.496094 last_received_ts = 273.495392 last_seq = 1537 current_ts = 273.512756 current_received_ts = 273.512115 current_seq = 1538 count = 124 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.512756 last_received_ts = 273.512115 last_seq = 1538 current_ts = 273.529449 current_received_ts = 273.528748 current_seq = 1539 count = 125 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.529449 last_received_ts = 273.528748 last_seq = 1539 current_ts = 273.546112 current_received_ts = 273.545410 current_seq = 1540 count = 126 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.546112 last_received_ts = 273.545410 last_seq = 1540 current_ts = 273.562775 current_received_ts = 273.562073 current_seq = 1541 count = 127 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.562775 last_received_ts = 273.562073 last_seq = 1541 current_ts = 273.579437 current_received_ts = 273.578735 current_seq = 1542 count = 128 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.579437 last_received_ts = 273.578735 last_seq = 1542 current_ts = 273.596100 current_received_ts = 273.595428 current_seq = 1543 count = 129 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 273.596100 last_received_ts = 273.595428 last_seq = 1543 current_ts = 273.612762 current_received_ts = 273.612091 current_seq = 1544 count = 130 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.612762 last_received_ts = 273.612091 last_seq = 1544 current_ts = 273.629425 current_received_ts = 273.628754 current_seq = 1545 count = 131 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 66us (kms_flip:13908) DEBUG: name = flip last_ts = 273.629425 last_received_ts = 273.628754 last_seq = 1545 current_ts = 273.646118 current_received_ts = 273.645416 current_seq = 1546 count = 132 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.646118 last_received_ts = 273.645416 last_seq = 1546 current_ts = 273.662781 current_received_ts = 273.662048 current_seq = 1547 count = 133 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.662781 last_received_ts = 273.662048 last_seq = 1547 current_ts = 273.679443 current_received_ts = 273.678741 current_seq = 1548 count = 134 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.679443 last_received_ts = 273.678741 last_seq = 1548 current_ts = 273.696106 current_received_ts = 273.695404 current_seq = 1549 count = 135 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.696106 last_received_ts = 273.695404 last_seq = 1549 current_ts = 273.712769 current_received_ts = 273.712097 current_seq = 1550 count = 136 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.712769 last_received_ts = 273.712097 last_seq = 1550 current_ts = 273.729431 current_received_ts = 273.728729 current_seq = 1551 count = 137 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.729431 last_received_ts = 273.728729 last_seq = 1551 current_ts = 273.746124 current_received_ts = 273.745422 current_seq = 1552 count = 138 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 70us (kms_flip:13908) DEBUG: name = flip last_ts = 273.746124 last_received_ts = 273.745422 last_seq = 1552 current_ts = 273.762787 current_received_ts = 273.762085 current_seq = 1553 count = 139 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.762787 last_received_ts = 273.762085 last_seq = 1553 current_ts = 273.779449 current_received_ts = 273.778809 current_seq = 1554 count = 140 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.779449 last_received_ts = 273.778809 last_seq = 1554 current_ts = 273.796112 current_received_ts = 273.795410 current_seq = 1555 count = 141 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.796112 last_received_ts = 273.795410 last_seq = 1555 current_ts = 273.812775 current_received_ts = 273.812073 current_seq = 1556 count = 142 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.812775 last_received_ts = 273.812073 last_seq = 1556 current_ts = 273.829437 current_received_ts = 273.828735 current_seq = 1557 count = 143 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 64us (kms_flip:13908) DEBUG: name = flip last_ts = 273.829437 last_received_ts = 273.828735 last_seq = 1557 current_ts = 273.846130 current_received_ts = 273.845428 current_seq = 1558 count = 144 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.846130 last_received_ts = 273.845428 last_seq = 1558 current_ts = 273.862793 current_received_ts = 273.862091 current_seq = 1559 count = 145 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.862793 last_received_ts = 273.862091 last_seq = 1559 current_ts = 273.879456 current_received_ts = 273.878784 current_seq = 1560 count = 146 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 65us (kms_flip:13908) DEBUG: name = flip last_ts = 273.879456 last_received_ts = 273.878784 last_seq = 1560 current_ts = 273.896118 current_received_ts = 273.895447 current_seq = 1561 count = 147 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 81us (kms_flip:13908) DEBUG: name = flip last_ts = 273.896118 last_received_ts = 273.895447 last_seq = 1561 current_ts = 273.912781 current_received_ts = 273.912109 current_seq = 1562 count = 148 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 75us (kms_flip:13908) DEBUG: name = flip last_ts = 273.912781 last_received_ts = 273.912109 last_seq = 1562 current_ts = 273.929443 current_received_ts = 273.928772 current_seq = 1563 count = 149 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 70us (kms_flip:13908) DEBUG: name = flip last_ts = 273.929443 last_received_ts = 273.928772 last_seq = 1563 current_ts = 273.946106 current_received_ts = 273.945374 current_seq = 1564 count = 150 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 67us (kms_flip:13908) DEBUG: name = flip last_ts = 273.946106 last_received_ts = 273.945374 last_seq = 1564 current_ts = 273.962799 current_received_ts = 273.961975 current_seq = 1565 count = 151 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 58us (kms_flip:13908) DEBUG: name = flip last_ts = 273.962799 last_received_ts = 273.961975 last_seq = 1565 current_ts = 273.979462 current_received_ts = 273.978760 current_seq = 1566 count = 152 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 54us (kms_flip:13908) DEBUG: name = flip last_ts = 273.979462 last_received_ts = 273.978760 last_seq = 1566 current_ts = 273.996124 current_received_ts = 273.995422 current_seq = 1567 count = 153 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 56us (kms_flip:13908) DEBUG: name = flip last_ts = 273.996124 last_received_ts = 273.995422 last_seq = 1567 current_ts = 274.012787 current_received_ts = 274.012085 current_seq = 1568 count = 154 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 45us (kms_flip:13908) DEBUG: name = flip last_ts = 274.012787 last_received_ts = 274.012085 last_seq = 1568 current_ts = 274.029449 current_received_ts = 274.028748 current_seq = 1569 count = 155 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 38us (kms_flip:13908) DEBUG: name = flip last_ts = 274.029449 last_received_ts = 274.028748 last_seq = 1569 current_ts = 274.046112 current_received_ts = 274.045410 current_seq = 1570 count = 156 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 38us (kms_flip:13908) DEBUG: name = flip last_ts = 274.046112 last_received_ts = 274.045410 last_seq = 1570 current_ts = 274.062775 current_received_ts = 274.062042 current_seq = 1571 count = 157 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 129us (kms_flip:13908) DEBUG: name = flip last_ts = 274.062775 last_received_ts = 274.062042 last_seq = 1571 current_ts = 274.079468 current_received_ts = 274.078766 current_seq = 1572 count = 158 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 111us (kms_flip:13908) DEBUG: name = flip last_ts = 274.079468 last_received_ts = 274.078766 last_seq = 1572 current_ts = 274.096130 current_received_ts = 274.095428 current_seq = 1573 count = 159 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 99us (kms_flip:13908) DEBUG: name = flip last_ts = 274.096130 last_received_ts = 274.095428 last_seq = 1573 current_ts = 274.112793 current_received_ts = 274.112152 current_seq = 1574 count = 160 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 102us (kms_flip:13908) DEBUG: name = flip last_ts = 274.112793 last_received_ts = 274.112152 last_seq = 1574 current_ts = 274.129456 current_received_ts = 274.128784 current_seq = 1575 count = 161 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 133us (kms_flip:13908) DEBUG: name = flip last_ts = 274.129456 last_received_ts = 274.128784 last_seq = 1575 current_ts = 274.146118 current_received_ts = 274.145447 current_seq = 1576 count = 162 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 122us (kms_flip:13908) DEBUG: name = flip last_ts = 274.146118 last_received_ts = 274.145447 last_seq = 1576 current_ts = 274.162781 current_received_ts = 274.162048 current_seq = 1577 count = 163 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 43us (kms_flip:13908) DEBUG: name = flip last_ts = 274.162781 last_received_ts = 274.162048 last_seq = 1577 current_ts = 274.179443 current_received_ts = 274.178741 current_seq = 1578 count = 164 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 99us (kms_flip:13908) DEBUG: name = flip last_ts = 274.179443 last_received_ts = 274.178741 last_seq = 1578 current_ts = 274.196136 current_received_ts = 274.195435 current_seq = 1579 count = 165 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 39us (kms_flip:13908) DEBUG: name = flip last_ts = 274.196136 last_received_ts = 274.195435 last_seq = 1579 current_ts = 274.212799 current_received_ts = 274.212036 current_seq = 1580 count = 166 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 41us (kms_flip:13908) DEBUG: name = flip last_ts = 274.212799 last_received_ts = 274.212036 last_seq = 1580 current_ts = 274.229462 current_received_ts = 274.228760 current_seq = 1581 count = 167 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 113us (kms_flip:13908) DEBUG: name = flip last_ts = 274.229462 last_received_ts = 274.228760 last_seq = 1581 current_ts = 274.246124 current_received_ts = 274.245422 current_seq = 1582 count = 168 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 97us (kms_flip:13908) DEBUG: name = flip last_ts = 274.246124 last_received_ts = 274.245422 last_seq = 1582 current_ts = 274.262787 current_received_ts = 274.262085 current_seq = 1583 count = 169 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 35us (kms_flip:13908) DEBUG: name = flip last_ts = 274.262787 last_received_ts = 274.262085 last_seq = 1583 current_ts = 274.279480 current_received_ts = 274.278748 current_seq = 1584 count = 170 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 41us (kms_flip:13908) DEBUG: name = flip last_ts = 274.279480 last_received_ts = 274.278748 last_seq = 1584 current_ts = 274.296143 current_received_ts = 274.295441 current_seq = 1585 count = 171 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 40us (kms_flip:13908) DEBUG: name = flip last_ts = 274.296143 last_received_ts = 274.295441 last_seq = 1585 current_ts = 274.312805 current_received_ts = 274.312134 current_seq = 1586 count = 172 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 102us (kms_flip:13908) DEBUG: name = flip last_ts = 274.312805 last_received_ts = 274.312134 last_seq = 1586 current_ts = 274.329468 current_received_ts = 274.328796 current_seq = 1587 count = 173 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 88us (kms_flip:13908) DEBUG: name = flip last_ts = 274.329468 last_received_ts = 274.328796 last_seq = 1587 current_ts = 274.346130 current_received_ts = 274.345459 current_seq = 1588 count = 174 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 74us (kms_flip:13908) DEBUG: name = flip last_ts = 274.346130 last_received_ts = 274.345459 last_seq = 1588 current_ts = 274.362793 current_received_ts = 274.362091 current_seq = 1589 count = 175 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 73us (kms_flip:13908) DEBUG: name = flip last_ts = 274.362793 last_received_ts = 274.362091 last_seq = 1589 current_ts = 274.379456 current_received_ts = 274.378784 current_seq = 1590 count = 176 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 71us (kms_flip:13908) DEBUG: name = flip last_ts = 274.379456 last_received_ts = 274.378784 last_seq = 1590 current_ts = 274.396149 current_received_ts = 274.395447 current_seq = 1591 count = 177 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 72us (kms_flip:13908) DEBUG: name = flip last_ts = 274.396149 last_received_ts = 274.395447 last_seq = 1591 current_ts = 274.412811 current_received_ts = 274.412140 current_seq = 1592 count = 178 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 75us (kms_flip:13908) DEBUG: name = flip last_ts = 274.412811 last_received_ts = 274.412140 last_seq = 1592 current_ts = 274.429474 current_received_ts = 274.428802 current_seq = 1593 count = 179 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 72us (kms_flip:13908) DEBUG: name = flip last_ts = 274.429474 last_received_ts = 274.428802 last_seq = 1593 current_ts = 274.446136 current_received_ts = 274.445435 current_seq = 1594 count = 180 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 69us (kms_flip:13908) DEBUG: name = flip last_ts = 274.446136 last_received_ts = 274.445435 last_seq = 1594 current_ts = 274.462799 current_received_ts = 274.462097 current_seq = 1595 count = 181 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 69us (kms_flip:13908) DEBUG: name = flip last_ts = 274.462799 last_received_ts = 274.462097 last_seq = 1595 current_ts = 274.479462 current_received_ts = 274.478790 current_seq = 1596 count = 182 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 70us (kms_flip:13908) DEBUG: name = flip last_ts = 274.479462 last_received_ts = 274.478790 last_seq = 1596 current_ts = 274.496124 current_received_ts = 274.495422 current_seq = 1597 count = 183 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 152us (kms_flip:13908) DEBUG: name = flip last_ts = 274.496124 last_received_ts = 274.495422 last_seq = 1597 current_ts = 274.512817 current_received_ts = 274.512024 current_seq = 1598 count = 184 seq_step = 1 (kms_flip:13908) DEBUG: Vblank took 1041us (kms_flip:13908) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:13908) CRITICAL: Failed assertion: end - start < 500 (kms_flip:13908) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:13908) igt_core-INFO: Stack trace: (kms_flip:13908) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:13908) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:13908) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:13908) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:13908) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:13908) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:13908) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:13908) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (4.293s)
Dmesg	<6> [285.144797] Console: switching to colour dummy device 80x25 <6> [285.145131] [IGT] kms_flip: executing <7> [285.152919] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] <7> [285.152930] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1] <7> [285.153113] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [285.153237] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected <7> [285.153558] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] <7> [285.153563] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2] <7> [285.153716] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [285.153855] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected <7> [285.154182] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] <7> [285.154187] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3] <7> [285.154340] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [285.154456] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected <7> [285.154773] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] <7> [285.154778] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:393:eDP-1] <7> [285.155273] 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> [285.155609] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [285.155735] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [285.156268] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [285.156616] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [285.156630] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [285.156749] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [285.156750] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [285.156754] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [285.156757] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [285.156759] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD monitor <5> [285.156763] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [285.156765] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD size 20, SAD count 0 <5> [285.157265] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [285.157285] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] VRR capable: yes <7> [285.157417] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [285.157542] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [285.157912] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [285.157915] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [285.157917] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [285.157980] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] probed modes: <7> [285.157985] 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> [285.157989] 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> [285.158008] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] <7> [285.158012] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1] <7> [285.158180] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected <7> [285.158192] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] <7> [285.158195] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2] <7> [285.158353] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected <7> [285.158365] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] <7> [285.158368] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3] <7> [285.158520] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected <6> [285.163096] [IGT] kms_flip: starting subtest flip-vs-expired-vblank-interruptible <6> [285.164658] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [285.165405] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430] <7> [285.165751] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432] <7> [285.225298] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [285.225381] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [285.225503] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [285.225600] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [285.225694] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [285.225805] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151: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> [285.225923] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [285.226041] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [285.226135] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [285.226223] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [285.226310] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [285.226396] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [285.226482] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [285.226566] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [285.226649] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [285.226746] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [285.226862] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [285.226971] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [285.227074] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [285.227156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [285.227238] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [285.227321] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [285.227411] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [285.227494] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [285.227577] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [285.227659] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [285.227740] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [285.227846] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [285.227949] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [285.228050] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [285.228136] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [285.228221] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [285.228302] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [285.228377] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [285.228452] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [285.228527] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [285.228600] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [285.228674] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [285.228747] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [285.228888] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [285.228988] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0 <7> [285.229112] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [285.229178] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [285.229263] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [285.229330] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [285.229395] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229453] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229510] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229565] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229632] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0 <7> [285.229727] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [285.229847] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [285.229968] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [285.230073] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [285.230155] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [285.230237] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [285.230330] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [285.230418] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [285.230502] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [285.230582] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [285.230678] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset] <7> [285.230764] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [285.230868] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [285.230974] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [285.231077] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [285.231158] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [285.231238] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [285.231352] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [285.231450] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [285.231589] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [285.232258] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [285.232370] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [285.436905] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0 <7> [285.437339] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [285.449071] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off <7> [285.449323] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time <7> [285.449576] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [285.501868] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [285.502148] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short <7> [285.510347] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [285.510751] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A] <7> [285.510760] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [285.512246] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [285.512751] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [285.513189] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [285.513521] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [285.513826] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [285.514095] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [285.514369] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [285.514625] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [285.514943] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [285.515194] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [285.515443] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [285.515688] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [285.516010] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [285.516254] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [285.516493] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [285.516750] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [285.517149] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [285.517410] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [285.517658] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [285.518225] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [285.518631] 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> [285.519133] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [285.519494] 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> [285.519921] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [285.520199] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [285.520992] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B] <7> [285.521319] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C] <7> [285.521590] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [285.521662] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1] <7> [285.521856] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [285.522218] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151: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> [285.522571] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000 <7> [285.522929] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [285.523260] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A] <7> [285.523596] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [285.523933] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [285.524248] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [285.524548] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [285.524844] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151: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> [285.525149] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [285.525394] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [285.525623] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [285.525881] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [285.526095] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [285.526307] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [285.526507] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [285.526747] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [285.526945] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [285.527143] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [285.527319] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [285.527491] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [285.527664] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [285.527853] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [285.528013] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [285.528169] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [285.528348] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [285.528499] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [285.528649] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [285.528879] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [285.529017] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [285.529154] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [285.529289] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [285.529422] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [285.529548] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [285.529693] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [285.529844] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [285.529969] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [285.530092] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [285.530215] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [285.530332] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [285.530463] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [285.530597] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 432000) <7> [285.530719] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [285.530869] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [285.530965] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [285.531087] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [285.531175] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [285.531250] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531324] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531398] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531470] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531565] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1 <7> [285.531690] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [285.531817] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [285.531920] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [285.532019] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [285.532116] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [285.532210] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [285.532316] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [285.532406] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [285.532491] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [285.532577] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [285.532673] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0 <7> [285.532774] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0 <7> [285.532877] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset] <7> [285.532987] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [285.533078] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0 <7> [285.533160] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [285.533242] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [285.533323] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [285.533402] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [285.533480] 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> [285.533560] 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> [285.533638] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [285.533722] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [285.533808] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [285.533892] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0 <7> [285.533973] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [285.534052] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [285.534128] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [285.534204] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [285.534277] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [285.534351] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [285.534426] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [285.534501] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [285.534575] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [285.534649] 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> [285.534733] 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> [285.534816] 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> [285.534899] 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> [285.534981] 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> [285.535059] 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> [285.535135] 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> [285.535210] 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> [285.535286] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0 <7> [285.535363] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [285.535439] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [285.535516] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0 <7> [285.535593] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [285.535669] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [285.535758] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [285.535842] 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> [285.535922] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no, <7> [285.536002] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [285.536074] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [285.536147] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [285.536220] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [285.536293] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [285.536366] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [285.536440] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [285.536514] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [285.536587] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [285.536659] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [285.536741] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [285.536829] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [285.536936] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [285.537042] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [285.537130] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [285.537203] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [285.537275] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [285.537347] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [285.537419] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [285.537491] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [285.537563] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [285.537636] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [285.537714] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [285.537802] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [285.537884] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [285.537963] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [285.538038] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [285.538110] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [285.538471] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [285.538614] 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> [285.538723] 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> [285.538827] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [285.538923] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [285.539016] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [285.539086] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [285.539156] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [285.539225] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [285.539291] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [285.539358] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [285.539425] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [285.539489] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [285.539553] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [285.539616] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [285.539678] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [285.539754] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [285.539825] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [285.539916] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [285.540081] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [285.540144] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [285.540248] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [285.541667] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A] <7> [285.541796] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [285.542421] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [285.542500] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [285.542575] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [285.542676] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [285.543999] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on <7> [285.544078] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining) <7> [286.012701] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [286.042669] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [286.042912] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on <7> [286.043151] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [286.079647] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [286.079960] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [286.080258] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [286.080668] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [286.188759] 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> [286.188879] 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> [286.188994] 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> [286.257241] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [286.257534] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on <7> [286.257855] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [286.259751] 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> [286.261202] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [286.261850] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [286.262834] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [286.264040] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [286.264968] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK <7> [286.265200] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [286.266489] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [286.266736] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [286.267339] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [286.267684] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [286.267934] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [286.268220] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518 <7> [286.284441] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [286.285962] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [286.286311] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [288.813169] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off <7> [288.813635] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [289.403031] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [289.403574] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [289.404055] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [289.458475] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

4.29 seconds

Hostname

shard-lnl-7

Igt-Version

IGT-Version: 2.4-g0f0afe46c (x86_64) (Linux: 7.1.0-rc1-lgci-xe-xe-4949-1db870ffb55b6414a-debug+ x86_64)

Out

Using IGT_SRANDOM=1777490128 for randomisation
Opened device: /dev/dri/card1
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:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (4.293s)

Err

Starting subtest: flip-vs-expired-vblank-interruptible
Starting dynamic subtest: A-eDP1
(kms_flip:13908) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:13908) CRITICAL: Failed assertion: end - start < 500
(kms_flip:13908) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:13908) DEBUG: Vblank took 89us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.496063
last_received_ts = 272.495270
last_seq = 1477
current_ts = 272.512756
current_received_ts = 272.512085
current_seq = 1478
count = 64
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.512756
last_received_ts = 272.512085
last_seq = 1478
current_ts = 272.529419
current_received_ts = 272.528717
current_seq = 1479
count = 65
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 96us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.529419
last_received_ts = 272.528717
last_seq = 1479
current_ts = 272.546082
current_received_ts = 272.545258
current_seq = 1480
count = 66
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.546082
last_received_ts = 272.545258
last_seq = 1480
current_ts = 272.562744
current_received_ts = 272.561951
current_seq = 1481
count = 67
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 99us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.562744
last_received_ts = 272.561951
last_seq = 1481
current_ts = 272.579407
current_received_ts = 272.578644
current_seq = 1482
count = 68
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 61us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.579407
last_received_ts = 272.578644
last_seq = 1482
current_ts = 272.596069
current_received_ts = 272.595276
current_seq = 1483
count = 69
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.596069
last_received_ts = 272.595276
last_seq = 1483
current_ts = 272.612732
current_received_ts = 272.611969
current_seq = 1484
count = 70
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 84us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.612732
last_received_ts = 272.611969
last_seq = 1484
current_ts = 272.629425
current_received_ts = 272.628632
current_seq = 1485
count = 71
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 60us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.629425
last_received_ts = 272.628632
last_seq = 1485
current_ts = 272.646088
current_received_ts = 272.645264
current_seq = 1486
count = 72
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.646088
last_received_ts = 272.645264
last_seq = 1486
current_ts = 272.662750
current_received_ts = 272.661957
current_seq = 1487
count = 73
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 92us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.662750
last_received_ts = 272.661957
last_seq = 1487
current_ts = 272.679413
current_received_ts = 272.678711
current_seq = 1488
count = 74
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.679413
last_received_ts = 272.678711
last_seq = 1488
current_ts = 272.696075
current_received_ts = 272.695282
current_seq = 1489
count = 75
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.696075
last_received_ts = 272.695282
last_seq = 1489
current_ts = 272.712738
current_received_ts = 272.711975
current_seq = 1490
count = 76
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 86us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.712738
last_received_ts = 272.711975
last_seq = 1490
current_ts = 272.729431
current_received_ts = 272.728607
current_seq = 1491
count = 77
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 67us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.729431
last_received_ts = 272.728607
last_seq = 1491
current_ts = 272.746094
current_received_ts = 272.745270
current_seq = 1492
count = 78
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.746094
last_received_ts = 272.745270
last_seq = 1492
current_ts = 272.762756
current_received_ts = 272.762054
current_seq = 1493
count = 79
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.762756
last_received_ts = 272.762054
last_seq = 1493
current_ts = 272.779419
current_received_ts = 272.778625
current_seq = 1494
count = 80
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.779419
last_received_ts = 272.778625
last_seq = 1494
current_ts = 272.796082
current_received_ts = 272.795380
current_seq = 1495
count = 81
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.796082
last_received_ts = 272.795380
last_seq = 1495
current_ts = 272.812744
current_received_ts = 272.812042
current_seq = 1496
count = 82
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.812744
last_received_ts = 272.812042
last_seq = 1496
current_ts = 272.829407
current_received_ts = 272.828705
current_seq = 1497
count = 83
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.829407
last_received_ts = 272.828705
last_seq = 1497
current_ts = 272.846100
current_received_ts = 272.845398
current_seq = 1498
count = 84
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.846100
last_received_ts = 272.845398
last_seq = 1498
current_ts = 272.862762
current_received_ts = 272.862061
current_seq = 1499
count = 85
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.862762
last_received_ts = 272.862061
last_seq = 1499
current_ts = 272.879425
current_received_ts = 272.878784
current_seq = 1500
count = 86
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 95us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.879425
last_received_ts = 272.878784
last_seq = 1500
current_ts = 272.896088
current_received_ts = 272.895416
current_seq = 1501
count = 87
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 94us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.896088
last_received_ts = 272.895416
last_seq = 1501
current_ts = 272.912750
current_received_ts = 272.912079
current_seq = 1502
count = 88
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 77us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.912750
last_received_ts = 272.912079
last_seq = 1502
current_ts = 272.929413
current_received_ts = 272.928741
current_seq = 1503
count = 89
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 67us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.929413
last_received_ts = 272.928741
last_seq = 1503
current_ts = 272.946075
current_received_ts = 272.945404
current_seq = 1504
count = 90
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 74us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.946075
last_received_ts = 272.945404
last_seq = 1504
current_ts = 272.962769
current_received_ts = 272.962067
current_seq = 1505
count = 91
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.962769
last_received_ts = 272.962067
last_seq = 1505
current_ts = 272.979431
current_received_ts = 272.978729
current_seq = 1506
count = 92
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.979431
last_received_ts = 272.978729
last_seq = 1506
current_ts = 272.996094
current_received_ts = 272.995392
current_seq = 1507
count = 93
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 67us
(kms_flip:13908) DEBUG: name = flip
last_ts = 272.996094
last_received_ts = 272.995392
last_seq = 1507
current_ts = 273.012756
current_received_ts = 273.012054
current_seq = 1508
count = 94
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 63us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.012756
last_received_ts = 273.012054
last_seq = 1508
current_ts = 273.029419
current_received_ts = 273.028717
current_seq = 1509
count = 95
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.029419
last_received_ts = 273.028717
last_seq = 1509
current_ts = 273.046082
current_received_ts = 273.045380
current_seq = 1510
count = 96
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.046082
last_received_ts = 273.045380
last_seq = 1510
current_ts = 273.062744
current_received_ts = 273.062073
current_seq = 1511
count = 97
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.062744
last_received_ts = 273.062073
last_seq = 1511
current_ts = 273.079437
current_received_ts = 273.078644
current_seq = 1512
count = 98
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.079437
last_received_ts = 273.078644
last_seq = 1512
current_ts = 273.096100
current_received_ts = 273.095398
current_seq = 1513
count = 99
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.096100
last_received_ts = 273.095398
last_seq = 1513
current_ts = 273.112762
current_received_ts = 273.112091
current_seq = 1514
count = 100
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.112762
last_received_ts = 273.112091
last_seq = 1514
current_ts = 273.129425
current_received_ts = 273.128723
current_seq = 1515
count = 101
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.129425
last_received_ts = 273.128723
last_seq = 1515
current_ts = 273.146088
current_received_ts = 273.145416
current_seq = 1516
count = 102
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.146088
last_received_ts = 273.145416
last_seq = 1516
current_ts = 273.162750
current_received_ts = 273.162079
current_seq = 1517
count = 103
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.162750
last_received_ts = 273.162079
last_seq = 1517
current_ts = 273.179413
current_received_ts = 273.178650
current_seq = 1518
count = 104
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.179413
last_received_ts = 273.178650
last_seq = 1518
current_ts = 273.196106
current_received_ts = 273.195374
current_seq = 1519
count = 105
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.196106
last_received_ts = 273.195374
last_seq = 1519
current_ts = 273.212769
current_received_ts = 273.212036
current_seq = 1520
count = 106
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.212769
last_received_ts = 273.212036
last_seq = 1520
current_ts = 273.229431
current_received_ts = 273.228729
current_seq = 1521
count = 107
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.229431
last_received_ts = 273.228729
last_seq = 1521
current_ts = 273.246094
current_received_ts = 273.245392
current_seq = 1522
count = 108
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 63us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.246094
last_received_ts = 273.245392
last_seq = 1522
current_ts = 273.262756
current_received_ts = 273.262054
current_seq = 1523
count = 109
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 72us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.262756
last_received_ts = 273.262054
last_seq = 1523
current_ts = 273.279419
current_received_ts = 273.278717
current_seq = 1524
count = 110
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.279419
last_received_ts = 273.278717
last_seq = 1524
current_ts = 273.296112
current_received_ts = 273.295380
current_seq = 1525
count = 111
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.296112
last_received_ts = 273.295380
last_seq = 1525
current_ts = 273.312775
current_received_ts = 273.312042
current_seq = 1526
count = 112
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 69us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.312775
last_received_ts = 273.312042
last_seq = 1526
current_ts = 273.329437
current_received_ts = 273.328674
current_seq = 1527
count = 113
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.329437
last_received_ts = 273.328674
last_seq = 1527
current_ts = 273.346100
current_received_ts = 273.345428
current_seq = 1528
count = 114
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.346100
last_received_ts = 273.345428
last_seq = 1528
current_ts = 273.362762
current_received_ts = 273.362061
current_seq = 1529
count = 115
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 96us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.362762
last_received_ts = 273.362061
last_seq = 1529
current_ts = 273.379425
current_received_ts = 273.378662
current_seq = 1530
count = 116
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 45us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.379425
last_received_ts = 273.378662
last_seq = 1530
current_ts = 273.396088
current_received_ts = 273.395477
current_seq = 1531
count = 117
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 80us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.396088
last_received_ts = 273.395477
last_seq = 1531
current_ts = 273.412781
current_received_ts = 273.412079
current_seq = 1532
count = 118
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 108us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.412781
last_received_ts = 273.412079
last_seq = 1532
current_ts = 273.429443
current_received_ts = 273.428772
current_seq = 1533
count = 119
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 71us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.429443
last_received_ts = 273.428772
last_seq = 1533
current_ts = 273.446106
current_received_ts = 273.445404
current_seq = 1534
count = 120
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 71us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.446106
last_received_ts = 273.445404
last_seq = 1534
current_ts = 273.462769
current_received_ts = 273.462097
current_seq = 1535
count = 121
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.462769
last_received_ts = 273.462097
last_seq = 1535
current_ts = 273.479431
current_received_ts = 273.478729
current_seq = 1536
count = 122
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.479431
last_received_ts = 273.478729
last_seq = 1536
current_ts = 273.496094
current_received_ts = 273.495392
current_seq = 1537
count = 123
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.496094
last_received_ts = 273.495392
last_seq = 1537
current_ts = 273.512756
current_received_ts = 273.512115
current_seq = 1538
count = 124
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.512756
last_received_ts = 273.512115
last_seq = 1538
current_ts = 273.529449
current_received_ts = 273.528748
current_seq = 1539
count = 125
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.529449
last_received_ts = 273.528748
last_seq = 1539
current_ts = 273.546112
current_received_ts = 273.545410
current_seq = 1540
count = 126
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.546112
last_received_ts = 273.545410
last_seq = 1540
current_ts = 273.562775
current_received_ts = 273.562073
current_seq = 1541
count = 127
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.562775
last_received_ts = 273.562073
last_seq = 1541
current_ts = 273.579437
current_received_ts = 273.578735
current_seq = 1542
count = 128
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.579437
last_received_ts = 273.578735
last_seq = 1542
current_ts = 273.596100
current_received_ts = 273.595428
current_seq = 1543
count = 129
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.596100
last_received_ts = 273.595428
last_seq = 1543
current_ts = 273.612762
current_received_ts = 273.612091
current_seq = 1544
count = 130
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.612762
last_received_ts = 273.612091
last_seq = 1544
current_ts = 273.629425
current_received_ts = 273.628754
current_seq = 1545
count = 131
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 66us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.629425
last_received_ts = 273.628754
last_seq = 1545
current_ts = 273.646118
current_received_ts = 273.645416
current_seq = 1546
count = 132
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.646118
last_received_ts = 273.645416
last_seq = 1546
current_ts = 273.662781
current_received_ts = 273.662048
current_seq = 1547
count = 133
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.662781
last_received_ts = 273.662048
last_seq = 1547
current_ts = 273.679443
current_received_ts = 273.678741
current_seq = 1548
count = 134
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.679443
last_received_ts = 273.678741
last_seq = 1548
current_ts = 273.696106
current_received_ts = 273.695404
current_seq = 1549
count = 135
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.696106
last_received_ts = 273.695404
last_seq = 1549
current_ts = 273.712769
current_received_ts = 273.712097
current_seq = 1550
count = 136
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.712769
last_received_ts = 273.712097
last_seq = 1550
current_ts = 273.729431
current_received_ts = 273.728729
current_seq = 1551
count = 137
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.729431
last_received_ts = 273.728729
last_seq = 1551
current_ts = 273.746124
current_received_ts = 273.745422
current_seq = 1552
count = 138
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 70us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.746124
last_received_ts = 273.745422
last_seq = 1552
current_ts = 273.762787
current_received_ts = 273.762085
current_seq = 1553
count = 139
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.762787
last_received_ts = 273.762085
last_seq = 1553
current_ts = 273.779449
current_received_ts = 273.778809
current_seq = 1554
count = 140
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.779449
last_received_ts = 273.778809
last_seq = 1554
current_ts = 273.796112
current_received_ts = 273.795410
current_seq = 1555
count = 141
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.796112
last_received_ts = 273.795410
last_seq = 1555
current_ts = 273.812775
current_received_ts = 273.812073
current_seq = 1556
count = 142
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.812775
last_received_ts = 273.812073
last_seq = 1556
current_ts = 273.829437
current_received_ts = 273.828735
current_seq = 1557
count = 143
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 64us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.829437
last_received_ts = 273.828735
last_seq = 1557
current_ts = 273.846130
current_received_ts = 273.845428
current_seq = 1558
count = 144
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.846130
last_received_ts = 273.845428
last_seq = 1558
current_ts = 273.862793
current_received_ts = 273.862091
current_seq = 1559
count = 145
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.862793
last_received_ts = 273.862091
last_seq = 1559
current_ts = 273.879456
current_received_ts = 273.878784
current_seq = 1560
count = 146
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 65us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.879456
last_received_ts = 273.878784
last_seq = 1560
current_ts = 273.896118
current_received_ts = 273.895447
current_seq = 1561
count = 147
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 81us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.896118
last_received_ts = 273.895447
last_seq = 1561
current_ts = 273.912781
current_received_ts = 273.912109
current_seq = 1562
count = 148
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 75us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.912781
last_received_ts = 273.912109
last_seq = 1562
current_ts = 273.929443
current_received_ts = 273.928772
current_seq = 1563
count = 149
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 70us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.929443
last_received_ts = 273.928772
last_seq = 1563
current_ts = 273.946106
current_received_ts = 273.945374
current_seq = 1564
count = 150
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 67us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.946106
last_received_ts = 273.945374
last_seq = 1564
current_ts = 273.962799
current_received_ts = 273.961975
current_seq = 1565
count = 151
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 58us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.962799
last_received_ts = 273.961975
last_seq = 1565
current_ts = 273.979462
current_received_ts = 273.978760
current_seq = 1566
count = 152
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 54us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.979462
last_received_ts = 273.978760
last_seq = 1566
current_ts = 273.996124
current_received_ts = 273.995422
current_seq = 1567
count = 153
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 56us
(kms_flip:13908) DEBUG: name = flip
last_ts = 273.996124
last_received_ts = 273.995422
last_seq = 1567
current_ts = 274.012787
current_received_ts = 274.012085
current_seq = 1568
count = 154
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 45us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.012787
last_received_ts = 274.012085
last_seq = 1568
current_ts = 274.029449
current_received_ts = 274.028748
current_seq = 1569
count = 155
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 38us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.029449
last_received_ts = 274.028748
last_seq = 1569
current_ts = 274.046112
current_received_ts = 274.045410
current_seq = 1570
count = 156
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 38us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.046112
last_received_ts = 274.045410
last_seq = 1570
current_ts = 274.062775
current_received_ts = 274.062042
current_seq = 1571
count = 157
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 129us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.062775
last_received_ts = 274.062042
last_seq = 1571
current_ts = 274.079468
current_received_ts = 274.078766
current_seq = 1572
count = 158
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 111us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.079468
last_received_ts = 274.078766
last_seq = 1572
current_ts = 274.096130
current_received_ts = 274.095428
current_seq = 1573
count = 159
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 99us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.096130
last_received_ts = 274.095428
last_seq = 1573
current_ts = 274.112793
current_received_ts = 274.112152
current_seq = 1574
count = 160
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 102us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.112793
last_received_ts = 274.112152
last_seq = 1574
current_ts = 274.129456
current_received_ts = 274.128784
current_seq = 1575
count = 161
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 133us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.129456
last_received_ts = 274.128784
last_seq = 1575
current_ts = 274.146118
current_received_ts = 274.145447
current_seq = 1576
count = 162
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 122us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.146118
last_received_ts = 274.145447
last_seq = 1576
current_ts = 274.162781
current_received_ts = 274.162048
current_seq = 1577
count = 163
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 43us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.162781
last_received_ts = 274.162048
last_seq = 1577
current_ts = 274.179443
current_received_ts = 274.178741
current_seq = 1578
count = 164
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 99us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.179443
last_received_ts = 274.178741
last_seq = 1578
current_ts = 274.196136
current_received_ts = 274.195435
current_seq = 1579
count = 165
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 39us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.196136
last_received_ts = 274.195435
last_seq = 1579
current_ts = 274.212799
current_received_ts = 274.212036
current_seq = 1580
count = 166
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 41us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.212799
last_received_ts = 274.212036
last_seq = 1580
current_ts = 274.229462
current_received_ts = 274.228760
current_seq = 1581
count = 167
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 113us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.229462
last_received_ts = 274.228760
last_seq = 1581
current_ts = 274.246124
current_received_ts = 274.245422
current_seq = 1582
count = 168
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 97us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.246124
last_received_ts = 274.245422
last_seq = 1582
current_ts = 274.262787
current_received_ts = 274.262085
current_seq = 1583
count = 169
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 35us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.262787
last_received_ts = 274.262085
last_seq = 1583
current_ts = 274.279480
current_received_ts = 274.278748
current_seq = 1584
count = 170
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 41us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.279480
last_received_ts = 274.278748
last_seq = 1584
current_ts = 274.296143
current_received_ts = 274.295441
current_seq = 1585
count = 171
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 40us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.296143
last_received_ts = 274.295441
last_seq = 1585
current_ts = 274.312805
current_received_ts = 274.312134
current_seq = 1586
count = 172
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 102us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.312805
last_received_ts = 274.312134
last_seq = 1586
current_ts = 274.329468
current_received_ts = 274.328796
current_seq = 1587
count = 173
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 88us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.329468
last_received_ts = 274.328796
last_seq = 1587
current_ts = 274.346130
current_received_ts = 274.345459
current_seq = 1588
count = 174
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 74us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.346130
last_received_ts = 274.345459
last_seq = 1588
current_ts = 274.362793
current_received_ts = 274.362091
current_seq = 1589
count = 175
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 73us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.362793
last_received_ts = 274.362091
last_seq = 1589
current_ts = 274.379456
current_received_ts = 274.378784
current_seq = 1590
count = 176
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 71us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.379456
last_received_ts = 274.378784
last_seq = 1590
current_ts = 274.396149
current_received_ts = 274.395447
current_seq = 1591
count = 177
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 72us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.396149
last_received_ts = 274.395447
last_seq = 1591
current_ts = 274.412811
current_received_ts = 274.412140
current_seq = 1592
count = 178
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 75us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.412811
last_received_ts = 274.412140
last_seq = 1592
current_ts = 274.429474
current_received_ts = 274.428802
current_seq = 1593
count = 179
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 72us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.429474
last_received_ts = 274.428802
last_seq = 1593
current_ts = 274.446136
current_received_ts = 274.445435
current_seq = 1594
count = 180
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 69us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.446136
last_received_ts = 274.445435
last_seq = 1594
current_ts = 274.462799
current_received_ts = 274.462097
current_seq = 1595
count = 181
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 69us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.462799
last_received_ts = 274.462097
last_seq = 1595
current_ts = 274.479462
current_received_ts = 274.478790
current_seq = 1596
count = 182
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 70us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.479462
last_received_ts = 274.478790
last_seq = 1596
current_ts = 274.496124
current_received_ts = 274.495422
current_seq = 1597
count = 183
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 152us
(kms_flip:13908) DEBUG: name = flip
last_ts = 274.496124
last_received_ts = 274.495422
last_seq = 1597
current_ts = 274.512817
current_received_ts = 274.512024
current_seq = 1598
count = 184
seq_step = 1
(kms_flip:13908) DEBUG: Vblank took 1041us
(kms_flip:13908) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:13908) CRITICAL: Failed assertion: end - start < 500
(kms_flip:13908) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:13908) igt_core-INFO: Stack trace:
(kms_flip:13908) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:13908) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:13908) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:13908) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:13908) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:13908) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:13908) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:13908) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (4.293s)

Dmesg

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [285.155273] 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> [285.155609] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [285.157985] 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> [285.157989] 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> [285.158008] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]

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

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

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

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

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

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

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

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

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

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

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

<7> [285.165751] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]

<7> [285.225298] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

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

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

<7> [285.225805] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151: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> [285.225923] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [285.229263] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

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

<7> [285.229395] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229453] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229510] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229565] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.229632] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [285.518631] 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> [285.519133] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

<7> [285.519494] 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> [285.519921] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

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

<7> [285.520992] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]

<7> [285.521319] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]

<7> [285.521590] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

<7> [285.522218] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151: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> [285.522571] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000

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

<7> [285.523260] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]

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

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

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

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

<7> [285.524844] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151: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> [285.525149] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [285.531087] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

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

<7> [285.531250] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531324] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531398] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531470] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35: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> [285.531565] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [285.533480] 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> [285.533560] 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> [285.533638] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

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

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

<7> [285.533892] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0

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

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

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

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

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

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

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

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

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

<7> [285.534649] 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> [285.534733] 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> [285.534816] 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> [285.534899] 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> [285.534981] 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> [285.535059] 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> [285.535135] 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> [285.535210] 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> [285.535286] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0

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

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

<7> [285.535516] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0

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

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

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

<7> [285.535842] 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> [285.535922] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [285.538614] 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> [285.538723] 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> [285.538827] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [286.188759] 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> [286.188879] 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> [286.188994] 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> [286.257241] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

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

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

<7> [286.259751] 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> [286.261202] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates

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

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

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

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

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

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

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

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

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

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

<7> [286.268220] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518

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

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

<7> [286.286311] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

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

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

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

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

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

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

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