igt@kms_flip@flip-vs-expired-vblank-interruptible@b-dp2 on shard-bmg@IGTPW

Detail	Value
Duration	3.63 seconds
Hostname	shard-bmg-9
Igt-Version	IGT-Version: 2.4-g9a23f360a (x86_64) (Linux: 7.1.0-rc2-lgci-xe-xe-5018-36eddf6e5c9411ad9-debug+ x86_64)
Out	Starting dynamic subtest: B-DP2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c: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 B-DP2: FAIL (3.630s)
Err	Starting dynamic subtest: B-DP2 (kms_flip:6695) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:6695) CRITICAL: Failed assertion: end - start < 500 (kms_flip:6695) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest B-DP2 failed. ** DEBUG (kms_flip:6695) DEBUG: Vblank took 244us (kms_flip:6695) DEBUG: name = flip last_ts = 214.989670 last_received_ts = 214.989288 last_seq = 1554 current_ts = 215.006332 current_received_ts = 215.005966 current_seq = 1555 count = 43 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 254us (kms_flip:6695) DEBUG: name = flip last_ts = 215.006332 last_received_ts = 215.005966 last_seq = 1555 current_ts = 215.022995 current_received_ts = 215.022629 current_seq = 1556 count = 44 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 237us (kms_flip:6695) DEBUG: name = flip last_ts = 215.022995 last_received_ts = 215.022629 last_seq = 1556 current_ts = 215.039673 current_received_ts = 215.039291 current_seq = 1557 count = 45 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 243us (kms_flip:6695) DEBUG: name = flip last_ts = 215.039673 last_received_ts = 215.039291 last_seq = 1557 current_ts = 215.056335 current_received_ts = 215.055969 current_seq = 1558 count = 46 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.056335 last_received_ts = 215.055969 last_seq = 1558 current_ts = 215.072998 current_received_ts = 215.072632 current_seq = 1559 count = 47 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 231us (kms_flip:6695) DEBUG: name = flip last_ts = 215.072998 last_received_ts = 215.072632 last_seq = 1559 current_ts = 215.089676 current_received_ts = 215.089294 current_seq = 1560 count = 48 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 239us (kms_flip:6695) DEBUG: name = flip last_ts = 215.089676 last_received_ts = 215.089294 last_seq = 1560 current_ts = 215.106339 current_received_ts = 215.106110 current_seq = 1561 count = 49 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 39us (kms_flip:6695) DEBUG: name = flip last_ts = 215.106339 last_received_ts = 215.106110 last_seq = 1561 current_ts = 215.123016 current_received_ts = 215.122757 current_seq = 1562 count = 50 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 38us (kms_flip:6695) DEBUG: name = flip last_ts = 215.123016 last_received_ts = 215.122757 last_seq = 1562 current_ts = 215.139664 current_received_ts = 215.139313 current_seq = 1563 count = 51 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 28us (kms_flip:6695) DEBUG: name = flip last_ts = 215.139664 last_received_ts = 215.139313 last_seq = 1563 current_ts = 215.156342 current_received_ts = 215.155975 current_seq = 1564 count = 52 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 250us (kms_flip:6695) DEBUG: name = flip last_ts = 215.156342 last_received_ts = 215.155975 last_seq = 1564 current_ts = 215.173004 current_received_ts = 215.172638 current_seq = 1565 count = 53 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 27us (kms_flip:6695) DEBUG: name = flip last_ts = 215.173004 last_received_ts = 215.172638 last_seq = 1565 current_ts = 215.189667 current_received_ts = 215.189301 current_seq = 1566 count = 54 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 215.189667 last_received_ts = 215.189301 last_seq = 1566 current_ts = 215.206345 current_received_ts = 215.205963 current_seq = 1567 count = 55 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 42us (kms_flip:6695) DEBUG: name = flip last_ts = 215.206345 last_received_ts = 215.205963 last_seq = 1567 current_ts = 215.223007 current_received_ts = 215.222641 current_seq = 1568 count = 56 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.223007 last_received_ts = 215.222641 last_seq = 1568 current_ts = 215.239685 current_received_ts = 215.239304 current_seq = 1569 count = 57 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.239685 last_received_ts = 215.239304 last_seq = 1569 current_ts = 215.256348 current_received_ts = 215.255966 current_seq = 1570 count = 58 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 44us (kms_flip:6695) DEBUG: name = flip last_ts = 215.256348 last_received_ts = 215.255966 last_seq = 1570 current_ts = 215.273010 current_received_ts = 215.272644 current_seq = 1571 count = 59 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 27us (kms_flip:6695) DEBUG: name = flip last_ts = 215.273010 last_received_ts = 215.272644 last_seq = 1571 current_ts = 215.289688 current_received_ts = 215.289307 current_seq = 1572 count = 60 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.289688 last_received_ts = 215.289307 last_seq = 1572 current_ts = 215.306351 current_received_ts = 215.305984 current_seq = 1573 count = 61 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 41us (kms_flip:6695) DEBUG: name = flip last_ts = 215.306351 last_received_ts = 215.305984 last_seq = 1573 current_ts = 215.323013 current_received_ts = 215.322571 current_seq = 1574 count = 62 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.323013 last_received_ts = 215.322571 last_seq = 1574 current_ts = 215.339676 current_received_ts = 215.339310 current_seq = 1575 count = 63 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.339676 last_received_ts = 215.339310 last_seq = 1575 current_ts = 215.356354 current_received_ts = 215.355972 current_seq = 1576 count = 64 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 42us (kms_flip:6695) DEBUG: name = flip last_ts = 215.356354 last_received_ts = 215.355972 last_seq = 1576 current_ts = 215.373016 current_received_ts = 215.372574 current_seq = 1577 count = 65 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.373016 last_received_ts = 215.372574 last_seq = 1577 current_ts = 215.389679 current_received_ts = 215.389236 current_seq = 1578 count = 66 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.389679 last_received_ts = 215.389236 last_seq = 1578 current_ts = 215.406357 current_received_ts = 215.405975 current_seq = 1579 count = 67 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 42us (kms_flip:6695) DEBUG: name = flip last_ts = 215.406357 last_received_ts = 215.405975 last_seq = 1579 current_ts = 215.423019 current_received_ts = 215.422531 current_seq = 1580 count = 68 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.423019 last_received_ts = 215.422531 last_seq = 1580 current_ts = 215.439682 current_received_ts = 215.439240 current_seq = 1581 count = 69 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.439682 last_received_ts = 215.439240 last_seq = 1581 current_ts = 215.456360 current_received_ts = 215.455978 current_seq = 1582 count = 70 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 47us (kms_flip:6695) DEBUG: name = flip last_ts = 215.456360 last_received_ts = 215.455978 last_seq = 1582 current_ts = 215.473022 current_received_ts = 215.472656 current_seq = 1583 count = 71 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.473022 last_received_ts = 215.472656 last_seq = 1583 current_ts = 215.489685 current_received_ts = 215.489319 current_seq = 1584 count = 72 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.489685 last_received_ts = 215.489319 last_seq = 1584 current_ts = 215.506363 current_received_ts = 215.505981 current_seq = 1585 count = 73 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 60us (kms_flip:6695) DEBUG: name = flip last_ts = 215.506363 last_received_ts = 215.505981 last_seq = 1585 current_ts = 215.523026 current_received_ts = 215.522659 current_seq = 1586 count = 74 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.523026 last_received_ts = 215.522659 last_seq = 1586 current_ts = 215.539703 current_received_ts = 215.539322 current_seq = 1587 count = 75 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 215.539703 last_received_ts = 215.539322 last_seq = 1587 current_ts = 215.556366 current_received_ts = 215.556046 current_seq = 1588 count = 76 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 37us (kms_flip:6695) DEBUG: name = flip last_ts = 215.556366 last_received_ts = 215.556046 last_seq = 1588 current_ts = 215.573029 current_received_ts = 215.572662 current_seq = 1589 count = 77 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 28us (kms_flip:6695) DEBUG: name = flip last_ts = 215.573029 last_received_ts = 215.572662 last_seq = 1589 current_ts = 215.589691 current_received_ts = 215.589325 current_seq = 1590 count = 78 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 27us (kms_flip:6695) DEBUG: name = flip last_ts = 215.589691 last_received_ts = 215.589325 last_seq = 1590 current_ts = 215.606369 current_received_ts = 215.605988 current_seq = 1591 count = 79 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.606369 last_received_ts = 215.605988 last_seq = 1591 current_ts = 215.623032 current_received_ts = 215.622589 current_seq = 1592 count = 80 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.623032 last_received_ts = 215.622589 last_seq = 1592 current_ts = 215.639694 current_received_ts = 215.639252 current_seq = 1593 count = 81 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.639694 last_received_ts = 215.639252 last_seq = 1593 current_ts = 215.656372 current_received_ts = 215.655991 current_seq = 1594 count = 82 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 215.656372 last_received_ts = 215.655991 last_seq = 1594 current_ts = 215.673035 current_received_ts = 215.672592 current_seq = 1595 count = 83 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.673035 last_received_ts = 215.672592 last_seq = 1595 current_ts = 215.689697 current_received_ts = 215.689331 current_seq = 1596 count = 84 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 235us (kms_flip:6695) DEBUG: name = flip last_ts = 215.689697 last_received_ts = 215.689331 last_seq = 1596 current_ts = 215.706375 current_received_ts = 215.705994 current_seq = 1597 count = 85 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 230us (kms_flip:6695) DEBUG: name = flip last_ts = 215.706375 last_received_ts = 215.705994 last_seq = 1597 current_ts = 215.723038 current_received_ts = 215.722656 current_seq = 1598 count = 86 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 240us (kms_flip:6695) DEBUG: name = flip last_ts = 215.723038 last_received_ts = 215.722656 last_seq = 1598 current_ts = 215.739700 current_received_ts = 215.739334 current_seq = 1599 count = 87 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 248us (kms_flip:6695) DEBUG: name = flip last_ts = 215.739700 last_received_ts = 215.739334 last_seq = 1599 current_ts = 215.756378 current_received_ts = 215.755997 current_seq = 1600 count = 88 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 233us (kms_flip:6695) DEBUG: name = flip last_ts = 215.756378 last_received_ts = 215.755997 last_seq = 1600 current_ts = 215.773041 current_received_ts = 215.772659 current_seq = 1601 count = 89 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 246us (kms_flip:6695) DEBUG: name = flip last_ts = 215.773041 last_received_ts = 215.772659 last_seq = 1601 current_ts = 215.789703 current_received_ts = 215.789337 current_seq = 1602 count = 90 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 246us (kms_flip:6695) DEBUG: name = flip last_ts = 215.789703 last_received_ts = 215.789337 last_seq = 1602 current_ts = 215.806366 current_received_ts = 215.806000 current_seq = 1603 count = 91 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 223us (kms_flip:6695) DEBUG: name = flip last_ts = 215.806366 last_received_ts = 215.806000 last_seq = 1603 current_ts = 215.823044 current_received_ts = 215.822662 current_seq = 1604 count = 92 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 215.823044 last_received_ts = 215.822662 last_seq = 1604 current_ts = 215.839722 current_received_ts = 215.839325 current_seq = 1605 count = 93 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.839722 last_received_ts = 215.839325 last_seq = 1605 current_ts = 215.856384 current_received_ts = 215.856003 current_seq = 1606 count = 94 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 215.856384 last_received_ts = 215.856003 last_seq = 1606 current_ts = 215.873047 current_received_ts = 215.872665 current_seq = 1607 count = 95 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.873047 last_received_ts = 215.872665 last_seq = 1607 current_ts = 215.889709 current_received_ts = 215.889328 current_seq = 1608 count = 96 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.889709 last_received_ts = 215.889328 last_seq = 1608 current_ts = 215.906387 current_received_ts = 215.906036 current_seq = 1609 count = 97 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 212us (kms_flip:6695) DEBUG: name = flip last_ts = 215.906387 last_received_ts = 215.906036 last_seq = 1609 current_ts = 215.923050 current_received_ts = 215.922668 current_seq = 1610 count = 98 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 215.923050 last_received_ts = 215.922668 last_seq = 1610 current_ts = 215.939713 current_received_ts = 215.939346 current_seq = 1611 count = 99 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 215.939713 last_received_ts = 215.939346 last_seq = 1611 current_ts = 215.956375 current_received_ts = 215.956039 current_seq = 1612 count = 100 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 32us (kms_flip:6695) DEBUG: name = flip last_ts = 215.956375 last_received_ts = 215.956039 last_seq = 1612 current_ts = 215.973053 current_received_ts = 215.972641 current_seq = 1613 count = 101 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 215.973053 last_received_ts = 215.972641 last_seq = 1613 current_ts = 215.989716 current_received_ts = 215.989273 current_seq = 1614 count = 102 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 28us (kms_flip:6695) DEBUG: name = flip last_ts = 215.989716 last_received_ts = 215.989273 last_seq = 1614 current_ts = 216.006378 current_received_ts = 216.006821 current_seq = 1615 count = 103 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 259us (kms_flip:6695) DEBUG: name = flip last_ts = 216.006378 last_received_ts = 216.006821 last_seq = 1615 current_ts = 216.023056 current_received_ts = 216.022690 current_seq = 1616 count = 104 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.023056 last_received_ts = 216.022690 last_seq = 1616 current_ts = 216.039719 current_received_ts = 216.039352 current_seq = 1617 count = 105 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.039719 last_received_ts = 216.039352 last_seq = 1617 current_ts = 216.056381 current_received_ts = 216.056046 current_seq = 1618 count = 106 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.056381 last_received_ts = 216.056046 last_seq = 1618 current_ts = 216.073044 current_received_ts = 216.072678 current_seq = 1619 count = 107 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.073044 last_received_ts = 216.072678 last_seq = 1619 current_ts = 216.089722 current_received_ts = 216.089523 current_seq = 1620 count = 108 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 45us (kms_flip:6695) DEBUG: name = flip last_ts = 216.089722 last_received_ts = 216.089523 last_seq = 1620 current_ts = 216.106384 current_received_ts = 216.106049 current_seq = 1621 count = 109 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.106384 last_received_ts = 216.106049 last_seq = 1621 current_ts = 216.123047 current_received_ts = 216.122681 current_seq = 1622 count = 110 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.123047 last_received_ts = 216.122681 last_seq = 1622 current_ts = 216.139725 current_received_ts = 216.139359 current_seq = 1623 count = 111 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.139725 last_received_ts = 216.139359 last_seq = 1623 current_ts = 216.156403 current_received_ts = 216.156036 current_seq = 1624 count = 112 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.156403 last_received_ts = 216.156036 last_seq = 1624 current_ts = 216.173050 current_received_ts = 216.172684 current_seq = 1625 count = 113 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.173050 last_received_ts = 216.172684 last_seq = 1625 current_ts = 216.189743 current_received_ts = 216.189346 current_seq = 1626 count = 114 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.189743 last_received_ts = 216.189346 last_seq = 1626 current_ts = 216.206390 current_received_ts = 216.205902 current_seq = 1627 count = 115 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.206390 last_received_ts = 216.205902 last_seq = 1627 current_ts = 216.223068 current_received_ts = 216.222839 current_seq = 1628 count = 116 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 121us (kms_flip:6695) DEBUG: name = flip last_ts = 216.223068 last_received_ts = 216.222839 last_seq = 1628 current_ts = 216.239731 current_received_ts = 216.239380 current_seq = 1629 count = 117 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 36us (kms_flip:6695) DEBUG: name = flip last_ts = 216.239731 last_received_ts = 216.239380 last_seq = 1629 current_ts = 216.256393 current_received_ts = 216.256119 current_seq = 1630 count = 118 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 29us (kms_flip:6695) DEBUG: name = flip last_ts = 216.256393 last_received_ts = 216.256119 last_seq = 1630 current_ts = 216.273071 current_received_ts = 216.272781 current_seq = 1631 count = 119 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.273071 last_received_ts = 216.272781 last_seq = 1631 current_ts = 216.289734 current_received_ts = 216.289429 current_seq = 1632 count = 120 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.289734 last_received_ts = 216.289429 last_seq = 1632 current_ts = 216.306396 current_received_ts = 216.305984 current_seq = 1633 count = 121 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 44us (kms_flip:6695) DEBUG: name = flip last_ts = 216.306396 last_received_ts = 216.305984 last_seq = 1633 current_ts = 216.323074 current_received_ts = 216.322632 current_seq = 1634 count = 122 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.323074 last_received_ts = 216.322632 last_seq = 1634 current_ts = 216.339737 current_received_ts = 216.339432 current_seq = 1635 count = 123 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 28us (kms_flip:6695) DEBUG: name = flip last_ts = 216.339737 last_received_ts = 216.339432 last_seq = 1635 current_ts = 216.356400 current_received_ts = 216.356094 current_seq = 1636 count = 124 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.356400 last_received_ts = 216.356094 last_seq = 1636 current_ts = 216.373077 current_received_ts = 216.372772 current_seq = 1637 count = 125 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.373077 last_received_ts = 216.372772 last_seq = 1637 current_ts = 216.389740 current_received_ts = 216.389435 current_seq = 1638 count = 126 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.389740 last_received_ts = 216.389435 last_seq = 1638 current_ts = 216.406403 current_received_ts = 216.406097 current_seq = 1639 count = 127 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.406403 last_received_ts = 216.406097 last_seq = 1639 current_ts = 216.423065 current_received_ts = 216.422775 current_seq = 1640 count = 128 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.423065 last_received_ts = 216.422775 last_seq = 1640 current_ts = 216.439743 current_received_ts = 216.439392 current_seq = 1641 count = 129 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 233us (kms_flip:6695) DEBUG: name = flip last_ts = 216.439743 last_received_ts = 216.439392 last_seq = 1641 current_ts = 216.456406 current_received_ts = 216.456055 current_seq = 1642 count = 130 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 230us (kms_flip:6695) DEBUG: name = flip last_ts = 216.456406 last_received_ts = 216.456055 last_seq = 1642 current_ts = 216.473068 current_received_ts = 216.472778 current_seq = 1643 count = 131 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 32us (kms_flip:6695) DEBUG: name = flip last_ts = 216.473068 last_received_ts = 216.472778 last_seq = 1643 current_ts = 216.489746 current_received_ts = 216.489380 current_seq = 1644 count = 132 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 27us (kms_flip:6695) DEBUG: name = flip last_ts = 216.489746 last_received_ts = 216.489380 last_seq = 1644 current_ts = 216.506409 current_received_ts = 216.506073 current_seq = 1645 count = 133 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.506409 last_received_ts = 216.506073 last_seq = 1645 current_ts = 216.523071 current_received_ts = 216.522629 current_seq = 1646 count = 134 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.523071 last_received_ts = 216.522629 last_seq = 1646 current_ts = 216.539749 current_received_ts = 216.539307 current_seq = 1647 count = 135 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.539749 last_received_ts = 216.539307 last_seq = 1647 current_ts = 216.556412 current_received_ts = 216.556061 current_seq = 1648 count = 136 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.556412 last_received_ts = 216.556061 last_seq = 1648 current_ts = 216.573074 current_received_ts = 216.572708 current_seq = 1649 count = 137 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.573074 last_received_ts = 216.572708 last_seq = 1649 current_ts = 216.589752 current_received_ts = 216.589294 current_seq = 1650 count = 138 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.589752 last_received_ts = 216.589294 last_seq = 1650 current_ts = 216.606415 current_received_ts = 216.606064 current_seq = 1651 count = 139 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.606415 last_received_ts = 216.606064 last_seq = 1651 current_ts = 216.623077 current_received_ts = 216.622665 current_seq = 1652 count = 140 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 216.623077 last_received_ts = 216.622665 last_seq = 1652 current_ts = 216.639755 current_received_ts = 216.639404 current_seq = 1653 count = 141 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.639755 last_received_ts = 216.639404 last_seq = 1653 current_ts = 216.656418 current_received_ts = 216.656097 current_seq = 1654 count = 142 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.656418 last_received_ts = 216.656097 last_seq = 1654 current_ts = 216.673080 current_received_ts = 216.672714 current_seq = 1655 count = 143 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 30us (kms_flip:6695) DEBUG: name = flip last_ts = 216.673080 last_received_ts = 216.672714 last_seq = 1655 current_ts = 216.689743 current_received_ts = 216.689377 current_seq = 1656 count = 144 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.689743 last_received_ts = 216.689377 last_seq = 1656 current_ts = 216.706421 current_received_ts = 216.706070 current_seq = 1657 count = 145 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.706421 last_received_ts = 216.706070 last_seq = 1657 current_ts = 216.723083 current_received_ts = 216.722717 current_seq = 1658 count = 146 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.723083 last_received_ts = 216.722717 last_seq = 1658 current_ts = 216.739761 current_received_ts = 216.739380 current_seq = 1659 count = 147 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.739761 last_received_ts = 216.739380 last_seq = 1659 current_ts = 216.756424 current_received_ts = 216.756073 current_seq = 1660 count = 148 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.756424 last_received_ts = 216.756073 last_seq = 1660 current_ts = 216.773087 current_received_ts = 216.772720 current_seq = 1661 count = 149 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 26us (kms_flip:6695) DEBUG: name = flip last_ts = 216.773087 last_received_ts = 216.772720 last_seq = 1661 current_ts = 216.789764 current_received_ts = 216.789383 current_seq = 1662 count = 150 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.789764 last_received_ts = 216.789383 last_seq = 1662 current_ts = 216.806427 current_received_ts = 216.806076 current_seq = 1663 count = 151 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 216.806427 last_received_ts = 216.806076 last_seq = 1663 current_ts = 216.823090 current_received_ts = 216.822723 current_seq = 1664 count = 152 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.823090 last_received_ts = 216.822723 last_seq = 1664 current_ts = 216.839767 current_received_ts = 216.839386 current_seq = 1665 count = 153 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 243us (kms_flip:6695) DEBUG: name = flip last_ts = 216.839767 last_received_ts = 216.839386 last_seq = 1665 current_ts = 216.856430 current_received_ts = 216.856064 current_seq = 1666 count = 154 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 229us (kms_flip:6695) DEBUG: name = flip last_ts = 216.856430 last_received_ts = 216.856064 last_seq = 1666 current_ts = 216.873093 current_received_ts = 216.872726 current_seq = 1667 count = 155 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 238us (kms_flip:6695) DEBUG: name = flip last_ts = 216.873093 last_received_ts = 216.872726 last_seq = 1667 current_ts = 216.889755 current_received_ts = 216.889389 current_seq = 1668 count = 156 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.889755 last_received_ts = 216.889389 last_seq = 1668 current_ts = 216.906433 current_received_ts = 216.906082 current_seq = 1669 count = 157 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 208us (kms_flip:6695) DEBUG: name = flip last_ts = 216.906433 last_received_ts = 216.906082 last_seq = 1669 current_ts = 216.923096 current_received_ts = 216.922714 current_seq = 1670 count = 158 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 24us (kms_flip:6695) DEBUG: name = flip last_ts = 216.923096 last_received_ts = 216.922714 last_seq = 1670 current_ts = 216.939758 current_received_ts = 216.939407 current_seq = 1671 count = 159 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 28us (kms_flip:6695) DEBUG: name = flip last_ts = 216.939758 last_received_ts = 216.939407 last_seq = 1671 current_ts = 216.956436 current_received_ts = 216.956070 current_seq = 1672 count = 160 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.956436 last_received_ts = 216.956070 last_seq = 1672 current_ts = 216.973099 current_received_ts = 216.972656 current_seq = 1673 count = 161 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.973099 last_received_ts = 216.972656 last_seq = 1673 current_ts = 216.989777 current_received_ts = 216.989395 current_seq = 1674 count = 162 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 25us (kms_flip:6695) DEBUG: name = flip last_ts = 216.989777 last_received_ts = 216.989395 last_seq = 1674 current_ts = 217.006439 current_received_ts = 217.005981 current_seq = 1675 count = 163 seq_step = 1 (kms_flip:6695) DEBUG: Vblank took 738us (kms_flip:6695) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:6695) CRITICAL: Failed assertion: end - start < 500 (kms_flip:6695) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:6695) igt_core-INFO: Stack trace: (kms_flip:6695) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:6695) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:6695) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() (kms_flip:6695) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() (kms_flip:6695) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() (kms_flip:6695) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:6695) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:6695) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-DP2: FAIL (3.630s)
Dmesg	<6> [214.235529] [IGT] kms_flip: starting dynamic subtest B-DP2 <7> [214.238400] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:557] <7> [214.239965] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:559] <7> [214.289419] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [214.289497] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [214.289626] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [214.289735] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [214.289839] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [214.289939] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 5190451/8388608 link 288358/524288, found tu 0, data 0/0 link 0/0) <7> [214.290038] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000) <7> [214.290152] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [214.290304] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [214.290473] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [214.290606] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [214.290722] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [214.290833] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [214.290942] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [214.291054] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [214.291182] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [214.291291] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [214.291400] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [214.291510] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [214.291615] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [214.291719] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [214.291823] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [214.291927] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [214.292032] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [214.292148] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [214.292253] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [214.292358] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [214.292460] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [214.292563] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [214.292667] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [214.292770] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [214.292874] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [214.292978] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [214.293086] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [214.293188] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [214.293291] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no) <7> [214.293394] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0) <7> [214.293495] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [214.293599] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [214.293701] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 270000, found 0) <7> [214.293804] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [214.293908] xe 0000:03:00.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing TC PLL 2 <7> [214.294043] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [214.294153] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [214.294264] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4037 - 4096) -> ( 0 - 0), size 59 -> 0 <7> [214.294352] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 192000 kHz -> 0 kHz <7> [214.294493] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset] <7> [214.294604] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [214.294714] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [214.294824] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [214.294933] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [214.295042] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [214.295167] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [214.295851] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Disable audio codec on [CRTC:151:pipe A] <7> [214.313348] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [214.330357] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2 <7> [214.333234] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disable TC PLL 2 (active 0x1, on? 1) for [CRTC:151:pipe A] <7> [214.335737] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disabling TC PLL 2 <7> [214.336593] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:507:DDI TC1/PHY F] <7> [214.337103] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST A] <7> [214.337586] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST B] <7> [214.338058] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST C] <7> [214.338567] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:512:DP-MST D] <7> [214.339013] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:526:DDI TC2/PHY G] <7> [214.339685] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST A] <7> [214.340076] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST B] <7> [214.340459] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST C] <7> [214.340841] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:531:DP-MST D] <7> [214.341237] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:538:DDI TC3/PHY H] <7> [214.341581] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:542:DDI TC4/PHY I] <7> [214.341911] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST A] <7> [214.342278] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST B] <7> [214.342590] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST C] <7> [214.342877] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:547:DP-MST D] <7> [214.343179] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:527:DP-2] <7> [214.343681] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no) <7> [214.344141] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [214.344366] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [214.344942] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [214.345435] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [214.345917] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2 <7> [214.346405] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [214.347035] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C] <7> [214.347637] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe B] <7> [214.347804] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D] <7> [214.347968] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C] <7> [214.348000] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:527:DP-2] <7> [214.348115] xe 0000:03:00.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:526:DDI TC2/PHY G][CRTC:269:pipe C] DP link limits: pixel clock 148500 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 36 min link_bpp 18.0000 max link_bpp 36.0000 <7> [214.348298] xe 0000:03:00.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 270000 bpp input 36 compressed 0.0000 HDR no link rate required 668250 available 1080000 <7> [214.348475] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] hw max bpp: 36, pipe bpp: 36, dithering: 0 <7> [214.348653] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:526:DDI TC2/PHY G] [CRTC:269:pipe C] <7> [214.348828] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.enable (expected no, found yes) <7> [214.348995] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.active (expected no, found yes) <7> [214.349170] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2) <7> [214.349328] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in lane_count (expected 0, found 4) <7> [214.349478] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 5190451/8388608 link 288358/524288) <7> [214.349624] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000080) <7> [214.349767] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [214.349911] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [214.350044] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [214.350190] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [214.350318] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [214.350441] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [214.350561] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [214.350677] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [214.350801] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [214.350918] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [214.351034] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [214.351154] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [214.351261] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [214.351374] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [214.351484] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [214.351590] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [214.351691] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [214.351791] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [214.351890] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [214.351990] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [214.352092] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [214.352188] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [214.352284] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [214.352380] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [214.352476] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [214.352572] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [214.352668] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [214.352764] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [214.352860] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in enhanced_framing (expected no, found yes) <7> [214.352960] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in dpll_hw_state <7> [214.353056] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected: <7> [214.353162] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [214.353258] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state: <7> [214.353354] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000 <7> [214.353451] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [214.353547] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x40e8 <7> [214.353643] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x7d20 <7> [214.353738] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0x0a06 <7> [214.353834] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0x8f1c <7> [214.353928] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x0000 <7> [214.354023] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x0000 <7> [214.354125] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2200 <7> [214.354221] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0xffff <7> [214.354316] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x0400 <7> [214.354411] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000 <7> [214.354507] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0001 <7> [214.354600] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00 <7> [214.354697] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found: <7> [214.354797] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [214.354896] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state: <7> [214.354995] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x4800, tx[2] = 0x0000 <7> [214.355098] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [214.355197] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x308c <7> [214.355293] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x2110 <7> [214.355391] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0xcc9c <7> [214.355487] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0xbfc1 <7> [214.355583] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x4b9a <7> [214.355679] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x3f81 <7> [214.355775] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2000 <7> [214.355870] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0x0001 <7> [214.355965] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x5000 <7> [214.356059] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000 <7> [214.356164] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000 <7> [214.356259] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x42, hdmi rate: 0x00 <7> [214.356356] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 36) <7> [214.356454] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [214.356550] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [214.356656] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in port_clock (expected 0, found 270000) <7> [214.356758] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] fastset requirement not met, forcing full modeset <7> [214.356876] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no <7> [214.356960] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:269:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4 <7> [214.357066] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:153:plane 1C] ddb ( 0 - 0) -> ( 0 - 1989), size 0 -> 1989 <7> [214.357143] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:263:cursor C] ddb ( 0 - 0) -> (1989 - 2048), size 0 -> 59 <7> [214.357217] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [214.357290] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 9, 9, 17, 17, 17, 17, 0, 15, 0 <7> [214.357366] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 139, 139, 261, 261, 261, 261, 137, 230, 244 <7> [214.357443] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 245, 245, 367, 367, 0, 0, 138, 306, 306 <7> [214.357528] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:269:pipe C] data rate 594000 num active planes 1 <7> [214.357635] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 624 qgv_peak_bw: 48000 <7> [214.357741] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 624 qgv_peak_bw: 48000 <7> [214.357843] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 624 <7> [214.357955] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:269:pipe C] min cdclk: 0 kHz -> 192000 kHz <7> [214.358087] xe 0000:03:00.0: [drm:intel_find_dpll [xe]] [CRTC:269:pipe C] allocated TC PLL 2 <7> [214.358189] xe 0000:03:00.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:269:pipe C] reserving TC PLL 2 <7> [214.358289] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:269:pipe C] enable: yes [modeset] <7> [214.358398] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB <7> [214.358505] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 36, dithering: 0 <7> [214.358610] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [214.358713] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [214.358817] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [214.358918] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [214.359018] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 5190451, data_n: 8388608, link_m: 288358, link_n: 524288, tu: 64 <7> [214.359127] xe 0000:03:00.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> [214.359227] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled <7> [214.359326] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [214.359425] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled <7> [214.359523] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0 <7> [214.359621] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 0, infoframes enabled: 0x0 <7> [214.359719] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00 <7> [214.359818] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11 <7> [214.359918] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 17 50 51 07 00 00 00 00 <7> [214.360021] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [214.360130] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [214.360228] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 42 vsync start: 41, vsync end: 36 <7> [214.360328] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1083, vmax vblank: 1083, vmin vtotal: 1125, vmax vtotal: 1125 <7> [214.360427] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [214.360523] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [214.360621] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [214.360721] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [214.360823] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 <7> [214.360924] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [214.361023] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 270000, pixel rate 148500, min cdclk 192000, min voltage level 0 <7> [214.361128] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0 <7> [214.361225] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [214.361323] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe src: 1920x1080+0+0 <7> [214.361421] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [214.361517] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [214.361615] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [214.361710] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [214.361806] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] c20pll_hw_state: <7> [214.361901] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] tx[0] = 0xbe88, tx[1] = 0x4800, tx[2] = 0x0000 <7> [214.361997] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [214.362098] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[0] = 0x308c <7> [214.362194] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[1] = 0x2110 <7> [214.362289] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[2] = 0xcc9c <7> [214.362386] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[3] = 0xbfc1 <7> [214.362482] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[4] = 0x4b9a <7> [214.362578] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[5] = 0x3f81 <7> [214.362674] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[6] = 0x2000 <7> [214.362769] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[7] = 0x0001 <7> [214.362865] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[8] = 0x5000 <7> [214.362969] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[9] = 0x0000 <7> [214.363073] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[10] = 0x0000 <7> [214.363173] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vdr: custom width: 0x00, serdes rate: 0x42, hdmi rate: 0x00 <7> [214.363271] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [214.363368] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [214.363465] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [214.363561] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [214.363658] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [214.363754] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [214.363851] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [214.363947] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [214.364043] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [214.364148] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [214.364244] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [214.364341] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [214.364439] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:153:plane 1C] fb: [FB:557] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [214.364537] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [214.364636] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [214.364735] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:183:plane 2C] fb: [NOFB], visible: no <7> [214.364838] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:213:plane 3C] fb: [NOFB], visible: no <7> [214.364940] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:243:plane 4C] fb: [NOFB], visible: no <7> [214.365038] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:253:plane 5C] fb: [NOFB], visible: no <7> [214.365173] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:263:cursor C] fb: [NOFB], visible: no <7> [214.365791] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2 <7> [214.365905] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_C <7> [214.366030] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000) <7> [214.366150] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:507:DDI TC1/PHY F] <7> [214.366244] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST A] <7> [214.366335] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST B] <7> [214.366427] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST C] <7> [214.366520] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:512:DP-MST D] <7> [214.366609] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:526:DDI TC2/PHY G] <7> [214.366697] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST A] <7> [214.366789] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST B] <7> [214.366876] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST C] <7> [214.366963] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:531:DP-MST D] <7> [214.367046] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:538:DDI TC3/PHY H] <7> [214.367139] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:542:DDI TC4/PHY I] <7> [214.367225] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST A] <7> [214.367319] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST B] <7> [214.367407] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST C] <7> [214.367497] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:547:DP-MST D] <7> [214.367596] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd <7> [214.367766] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no) <7> [214.367867] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enable TC PLL 2 (active 0x4, on? 0) for [CRTC:269:pipe C] <7> [214.367964] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enabling TC PLL 2 <7> [214.372087] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01 <7> [214.376838] xe 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00 <7> [214.377861] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01 <7> [214.378308] xe 0000:03:00.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using LINK_BW_SET value 0a <7> [214.379818] xe 0000:03:00.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [214.380382] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS1 <7> [214.386964] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Clock recovery OK <7> [214.387090] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS3 <7> [214.392963] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Channel EQ done. DP Training successful <7> [214.393175] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Link Training passed at link rate = 270000, lane count = 4 <7> [214.394487] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe C <7> [214.428638] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Enable audio codec on [CRTC:269:pipe C], 40 bytes ELD <7> [214.445435] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:527:DP-2] <7> [214.446323] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:269:pipe C] <7> [214.503219] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2 <7> [216.407331] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2 <7> [216.510103] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2 <6> [217.873280] [IGT] kms_flip: finished subtest B-DP2, FAIL

Detail

Value

Duration

3.63 seconds

Hostname

shard-bmg-9

Igt-Version

IGT-Version: 2.4-g9a23f360a (x86_64) (Linux: 7.1.0-rc2-lgci-xe-xe-5018-36eddf6e5c9411ad9-debug+ x86_64)

Out

Starting dynamic subtest: B-DP2
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c: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 B-DP2: FAIL (3.630s)

Err

Starting dynamic subtest: B-DP2
(kms_flip:6695) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:6695) CRITICAL: Failed assertion: end - start < 500
(kms_flip:6695) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-DP2 failed.
**** DEBUG ****
(kms_flip:6695) DEBUG: Vblank took 244us
(kms_flip:6695) DEBUG: name = flip
last_ts = 214.989670
last_received_ts = 214.989288
last_seq = 1554
current_ts = 215.006332
current_received_ts = 215.005966
current_seq = 1555
count = 43
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 254us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.006332
last_received_ts = 215.005966
last_seq = 1555
current_ts = 215.022995
current_received_ts = 215.022629
current_seq = 1556
count = 44
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 237us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.022995
last_received_ts = 215.022629
last_seq = 1556
current_ts = 215.039673
current_received_ts = 215.039291
current_seq = 1557
count = 45
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 243us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.039673
last_received_ts = 215.039291
last_seq = 1557
current_ts = 215.056335
current_received_ts = 215.055969
current_seq = 1558
count = 46
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.056335
last_received_ts = 215.055969
last_seq = 1558
current_ts = 215.072998
current_received_ts = 215.072632
current_seq = 1559
count = 47
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 231us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.072998
last_received_ts = 215.072632
last_seq = 1559
current_ts = 215.089676
current_received_ts = 215.089294
current_seq = 1560
count = 48
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 239us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.089676
last_received_ts = 215.089294
last_seq = 1560
current_ts = 215.106339
current_received_ts = 215.106110
current_seq = 1561
count = 49
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 39us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.106339
last_received_ts = 215.106110
last_seq = 1561
current_ts = 215.123016
current_received_ts = 215.122757
current_seq = 1562
count = 50
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 38us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.123016
last_received_ts = 215.122757
last_seq = 1562
current_ts = 215.139664
current_received_ts = 215.139313
current_seq = 1563
count = 51
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 28us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.139664
last_received_ts = 215.139313
last_seq = 1563
current_ts = 215.156342
current_received_ts = 215.155975
current_seq = 1564
count = 52
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 250us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.156342
last_received_ts = 215.155975
last_seq = 1564
current_ts = 215.173004
current_received_ts = 215.172638
current_seq = 1565
count = 53
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 27us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.173004
last_received_ts = 215.172638
last_seq = 1565
current_ts = 215.189667
current_received_ts = 215.189301
current_seq = 1566
count = 54
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.189667
last_received_ts = 215.189301
last_seq = 1566
current_ts = 215.206345
current_received_ts = 215.205963
current_seq = 1567
count = 55
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 42us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.206345
last_received_ts = 215.205963
last_seq = 1567
current_ts = 215.223007
current_received_ts = 215.222641
current_seq = 1568
count = 56
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.223007
last_received_ts = 215.222641
last_seq = 1568
current_ts = 215.239685
current_received_ts = 215.239304
current_seq = 1569
count = 57
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.239685
last_received_ts = 215.239304
last_seq = 1569
current_ts = 215.256348
current_received_ts = 215.255966
current_seq = 1570
count = 58
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 44us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.256348
last_received_ts = 215.255966
last_seq = 1570
current_ts = 215.273010
current_received_ts = 215.272644
current_seq = 1571
count = 59
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 27us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.273010
last_received_ts = 215.272644
last_seq = 1571
current_ts = 215.289688
current_received_ts = 215.289307
current_seq = 1572
count = 60
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.289688
last_received_ts = 215.289307
last_seq = 1572
current_ts = 215.306351
current_received_ts = 215.305984
current_seq = 1573
count = 61
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 41us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.306351
last_received_ts = 215.305984
last_seq = 1573
current_ts = 215.323013
current_received_ts = 215.322571
current_seq = 1574
count = 62
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.323013
last_received_ts = 215.322571
last_seq = 1574
current_ts = 215.339676
current_received_ts = 215.339310
current_seq = 1575
count = 63
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.339676
last_received_ts = 215.339310
last_seq = 1575
current_ts = 215.356354
current_received_ts = 215.355972
current_seq = 1576
count = 64
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 42us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.356354
last_received_ts = 215.355972
last_seq = 1576
current_ts = 215.373016
current_received_ts = 215.372574
current_seq = 1577
count = 65
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.373016
last_received_ts = 215.372574
last_seq = 1577
current_ts = 215.389679
current_received_ts = 215.389236
current_seq = 1578
count = 66
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.389679
last_received_ts = 215.389236
last_seq = 1578
current_ts = 215.406357
current_received_ts = 215.405975
current_seq = 1579
count = 67
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 42us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.406357
last_received_ts = 215.405975
last_seq = 1579
current_ts = 215.423019
current_received_ts = 215.422531
current_seq = 1580
count = 68
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.423019
last_received_ts = 215.422531
last_seq = 1580
current_ts = 215.439682
current_received_ts = 215.439240
current_seq = 1581
count = 69
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.439682
last_received_ts = 215.439240
last_seq = 1581
current_ts = 215.456360
current_received_ts = 215.455978
current_seq = 1582
count = 70
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 47us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.456360
last_received_ts = 215.455978
last_seq = 1582
current_ts = 215.473022
current_received_ts = 215.472656
current_seq = 1583
count = 71
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.473022
last_received_ts = 215.472656
last_seq = 1583
current_ts = 215.489685
current_received_ts = 215.489319
current_seq = 1584
count = 72
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.489685
last_received_ts = 215.489319
last_seq = 1584
current_ts = 215.506363
current_received_ts = 215.505981
current_seq = 1585
count = 73
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 60us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.506363
last_received_ts = 215.505981
last_seq = 1585
current_ts = 215.523026
current_received_ts = 215.522659
current_seq = 1586
count = 74
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.523026
last_received_ts = 215.522659
last_seq = 1586
current_ts = 215.539703
current_received_ts = 215.539322
current_seq = 1587
count = 75
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.539703
last_received_ts = 215.539322
last_seq = 1587
current_ts = 215.556366
current_received_ts = 215.556046
current_seq = 1588
count = 76
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 37us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.556366
last_received_ts = 215.556046
last_seq = 1588
current_ts = 215.573029
current_received_ts = 215.572662
current_seq = 1589
count = 77
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 28us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.573029
last_received_ts = 215.572662
last_seq = 1589
current_ts = 215.589691
current_received_ts = 215.589325
current_seq = 1590
count = 78
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 27us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.589691
last_received_ts = 215.589325
last_seq = 1590
current_ts = 215.606369
current_received_ts = 215.605988
current_seq = 1591
count = 79
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.606369
last_received_ts = 215.605988
last_seq = 1591
current_ts = 215.623032
current_received_ts = 215.622589
current_seq = 1592
count = 80
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.623032
last_received_ts = 215.622589
last_seq = 1592
current_ts = 215.639694
current_received_ts = 215.639252
current_seq = 1593
count = 81
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.639694
last_received_ts = 215.639252
last_seq = 1593
current_ts = 215.656372
current_received_ts = 215.655991
current_seq = 1594
count = 82
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.656372
last_received_ts = 215.655991
last_seq = 1594
current_ts = 215.673035
current_received_ts = 215.672592
current_seq = 1595
count = 83
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.673035
last_received_ts = 215.672592
last_seq = 1595
current_ts = 215.689697
current_received_ts = 215.689331
current_seq = 1596
count = 84
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 235us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.689697
last_received_ts = 215.689331
last_seq = 1596
current_ts = 215.706375
current_received_ts = 215.705994
current_seq = 1597
count = 85
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 230us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.706375
last_received_ts = 215.705994
last_seq = 1597
current_ts = 215.723038
current_received_ts = 215.722656
current_seq = 1598
count = 86
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 240us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.723038
last_received_ts = 215.722656
last_seq = 1598
current_ts = 215.739700
current_received_ts = 215.739334
current_seq = 1599
count = 87
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 248us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.739700
last_received_ts = 215.739334
last_seq = 1599
current_ts = 215.756378
current_received_ts = 215.755997
current_seq = 1600
count = 88
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 233us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.756378
last_received_ts = 215.755997
last_seq = 1600
current_ts = 215.773041
current_received_ts = 215.772659
current_seq = 1601
count = 89
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 246us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.773041
last_received_ts = 215.772659
last_seq = 1601
current_ts = 215.789703
current_received_ts = 215.789337
current_seq = 1602
count = 90
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 246us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.789703
last_received_ts = 215.789337
last_seq = 1602
current_ts = 215.806366
current_received_ts = 215.806000
current_seq = 1603
count = 91
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 223us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.806366
last_received_ts = 215.806000
last_seq = 1603
current_ts = 215.823044
current_received_ts = 215.822662
current_seq = 1604
count = 92
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.823044
last_received_ts = 215.822662
last_seq = 1604
current_ts = 215.839722
current_received_ts = 215.839325
current_seq = 1605
count = 93
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.839722
last_received_ts = 215.839325
last_seq = 1605
current_ts = 215.856384
current_received_ts = 215.856003
current_seq = 1606
count = 94
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.856384
last_received_ts = 215.856003
last_seq = 1606
current_ts = 215.873047
current_received_ts = 215.872665
current_seq = 1607
count = 95
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.873047
last_received_ts = 215.872665
last_seq = 1607
current_ts = 215.889709
current_received_ts = 215.889328
current_seq = 1608
count = 96
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.889709
last_received_ts = 215.889328
last_seq = 1608
current_ts = 215.906387
current_received_ts = 215.906036
current_seq = 1609
count = 97
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 212us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.906387
last_received_ts = 215.906036
last_seq = 1609
current_ts = 215.923050
current_received_ts = 215.922668
current_seq = 1610
count = 98
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.923050
last_received_ts = 215.922668
last_seq = 1610
current_ts = 215.939713
current_received_ts = 215.939346
current_seq = 1611
count = 99
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.939713
last_received_ts = 215.939346
last_seq = 1611
current_ts = 215.956375
current_received_ts = 215.956039
current_seq = 1612
count = 100
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 32us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.956375
last_received_ts = 215.956039
last_seq = 1612
current_ts = 215.973053
current_received_ts = 215.972641
current_seq = 1613
count = 101
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.973053
last_received_ts = 215.972641
last_seq = 1613
current_ts = 215.989716
current_received_ts = 215.989273
current_seq = 1614
count = 102
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 28us
(kms_flip:6695) DEBUG: name = flip
last_ts = 215.989716
last_received_ts = 215.989273
last_seq = 1614
current_ts = 216.006378
current_received_ts = 216.006821
current_seq = 1615
count = 103
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 259us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.006378
last_received_ts = 216.006821
last_seq = 1615
current_ts = 216.023056
current_received_ts = 216.022690
current_seq = 1616
count = 104
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.023056
last_received_ts = 216.022690
last_seq = 1616
current_ts = 216.039719
current_received_ts = 216.039352
current_seq = 1617
count = 105
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.039719
last_received_ts = 216.039352
last_seq = 1617
current_ts = 216.056381
current_received_ts = 216.056046
current_seq = 1618
count = 106
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.056381
last_received_ts = 216.056046
last_seq = 1618
current_ts = 216.073044
current_received_ts = 216.072678
current_seq = 1619
count = 107
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.073044
last_received_ts = 216.072678
last_seq = 1619
current_ts = 216.089722
current_received_ts = 216.089523
current_seq = 1620
count = 108
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 45us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.089722
last_received_ts = 216.089523
last_seq = 1620
current_ts = 216.106384
current_received_ts = 216.106049
current_seq = 1621
count = 109
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.106384
last_received_ts = 216.106049
last_seq = 1621
current_ts = 216.123047
current_received_ts = 216.122681
current_seq = 1622
count = 110
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.123047
last_received_ts = 216.122681
last_seq = 1622
current_ts = 216.139725
current_received_ts = 216.139359
current_seq = 1623
count = 111
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.139725
last_received_ts = 216.139359
last_seq = 1623
current_ts = 216.156403
current_received_ts = 216.156036
current_seq = 1624
count = 112
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.156403
last_received_ts = 216.156036
last_seq = 1624
current_ts = 216.173050
current_received_ts = 216.172684
current_seq = 1625
count = 113
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.173050
last_received_ts = 216.172684
last_seq = 1625
current_ts = 216.189743
current_received_ts = 216.189346
current_seq = 1626
count = 114
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.189743
last_received_ts = 216.189346
last_seq = 1626
current_ts = 216.206390
current_received_ts = 216.205902
current_seq = 1627
count = 115
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.206390
last_received_ts = 216.205902
last_seq = 1627
current_ts = 216.223068
current_received_ts = 216.222839
current_seq = 1628
count = 116
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 121us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.223068
last_received_ts = 216.222839
last_seq = 1628
current_ts = 216.239731
current_received_ts = 216.239380
current_seq = 1629
count = 117
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 36us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.239731
last_received_ts = 216.239380
last_seq = 1629
current_ts = 216.256393
current_received_ts = 216.256119
current_seq = 1630
count = 118
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 29us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.256393
last_received_ts = 216.256119
last_seq = 1630
current_ts = 216.273071
current_received_ts = 216.272781
current_seq = 1631
count = 119
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.273071
last_received_ts = 216.272781
last_seq = 1631
current_ts = 216.289734
current_received_ts = 216.289429
current_seq = 1632
count = 120
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.289734
last_received_ts = 216.289429
last_seq = 1632
current_ts = 216.306396
current_received_ts = 216.305984
current_seq = 1633
count = 121
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 44us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.306396
last_received_ts = 216.305984
last_seq = 1633
current_ts = 216.323074
current_received_ts = 216.322632
current_seq = 1634
count = 122
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.323074
last_received_ts = 216.322632
last_seq = 1634
current_ts = 216.339737
current_received_ts = 216.339432
current_seq = 1635
count = 123
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 28us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.339737
last_received_ts = 216.339432
last_seq = 1635
current_ts = 216.356400
current_received_ts = 216.356094
current_seq = 1636
count = 124
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.356400
last_received_ts = 216.356094
last_seq = 1636
current_ts = 216.373077
current_received_ts = 216.372772
current_seq = 1637
count = 125
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.373077
last_received_ts = 216.372772
last_seq = 1637
current_ts = 216.389740
current_received_ts = 216.389435
current_seq = 1638
count = 126
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.389740
last_received_ts = 216.389435
last_seq = 1638
current_ts = 216.406403
current_received_ts = 216.406097
current_seq = 1639
count = 127
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.406403
last_received_ts = 216.406097
last_seq = 1639
current_ts = 216.423065
current_received_ts = 216.422775
current_seq = 1640
count = 128
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.423065
last_received_ts = 216.422775
last_seq = 1640
current_ts = 216.439743
current_received_ts = 216.439392
current_seq = 1641
count = 129
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 233us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.439743
last_received_ts = 216.439392
last_seq = 1641
current_ts = 216.456406
current_received_ts = 216.456055
current_seq = 1642
count = 130
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 230us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.456406
last_received_ts = 216.456055
last_seq = 1642
current_ts = 216.473068
current_received_ts = 216.472778
current_seq = 1643
count = 131
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 32us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.473068
last_received_ts = 216.472778
last_seq = 1643
current_ts = 216.489746
current_received_ts = 216.489380
current_seq = 1644
count = 132
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 27us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.489746
last_received_ts = 216.489380
last_seq = 1644
current_ts = 216.506409
current_received_ts = 216.506073
current_seq = 1645
count = 133
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.506409
last_received_ts = 216.506073
last_seq = 1645
current_ts = 216.523071
current_received_ts = 216.522629
current_seq = 1646
count = 134
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.523071
last_received_ts = 216.522629
last_seq = 1646
current_ts = 216.539749
current_received_ts = 216.539307
current_seq = 1647
count = 135
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.539749
last_received_ts = 216.539307
last_seq = 1647
current_ts = 216.556412
current_received_ts = 216.556061
current_seq = 1648
count = 136
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.556412
last_received_ts = 216.556061
last_seq = 1648
current_ts = 216.573074
current_received_ts = 216.572708
current_seq = 1649
count = 137
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.573074
last_received_ts = 216.572708
last_seq = 1649
current_ts = 216.589752
current_received_ts = 216.589294
current_seq = 1650
count = 138
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.589752
last_received_ts = 216.589294
last_seq = 1650
current_ts = 216.606415
current_received_ts = 216.606064
current_seq = 1651
count = 139
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.606415
last_received_ts = 216.606064
last_seq = 1651
current_ts = 216.623077
current_received_ts = 216.622665
current_seq = 1652
count = 140
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.623077
last_received_ts = 216.622665
last_seq = 1652
current_ts = 216.639755
current_received_ts = 216.639404
current_seq = 1653
count = 141
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.639755
last_received_ts = 216.639404
last_seq = 1653
current_ts = 216.656418
current_received_ts = 216.656097
current_seq = 1654
count = 142
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.656418
last_received_ts = 216.656097
last_seq = 1654
current_ts = 216.673080
current_received_ts = 216.672714
current_seq = 1655
count = 143
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 30us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.673080
last_received_ts = 216.672714
last_seq = 1655
current_ts = 216.689743
current_received_ts = 216.689377
current_seq = 1656
count = 144
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.689743
last_received_ts = 216.689377
last_seq = 1656
current_ts = 216.706421
current_received_ts = 216.706070
current_seq = 1657
count = 145
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.706421
last_received_ts = 216.706070
last_seq = 1657
current_ts = 216.723083
current_received_ts = 216.722717
current_seq = 1658
count = 146
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.723083
last_received_ts = 216.722717
last_seq = 1658
current_ts = 216.739761
current_received_ts = 216.739380
current_seq = 1659
count = 147
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.739761
last_received_ts = 216.739380
last_seq = 1659
current_ts = 216.756424
current_received_ts = 216.756073
current_seq = 1660
count = 148
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.756424
last_received_ts = 216.756073
last_seq = 1660
current_ts = 216.773087
current_received_ts = 216.772720
current_seq = 1661
count = 149
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 26us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.773087
last_received_ts = 216.772720
last_seq = 1661
current_ts = 216.789764
current_received_ts = 216.789383
current_seq = 1662
count = 150
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.789764
last_received_ts = 216.789383
last_seq = 1662
current_ts = 216.806427
current_received_ts = 216.806076
current_seq = 1663
count = 151
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.806427
last_received_ts = 216.806076
last_seq = 1663
current_ts = 216.823090
current_received_ts = 216.822723
current_seq = 1664
count = 152
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.823090
last_received_ts = 216.822723
last_seq = 1664
current_ts = 216.839767
current_received_ts = 216.839386
current_seq = 1665
count = 153
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 243us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.839767
last_received_ts = 216.839386
last_seq = 1665
current_ts = 216.856430
current_received_ts = 216.856064
current_seq = 1666
count = 154
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 229us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.856430
last_received_ts = 216.856064
last_seq = 1666
current_ts = 216.873093
current_received_ts = 216.872726
current_seq = 1667
count = 155
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 238us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.873093
last_received_ts = 216.872726
last_seq = 1667
current_ts = 216.889755
current_received_ts = 216.889389
current_seq = 1668
count = 156
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.889755
last_received_ts = 216.889389
last_seq = 1668
current_ts = 216.906433
current_received_ts = 216.906082
current_seq = 1669
count = 157
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 208us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.906433
last_received_ts = 216.906082
last_seq = 1669
current_ts = 216.923096
current_received_ts = 216.922714
current_seq = 1670
count = 158
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 24us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.923096
last_received_ts = 216.922714
last_seq = 1670
current_ts = 216.939758
current_received_ts = 216.939407
current_seq = 1671
count = 159
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 28us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.939758
last_received_ts = 216.939407
last_seq = 1671
current_ts = 216.956436
current_received_ts = 216.956070
current_seq = 1672
count = 160
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.956436
last_received_ts = 216.956070
last_seq = 1672
current_ts = 216.973099
current_received_ts = 216.972656
current_seq = 1673
count = 161
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.973099
last_received_ts = 216.972656
last_seq = 1673
current_ts = 216.989777
current_received_ts = 216.989395
current_seq = 1674
count = 162
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 25us
(kms_flip:6695) DEBUG: name = flip
last_ts = 216.989777
last_received_ts = 216.989395
last_seq = 1674
current_ts = 217.006439
current_received_ts = 217.005981
current_seq = 1675
count = 163
seq_step = 1
(kms_flip:6695) DEBUG: Vblank took 738us
(kms_flip:6695) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:6695) CRITICAL: Failed assertion: end - start < 500
(kms_flip:6695) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:6695) igt_core-INFO: Stack trace:
(kms_flip:6695) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:6695) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:6695) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:6695) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:6695) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:6695) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:6695) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:6695) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-DP2: FAIL (3.630s)

Dmesg

<6> [214.235529] [IGT] kms_flip: starting dynamic subtest B-DP2

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

<7> [214.239965] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:559]

<7> [214.289419] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [214.293908] xe 0000:03:00.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing TC PLL 2

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

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

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

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

<7> [214.294493] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]

<7> [214.294604] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no

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

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

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

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

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

<7> [214.295851] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Disable audio codec on [CRTC:151:pipe A]

<7> [214.313348] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe A

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

<7> [214.333234] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disable TC PLL 2 (active 0x1, on? 1) for [CRTC:151:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [214.344942] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_A

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

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

<7> [214.346405] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

<7> [214.347035] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C]

<7> [214.347637] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe B]

<7> [214.347804] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]

<7> [214.347968] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C]

<7> [214.348000] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:527:DP-2]

<7> [214.348115] xe 0000:03:00.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:526:DDI TC2/PHY G][CRTC:269:pipe C] DP link limits: pixel clock 148500 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 36 min link_bpp 18.0000 max link_bpp 36.0000

<7> [214.348298] xe 0000:03:00.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 270000 bpp input 36 compressed 0.0000 HDR no link rate required 668250 available 1080000

<7> [214.348475] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] hw max bpp: 36, pipe bpp: 36, dithering: 0

<7> [214.348653] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:526:DDI TC2/PHY G] [CRTC:269:pipe C]

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

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

<7> [214.349170] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [214.352960] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in dpll_hw_state

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [214.356758] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] fastset requirement not met, forcing full modeset

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

<7> [214.356960] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:269:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4

<7> [214.357066] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:153:plane 1C] ddb ( 0 - 0) -> ( 0 - 1989), size 0 -> 1989

<7> [214.357143] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:263:cursor C] ddb ( 0 - 0) -> (1989 - 2048), size 0 -> 59

<7> [214.357217] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm

<7> [214.357290] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 9, 9, 17, 17, 17, 17, 0, 15, 0

<7> [214.357366] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 139, 139, 261, 261, 261, 261, 137, 230, 244

<7> [214.357443] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 245, 245, 367, 367, 0, 0, 138, 306, 306

<7> [214.357528] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:269:pipe C] data rate 594000 num active planes 1

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

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

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

<7> [214.357955] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:269:pipe C] min cdclk: 0 kHz -> 192000 kHz

<7> [214.358087] xe 0000:03:00.0: [drm:intel_find_dpll [xe]] [CRTC:269:pipe C] allocated TC PLL 2

<7> [214.358189] xe 0000:03:00.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:269:pipe C] reserving TC PLL 2

<7> [214.358289] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:269:pipe C] enable: yes [modeset]

<7> [214.358398] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB

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

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

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

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

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

<7> [214.359018] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 5190451, data_n: 8388608, link_m: 288358, link_n: 524288, tu: 64

<7> [214.359127] xe 0000:03:00.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> [214.359227] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled

<7> [214.359326] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled

<7> [214.359425] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled

<7> [214.359523] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0

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

<7> [214.359719] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00

<7> [214.359818] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11

<7> [214.359918] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 17 50 51 07 00 00 00 00

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

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

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

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

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

<7> [214.360523] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [214.360621] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

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

<7> [214.360823] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5

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

<7> [214.361023] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 270000, pixel rate 148500, min cdclk 192000, min voltage level 0

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

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

<7> [214.361323] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe src: 1920x1080+0+0

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

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

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

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

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

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

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

<7> [214.362098] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[0] = 0x308c

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [214.364735] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:183:plane 2C] fb: [NOFB], visible: no

<7> [214.364838] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:213:plane 3C] fb: [NOFB], visible: no

<7> [214.364940] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:243:plane 4C] fb: [NOFB], visible: no

<7> [214.365038] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:253:plane 5C] fb: [NOFB], visible: no

<7> [214.365173] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:263:cursor C] fb: [NOFB], visible: no

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

<7> [214.365905] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_C

<7> [214.366030] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [214.367867] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enable TC PLL 2 (active 0x4, on? 0) for [CRTC:269:pipe C]

<7> [214.367964] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enabling TC PLL 2

<7> [214.372087] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01

<7> [214.376838] xe 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00

<7> [214.377861] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01

<7> [214.378308] xe 0000:03:00.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using LINK_BW_SET value 0a

<7> [214.379818] xe 0000:03:00.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0

<7> [214.380382] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS1

<7> [214.386964] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Clock recovery OK

<7> [214.387090] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS3

<7> [214.392963] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Channel EQ done. DP Training successful

<7> [214.393175] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Link Training passed at link rate = 270000, lane count = 4

<7> [214.394487] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe C

<7> [214.428638] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Enable audio codec on [CRTC:269:pipe C], 40 bytes ELD

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

<7> [214.446323] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:269:pipe C]

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

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

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

<6> [217.873280] [IGT] kms_flip: finished subtest B-DP2, FAIL

Results for igt@kms_flip@flip-vs-expired-vblank-interruptible@b-dp2