igt@kms_flip@flip-vs-expired-vblank-interruptible@b-hdmi-a3 on shard-dg2@CI_DRM

Detail	Value
Duration	7.16 seconds
Hostname	shard-dg2-8
Igt-Version	IGT-Version: 2.3-g33f5420a2 (x86_64) (Linux: 7.0.0-rc4-CI_DRM_18151-gb8e21edb19c3+ x86_64)
Out	Starting dynamic subtest: B-HDMI-A3 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:921 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1887 run_test() #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043() #4 ../tests/kms_flip.c:2043 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest B-HDMI-A3: FAIL (7.164s)
Err	Starting dynamic subtest: B-HDMI-A3 (kms_flip:2841) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2841) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2841) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest B-HDMI-A3 failed. ** DEBUG (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 159.329910 last_received_ts = 159.329437 last_seq = 570 current_ts = 159.346573 current_received_ts = 159.346100 current_seq = 571 count = 296 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.346573 last_received_ts = 159.346100 last_seq = 571 current_ts = 159.363251 current_received_ts = 159.362869 current_seq = 572 count = 297 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.363251 last_received_ts = 159.362869 last_seq = 572 current_ts = 159.379913 current_received_ts = 159.379547 current_seq = 573 count = 298 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 159.379913 last_received_ts = 159.379547 last_seq = 573 current_ts = 159.396591 current_received_ts = 159.396225 current_seq = 574 count = 299 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.396591 last_received_ts = 159.396225 last_seq = 574 current_ts = 159.413254 current_received_ts = 159.412872 current_seq = 575 count = 300 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.413254 last_received_ts = 159.412872 last_seq = 575 current_ts = 159.429932 current_received_ts = 159.429535 current_seq = 576 count = 301 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 159.429932 last_received_ts = 159.429535 last_seq = 576 current_ts = 159.446579 current_received_ts = 159.446213 current_seq = 577 count = 302 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 81us (kms_flip:2841) DEBUG: name = flip last_ts = 159.446579 last_received_ts = 159.446213 last_seq = 577 current_ts = 159.463257 current_received_ts = 159.462875 current_seq = 578 count = 303 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 159.463257 last_received_ts = 159.462875 last_seq = 578 current_ts = 159.479919 current_received_ts = 159.479477 current_seq = 579 count = 304 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 159.479919 last_received_ts = 159.479477 last_seq = 579 current_ts = 159.496582 current_received_ts = 159.496216 current_seq = 580 count = 305 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.496582 last_received_ts = 159.496216 last_seq = 580 current_ts = 159.513260 current_received_ts = 159.512878 current_seq = 581 count = 306 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.513260 last_received_ts = 159.512878 last_seq = 581 current_ts = 159.529907 current_received_ts = 159.529404 current_seq = 582 count = 307 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.529907 last_received_ts = 159.529404 last_seq = 582 current_ts = 159.546585 current_received_ts = 159.546219 current_seq = 583 count = 308 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.546585 last_received_ts = 159.546219 last_seq = 583 current_ts = 159.563248 current_received_ts = 159.562866 current_seq = 584 count = 309 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.563248 last_received_ts = 159.562866 last_seq = 584 current_ts = 159.579926 current_received_ts = 159.579559 current_seq = 585 count = 310 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.579926 last_received_ts = 159.579559 last_seq = 585 current_ts = 159.596588 current_received_ts = 159.596222 current_seq = 586 count = 311 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.596588 last_received_ts = 159.596222 last_seq = 586 current_ts = 159.613266 current_received_ts = 159.612869 current_seq = 587 count = 312 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.613266 last_received_ts = 159.612869 last_seq = 587 current_ts = 159.629929 current_received_ts = 159.629547 current_seq = 588 count = 313 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.629929 last_received_ts = 159.629547 last_seq = 588 current_ts = 159.646591 current_received_ts = 159.646225 current_seq = 589 count = 314 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 159.646591 last_received_ts = 159.646225 last_seq = 589 current_ts = 159.663254 current_received_ts = 159.662872 current_seq = 590 count = 315 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.663254 last_received_ts = 159.662872 last_seq = 590 current_ts = 159.679916 current_received_ts = 159.679550 current_seq = 591 count = 316 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.679916 last_received_ts = 159.679550 last_seq = 591 current_ts = 159.696579 current_received_ts = 159.696213 current_seq = 592 count = 317 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.696579 last_received_ts = 159.696213 last_seq = 592 current_ts = 159.713257 current_received_ts = 159.712814 current_seq = 593 count = 318 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 159.713257 last_received_ts = 159.712814 last_seq = 593 current_ts = 159.729935 current_received_ts = 159.729538 current_seq = 594 count = 319 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.729935 last_received_ts = 159.729538 last_seq = 594 current_ts = 159.746582 current_received_ts = 159.746216 current_seq = 595 count = 320 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.746582 last_received_ts = 159.746216 last_seq = 595 current_ts = 159.763260 current_received_ts = 159.762909 current_seq = 596 count = 321 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.763260 last_received_ts = 159.762909 last_seq = 596 current_ts = 159.779922 current_received_ts = 159.779541 current_seq = 597 count = 322 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 159.779922 last_received_ts = 159.779541 last_seq = 597 current_ts = 159.796585 current_received_ts = 159.796219 current_seq = 598 count = 323 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.796585 last_received_ts = 159.796219 last_seq = 598 current_ts = 159.813248 current_received_ts = 159.812881 current_seq = 599 count = 324 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.813248 last_received_ts = 159.812881 last_seq = 599 current_ts = 159.829926 current_received_ts = 159.829575 current_seq = 600 count = 325 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 55us (kms_flip:2841) DEBUG: name = flip last_ts = 159.829926 last_received_ts = 159.829575 last_seq = 600 current_ts = 159.846588 current_received_ts = 159.846115 current_seq = 601 count = 326 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.846588 last_received_ts = 159.846115 last_seq = 601 current_ts = 159.863266 current_received_ts = 159.862885 current_seq = 602 count = 327 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.863266 last_received_ts = 159.862885 last_seq = 602 current_ts = 159.879929 current_received_ts = 159.879547 current_seq = 603 count = 328 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.879929 last_received_ts = 159.879547 last_seq = 603 current_ts = 159.896606 current_received_ts = 159.896210 current_seq = 604 count = 329 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 159.896606 last_received_ts = 159.896210 last_seq = 604 current_ts = 159.913269 current_received_ts = 159.912888 current_seq = 605 count = 330 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.913269 last_received_ts = 159.912888 last_seq = 605 current_ts = 159.929932 current_received_ts = 159.929520 current_seq = 606 count = 331 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.929932 last_received_ts = 159.929520 last_seq = 606 current_ts = 159.946594 current_received_ts = 159.946213 current_seq = 607 count = 332 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 159.946594 last_received_ts = 159.946213 last_seq = 607 current_ts = 159.963272 current_received_ts = 159.962875 current_seq = 608 count = 333 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.963272 last_received_ts = 159.962875 last_seq = 608 current_ts = 159.979919 current_received_ts = 159.979507 current_seq = 609 count = 334 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.979919 last_received_ts = 159.979507 last_seq = 609 current_ts = 159.996597 current_received_ts = 159.996216 current_seq = 610 count = 335 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 159.996597 last_received_ts = 159.996216 last_seq = 610 current_ts = 160.013275 current_received_ts = 160.012878 current_seq = 611 count = 336 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.013275 last_received_ts = 160.012878 last_seq = 611 current_ts = 160.029938 current_received_ts = 160.029541 current_seq = 612 count = 337 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.029938 last_received_ts = 160.029541 last_seq = 612 current_ts = 160.046600 current_received_ts = 160.046219 current_seq = 613 count = 338 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.046600 last_received_ts = 160.046219 last_seq = 613 current_ts = 160.063263 current_received_ts = 160.062881 current_seq = 614 count = 339 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.063263 last_received_ts = 160.062881 last_seq = 614 current_ts = 160.079926 current_received_ts = 160.079544 current_seq = 615 count = 340 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.079926 last_received_ts = 160.079544 last_seq = 615 current_ts = 160.096588 current_received_ts = 160.096222 current_seq = 616 count = 341 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.096588 last_received_ts = 160.096222 last_seq = 616 current_ts = 160.113266 current_received_ts = 160.112885 current_seq = 617 count = 342 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.113266 last_received_ts = 160.112885 last_seq = 617 current_ts = 160.129929 current_received_ts = 160.129547 current_seq = 618 count = 343 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.129929 last_received_ts = 160.129547 last_seq = 618 current_ts = 160.146591 current_received_ts = 160.146225 current_seq = 619 count = 344 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.146591 last_received_ts = 160.146225 last_seq = 619 current_ts = 160.163269 current_received_ts = 160.162827 current_seq = 620 count = 345 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.163269 last_received_ts = 160.162827 last_seq = 620 current_ts = 160.179932 current_received_ts = 160.179550 current_seq = 621 count = 346 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.179932 last_received_ts = 160.179550 last_seq = 621 current_ts = 160.196594 current_received_ts = 160.196228 current_seq = 622 count = 347 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.196594 last_received_ts = 160.196228 last_seq = 622 current_ts = 160.213272 current_received_ts = 160.212875 current_seq = 623 count = 348 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.213272 last_received_ts = 160.212875 last_seq = 623 current_ts = 160.229935 current_received_ts = 160.229538 current_seq = 624 count = 349 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.229935 last_received_ts = 160.229538 last_seq = 624 current_ts = 160.246597 current_received_ts = 160.246155 current_seq = 625 count = 350 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.246597 last_received_ts = 160.246155 last_seq = 625 current_ts = 160.263275 current_received_ts = 160.262878 current_seq = 626 count = 351 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 160.263275 last_received_ts = 160.262878 last_seq = 626 current_ts = 160.279938 current_received_ts = 160.279556 current_seq = 627 count = 352 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.279938 last_received_ts = 160.279556 last_seq = 627 current_ts = 160.296600 current_received_ts = 160.296249 current_seq = 628 count = 353 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.296600 last_received_ts = 160.296249 last_seq = 628 current_ts = 160.313278 current_received_ts = 160.312881 current_seq = 629 count = 354 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.313278 last_received_ts = 160.312881 last_seq = 629 current_ts = 160.329926 current_received_ts = 160.329559 current_seq = 630 count = 355 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.329926 last_received_ts = 160.329559 last_seq = 630 current_ts = 160.346603 current_received_ts = 160.346222 current_seq = 631 count = 356 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.346603 last_received_ts = 160.346222 last_seq = 631 current_ts = 160.363281 current_received_ts = 160.362885 current_seq = 632 count = 357 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.363281 last_received_ts = 160.362885 last_seq = 632 current_ts = 160.379944 current_received_ts = 160.379486 current_seq = 633 count = 358 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.379944 last_received_ts = 160.379486 last_seq = 633 current_ts = 160.396606 current_received_ts = 160.396240 current_seq = 634 count = 359 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.396606 last_received_ts = 160.396240 last_seq = 634 current_ts = 160.413269 current_received_ts = 160.412888 current_seq = 635 count = 360 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.413269 last_received_ts = 160.412888 last_seq = 635 current_ts = 160.429947 current_received_ts = 160.429474 current_seq = 636 count = 361 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.429947 last_received_ts = 160.429474 last_seq = 636 current_ts = 160.446609 current_received_ts = 160.446228 current_seq = 637 count = 362 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.446609 last_received_ts = 160.446228 last_seq = 637 current_ts = 160.463272 current_received_ts = 160.462891 current_seq = 638 count = 363 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.463272 last_received_ts = 160.462891 last_seq = 638 current_ts = 160.479935 current_received_ts = 160.479553 current_seq = 639 count = 364 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.479935 last_received_ts = 160.479553 last_seq = 639 current_ts = 160.496613 current_received_ts = 160.496246 current_seq = 640 count = 365 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.496613 last_received_ts = 160.496246 last_seq = 640 current_ts = 160.513260 current_received_ts = 160.512894 current_seq = 641 count = 366 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.513260 last_received_ts = 160.512894 last_seq = 641 current_ts = 160.529938 current_received_ts = 160.529556 current_seq = 642 count = 367 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.529938 last_received_ts = 160.529556 last_seq = 642 current_ts = 160.546600 current_received_ts = 160.546234 current_seq = 643 count = 368 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.546600 last_received_ts = 160.546234 last_seq = 643 current_ts = 160.563263 current_received_ts = 160.562851 current_seq = 644 count = 369 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.563263 last_received_ts = 160.562851 last_seq = 644 current_ts = 160.579941 current_received_ts = 160.579544 current_seq = 645 count = 370 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.579941 last_received_ts = 160.579544 last_seq = 645 current_ts = 160.596603 current_received_ts = 160.596237 current_seq = 646 count = 371 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.596603 last_received_ts = 160.596237 last_seq = 646 current_ts = 160.613281 current_received_ts = 160.612808 current_seq = 647 count = 372 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.613281 last_received_ts = 160.612808 last_seq = 647 current_ts = 160.629944 current_received_ts = 160.629562 current_seq = 648 count = 373 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 160.629944 last_received_ts = 160.629562 last_seq = 648 current_ts = 160.646606 current_received_ts = 160.646240 current_seq = 649 count = 374 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.646606 last_received_ts = 160.646240 last_seq = 649 current_ts = 160.663284 current_received_ts = 160.662903 current_seq = 650 count = 375 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.663284 last_received_ts = 160.662903 last_seq = 650 current_ts = 160.679947 current_received_ts = 160.679550 current_seq = 651 count = 376 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.679947 last_received_ts = 160.679550 last_seq = 651 current_ts = 160.696609 current_received_ts = 160.696167 current_seq = 652 count = 377 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.696609 last_received_ts = 160.696167 last_seq = 652 current_ts = 160.713287 current_received_ts = 160.712891 current_seq = 653 count = 378 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 160.713287 last_received_ts = 160.712891 last_seq = 653 current_ts = 160.729935 current_received_ts = 160.729553 current_seq = 654 count = 379 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.729935 last_received_ts = 160.729553 last_seq = 654 current_ts = 160.746613 current_received_ts = 160.746246 current_seq = 655 count = 380 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.746613 last_received_ts = 160.746246 last_seq = 655 current_ts = 160.763275 current_received_ts = 160.762894 current_seq = 656 count = 381 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.763275 last_received_ts = 160.762894 last_seq = 656 current_ts = 160.779953 current_received_ts = 160.779556 current_seq = 657 count = 382 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.779953 last_received_ts = 160.779556 last_seq = 657 current_ts = 160.796616 current_received_ts = 160.796265 current_seq = 658 count = 383 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.796616 last_received_ts = 160.796265 last_seq = 658 current_ts = 160.813278 current_received_ts = 160.812897 current_seq = 659 count = 384 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.813278 last_received_ts = 160.812897 last_seq = 659 current_ts = 160.829941 current_received_ts = 160.829559 current_seq = 660 count = 385 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.829941 last_received_ts = 160.829559 last_seq = 660 current_ts = 160.846603 current_received_ts = 160.846237 current_seq = 661 count = 386 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.846603 last_received_ts = 160.846237 last_seq = 661 current_ts = 160.863266 current_received_ts = 160.862900 current_seq = 662 count = 387 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.863266 last_received_ts = 160.862900 last_seq = 662 current_ts = 160.879944 current_received_ts = 160.879501 current_seq = 663 count = 388 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.879944 last_received_ts = 160.879501 last_seq = 663 current_ts = 160.896606 current_received_ts = 160.896240 current_seq = 664 count = 389 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 51us (kms_flip:2841) DEBUG: name = flip last_ts = 160.896606 last_received_ts = 160.896240 last_seq = 664 current_ts = 160.913269 current_received_ts = 160.912903 current_seq = 665 count = 390 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.913269 last_received_ts = 160.912903 last_seq = 665 current_ts = 160.929947 current_received_ts = 160.929443 current_seq = 666 count = 391 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.929947 last_received_ts = 160.929443 last_seq = 666 current_ts = 160.946609 current_received_ts = 160.946243 current_seq = 667 count = 392 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.946609 last_received_ts = 160.946243 last_seq = 667 current_ts = 160.963287 current_received_ts = 160.962906 current_seq = 668 count = 393 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.963287 last_received_ts = 160.962906 last_seq = 668 current_ts = 160.979950 current_received_ts = 160.979584 current_seq = 669 count = 394 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.979950 last_received_ts = 160.979584 last_seq = 669 current_ts = 160.996613 current_received_ts = 160.996246 current_seq = 670 count = 395 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 160.996613 last_received_ts = 160.996246 last_seq = 670 current_ts = 161.013275 current_received_ts = 161.012909 current_seq = 671 count = 396 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.013275 last_received_ts = 161.012909 last_seq = 671 current_ts = 161.029953 current_received_ts = 161.029572 current_seq = 672 count = 397 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.029953 last_received_ts = 161.029572 last_seq = 672 current_ts = 161.046616 current_received_ts = 161.046249 current_seq = 673 count = 398 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.046616 last_received_ts = 161.046249 last_seq = 673 current_ts = 161.063278 current_received_ts = 161.062897 current_seq = 674 count = 399 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.063278 last_received_ts = 161.062897 last_seq = 674 current_ts = 161.079956 current_received_ts = 161.079575 current_seq = 675 count = 400 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.079956 last_received_ts = 161.079575 last_seq = 675 current_ts = 161.096619 current_received_ts = 161.096252 current_seq = 676 count = 401 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.096619 last_received_ts = 161.096252 last_seq = 676 current_ts = 161.113281 current_received_ts = 161.112839 current_seq = 677 count = 402 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.113281 last_received_ts = 161.112839 last_seq = 677 current_ts = 161.129959 current_received_ts = 161.129578 current_seq = 678 count = 403 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 52us (kms_flip:2841) DEBUG: name = flip last_ts = 161.129959 last_received_ts = 161.129578 last_seq = 678 current_ts = 161.146622 current_received_ts = 161.146149 current_seq = 679 count = 404 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 54us (kms_flip:2841) DEBUG: name = flip last_ts = 161.146622 last_received_ts = 161.146149 last_seq = 679 current_ts = 161.163284 current_received_ts = 161.164108 current_seq = 680 count = 405 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 53us (kms_flip:2841) DEBUG: name = flip last_ts = 161.163284 last_received_ts = 161.164108 last_seq = 680 current_ts = 161.179947 current_received_ts = 161.179428 current_seq = 681 count = 406 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 39us (kms_flip:2841) DEBUG: name = flip last_ts = 161.179947 last_received_ts = 161.179428 last_seq = 681 current_ts = 161.196625 current_received_ts = 161.196045 current_seq = 682 count = 407 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 34us (kms_flip:2841) DEBUG: name = flip last_ts = 161.196625 last_received_ts = 161.196045 last_seq = 682 current_ts = 161.213287 current_received_ts = 161.212738 current_seq = 683 count = 408 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 32us (kms_flip:2841) DEBUG: name = flip last_ts = 161.213287 last_received_ts = 161.212738 last_seq = 683 current_ts = 161.229950 current_received_ts = 161.229401 current_seq = 684 count = 409 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 32us (kms_flip:2841) DEBUG: name = flip last_ts = 161.229950 last_received_ts = 161.229401 last_seq = 684 current_ts = 161.246628 current_received_ts = 161.246078 current_seq = 685 count = 410 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 31us (kms_flip:2841) DEBUG: name = flip last_ts = 161.246628 last_received_ts = 161.246078 last_seq = 685 current_ts = 161.263290 current_received_ts = 161.262726 current_seq = 686 count = 411 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 32us (kms_flip:2841) DEBUG: name = flip last_ts = 161.263290 last_received_ts = 161.262726 last_seq = 686 current_ts = 161.279953 current_received_ts = 161.279404 current_seq = 687 count = 412 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 32us (kms_flip:2841) DEBUG: name = flip last_ts = 161.279953 last_received_ts = 161.279404 last_seq = 687 current_ts = 161.296631 current_received_ts = 161.296066 current_seq = 688 count = 413 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 32us (kms_flip:2841) DEBUG: name = flip last_ts = 161.296631 last_received_ts = 161.296066 last_seq = 688 current_ts = 161.313293 current_received_ts = 161.312729 current_seq = 689 count = 414 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 33us (kms_flip:2841) DEBUG: name = flip last_ts = 161.313293 last_received_ts = 161.312729 last_seq = 689 current_ts = 161.329956 current_received_ts = 161.329407 current_seq = 690 count = 415 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 32us (kms_flip:2841) DEBUG: name = flip last_ts = 161.329956 last_received_ts = 161.329407 last_seq = 690 current_ts = 161.346619 current_received_ts = 161.346069 current_seq = 691 count = 416 seq_step = 1 (kms_flip:2841) DEBUG: Vblank took 702us (kms_flip:2841) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926: (kms_flip:2841) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2841) CRITICAL: Last errno: 4, Interrupted system call (kms_flip:2841) igt_core-INFO: Stack trace: (kms_flip:2841) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2841) igt_core-INFO: #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0() (kms_flip:2841) igt_core-INFO: #2 ../tests/kms_flip.c:1887 run_test() (kms_flip:2841) igt_core-INFO: #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043() (kms_flip:2841) igt_core-INFO: #4 ../tests/kms_flip.c:2043 main() (kms_flip:2841) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2841) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2841) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-HDMI-A3: FAIL (7.164s)
Dmesg	<6> [154.543480] [IGT] kms_flip: starting dynamic subtest B-HDMI-A3 <7> [154.544082] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:561] <7> [154.544306] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:586] <7> [154.544792] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.545725] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.576336] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.576852] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.584804] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.585193] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.606744] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.607070] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509 <7> [154.614058] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A] <7> [154.614181] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [154.614374] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [154.614527] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [154.614780] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [154.614984] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000) <7> [154.615138] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [154.615289] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [154.615441] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [154.615600] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [154.615829] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [154.615980] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [154.616131] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [154.616282] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [154.616437] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [154.616612] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [154.616780] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [154.616931] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [154.617082] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [154.617239] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [154.617390] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [154.617543] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [154.617888] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [154.618040] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [154.618192] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [154.618342] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [154.618493] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [154.618760] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [154.618927] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [154.619078] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [154.619228] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [154.619379] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [154.619530] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [154.619725] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [154.619877] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [154.620028] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [154.620179] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [154.620333] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:150:pipe A] fastset requirement not met in port_clock (expected 148500, found 0) <7> [154.620485] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:150:pipe A] fastset requirement not met, forcing full modeset <7> [154.620788] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no <7> [154.620936] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:150:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [154.621107] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:144:cursor A] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0 <7> [154.621284] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:150:pipe A] min cdclk: 74250 kHz -> 0 kHz <7> [154.621434] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz <7> [154.621613] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0 <7> [154.621773] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:150:pipe A] enable: no [modeset] <7> [154.621930] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [NOFB], visible: no <7> [154.622098] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:64:plane 2A] fb: [NOFB], visible: no <7> [154.622269] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:94:plane 3A] fb: [NOFB], visible: no <7> [154.622436] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:124:plane 4A] fb: [NOFB], visible: no <7> [154.622586] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:134:plane 5A] fb: [NOFB], visible: no <7> [154.622782] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:144:cursor A] fb: [NOFB], visible: no <7> [154.623438] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A <7> [154.625343] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D <7> [154.625726] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A] <7> [154.625887] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:508:DP-MST A] <7> [154.626082] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST B] <7> [154.626232] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST C] <7> [154.626398] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST D] <7> [154.626551] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DDI B/PHY B] <7> [154.626725] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST A] <7> [154.626908] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST B] <7> [154.627075] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST C] <7> [154.627227] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST D] <7> [154.627379] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DDI C/PHY C] <7> [154.627532] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST A] <7> [154.627691] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST B] <7> [154.627844] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST C] <7> [154.627999] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST D] <7> [154.628210] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI D/PHY D] <7> [154.628382] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A] <7> [154.628535] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B] <7> [154.628739] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C] <7> [154.628904] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D] <7> [154.629056] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:555:HDMI-A-3] <7> [154.629246] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1 <7> [154.629501] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_A <7> [154.629781] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2 <7> [154.629990] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:150:pipe A] <7> [154.630414] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B] <7> [154.630584] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C] <7> [154.630782] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:504:pipe D] <7> [154.630986] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B] <7> [154.631015] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:555:HDMI-A-3] <7> [154.631089] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:555:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36) <7> [154.631292] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24) <7> [154.631452] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:268:pipe B] hw max bpp: 24, pipe bpp: 24, dithering: 0 <7> [154.631615] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:546:DDI D/PHY D] [CRTC:268:pipe B] <7> [154.631795] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.enable (expected no, found yes) <7> [154.631962] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.active (expected no, found yes) <7> [154.632115] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1) <7> [154.632267] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in lane_count (expected 0, found 4) <7> [154.632433] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040) <7> [154.632589] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [154.632782] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [154.632980] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [154.633130] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [154.633283] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [154.633449] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [154.633611] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [154.633795] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [154.633961] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [154.634140] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [154.634292] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [154.634459] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [154.634632] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [154.634862] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [154.635017] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [154.635171] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [154.635338] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [154.635503] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [154.635676] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [154.635827] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [154.635978] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [154.636128] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [154.636279] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [154.636430] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [154.636580] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [154.636802] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [154.636954] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [154.637104] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [154.637256] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [154.637407] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [154.637559] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [154.637751] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in port_clock (expected 0, found 148500) <7> [154.637963] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:268:pipe B] fastset requirement not met, forcing full modeset <7> [154.638139] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0xf), mbus joined? no->no <7> [154.638286] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:268:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2 <7> [154.638461] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:152:plane 1B] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963 <7> [154.638639] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:262:cursor B] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85 <7> [154.638830] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5,wm6,wm7,*twm, swm, stwm <7> [154.638976] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0 <7> [154.639122] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0 <7> [154.639267] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0 <7> [154.639431] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:268:pipe B] data rate 594000 num active planes 1 <7> [154.639580] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624 <7> [154.639782] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1 <7> [154.639976] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:268:pipe B] min cdclk: 0 kHz -> 74250 kHz <7> [154.640141] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz <7> [154.640290] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0 <7> [154.640440] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:268:pipe B] enable: yes [modeset] <7> [154.640616] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB <7> [154.640840] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0 <7> [154.640990] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid> <7> [154.641140] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [154.641291] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0 <7> [154.641440] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0 <7> [154.641614] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0 <7> [154.641809] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2 <7> [154.641959] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [154.642140] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 41, vsync end: 36 <7> [154.642291] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125 <7> [154.642458] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [154.642632] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [154.642784] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [154.642934] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [154.643099] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 <7> [154.643253] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [154.643408] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 74250 <7> [154.643562] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0 <7> [154.643722] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [154.643876] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [154.644029] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0 <7> [154.644183] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440 <7> [154.644336] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [154.644494] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [154.644658] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [154.644813] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [154.644968] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [154.645121] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [154.645276] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [154.645429] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [154.645583] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [154.645743] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [154.645896] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [154.646049] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [154.646202] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [154.646356] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:152:plane 1B] fb: [FB:561] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [154.646511] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [154.646671] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [154.646827] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:182:plane 2B] fb: [NOFB], visible: no <7> [154.646980] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:212:plane 3B] fb: [NOFB], visible: no <7> [154.647134] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:242:plane 4B] fb: [NOFB], visible: no <7> [154.647293] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:252:plane 5B] fb: [NOFB], visible: no <7> [154.647446] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:262:cursor B] fb: [NOFB], visible: no <7> [154.648048] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2 <7> [154.648230] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_B <7> [154.648434] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A] <7> [154.648588] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:508:DP-MST A] <7> [154.648750] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST B] <7> [154.648904] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST C] <7> [154.649058] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST D] <7> [154.649211] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DDI B/PHY B] <7> [154.649364] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST A] <7> [154.649516] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST B] <7> [154.649676] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST C] <7> [154.649829] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST D] <7> [154.649982] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DDI C/PHY C] <7> [154.650141] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST A] <7> [154.650294] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST B] <7> [154.650447] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST C] <7> [154.650609] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST D] <7> [154.650763] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI D/PHY D] <7> [154.650917] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A] <7> [154.651069] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B] <7> [154.651222] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C] <7> [154.651377] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D] <7> [154.651530] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3 <7> [154.651913] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D <7> [154.652195] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe B <7> [154.671245] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:555:HDMI-A-3] <7> [154.671518] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:268:pipe B] <6> [161.709367] [IGT] kms_flip: finished subtest B-HDMI-A3, FAIL

Detail

Value

Duration

7.16 seconds

Hostname

shard-dg2-8

Igt-Version

IGT-Version: 2.3-g33f5420a2 (x86_64) (Linux: 7.0.0-rc4-CI_DRM_18151-gb8e21edb19c3+ x86_64)

Out

Starting dynamic subtest: B-HDMI-A3
  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:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-HDMI-A3: FAIL (7.164s)

Err

Starting dynamic subtest: B-HDMI-A3
(kms_flip:2841) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2841) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2841) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.329910
last_received_ts = 159.329437
last_seq = 570
current_ts = 159.346573
current_received_ts = 159.346100
current_seq = 571
count = 296
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.346573
last_received_ts = 159.346100
last_seq = 571
current_ts = 159.363251
current_received_ts = 159.362869
current_seq = 572
count = 297
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.363251
last_received_ts = 159.362869
last_seq = 572
current_ts = 159.379913
current_received_ts = 159.379547
current_seq = 573
count = 298
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.379913
last_received_ts = 159.379547
last_seq = 573
current_ts = 159.396591
current_received_ts = 159.396225
current_seq = 574
count = 299
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.396591
last_received_ts = 159.396225
last_seq = 574
current_ts = 159.413254
current_received_ts = 159.412872
current_seq = 575
count = 300
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.413254
last_received_ts = 159.412872
last_seq = 575
current_ts = 159.429932
current_received_ts = 159.429535
current_seq = 576
count = 301
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.429932
last_received_ts = 159.429535
last_seq = 576
current_ts = 159.446579
current_received_ts = 159.446213
current_seq = 577
count = 302
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 81us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.446579
last_received_ts = 159.446213
last_seq = 577
current_ts = 159.463257
current_received_ts = 159.462875
current_seq = 578
count = 303
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.463257
last_received_ts = 159.462875
last_seq = 578
current_ts = 159.479919
current_received_ts = 159.479477
current_seq = 579
count = 304
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.479919
last_received_ts = 159.479477
last_seq = 579
current_ts = 159.496582
current_received_ts = 159.496216
current_seq = 580
count = 305
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.496582
last_received_ts = 159.496216
last_seq = 580
current_ts = 159.513260
current_received_ts = 159.512878
current_seq = 581
count = 306
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.513260
last_received_ts = 159.512878
last_seq = 581
current_ts = 159.529907
current_received_ts = 159.529404
current_seq = 582
count = 307
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.529907
last_received_ts = 159.529404
last_seq = 582
current_ts = 159.546585
current_received_ts = 159.546219
current_seq = 583
count = 308
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.546585
last_received_ts = 159.546219
last_seq = 583
current_ts = 159.563248
current_received_ts = 159.562866
current_seq = 584
count = 309
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.563248
last_received_ts = 159.562866
last_seq = 584
current_ts = 159.579926
current_received_ts = 159.579559
current_seq = 585
count = 310
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.579926
last_received_ts = 159.579559
last_seq = 585
current_ts = 159.596588
current_received_ts = 159.596222
current_seq = 586
count = 311
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.596588
last_received_ts = 159.596222
last_seq = 586
current_ts = 159.613266
current_received_ts = 159.612869
current_seq = 587
count = 312
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.613266
last_received_ts = 159.612869
last_seq = 587
current_ts = 159.629929
current_received_ts = 159.629547
current_seq = 588
count = 313
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.629929
last_received_ts = 159.629547
last_seq = 588
current_ts = 159.646591
current_received_ts = 159.646225
current_seq = 589
count = 314
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.646591
last_received_ts = 159.646225
last_seq = 589
current_ts = 159.663254
current_received_ts = 159.662872
current_seq = 590
count = 315
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.663254
last_received_ts = 159.662872
last_seq = 590
current_ts = 159.679916
current_received_ts = 159.679550
current_seq = 591
count = 316
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.679916
last_received_ts = 159.679550
last_seq = 591
current_ts = 159.696579
current_received_ts = 159.696213
current_seq = 592
count = 317
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.696579
last_received_ts = 159.696213
last_seq = 592
current_ts = 159.713257
current_received_ts = 159.712814
current_seq = 593
count = 318
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.713257
last_received_ts = 159.712814
last_seq = 593
current_ts = 159.729935
current_received_ts = 159.729538
current_seq = 594
count = 319
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.729935
last_received_ts = 159.729538
last_seq = 594
current_ts = 159.746582
current_received_ts = 159.746216
current_seq = 595
count = 320
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.746582
last_received_ts = 159.746216
last_seq = 595
current_ts = 159.763260
current_received_ts = 159.762909
current_seq = 596
count = 321
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.763260
last_received_ts = 159.762909
last_seq = 596
current_ts = 159.779922
current_received_ts = 159.779541
current_seq = 597
count = 322
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.779922
last_received_ts = 159.779541
last_seq = 597
current_ts = 159.796585
current_received_ts = 159.796219
current_seq = 598
count = 323
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.796585
last_received_ts = 159.796219
last_seq = 598
current_ts = 159.813248
current_received_ts = 159.812881
current_seq = 599
count = 324
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.813248
last_received_ts = 159.812881
last_seq = 599
current_ts = 159.829926
current_received_ts = 159.829575
current_seq = 600
count = 325
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 55us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.829926
last_received_ts = 159.829575
last_seq = 600
current_ts = 159.846588
current_received_ts = 159.846115
current_seq = 601
count = 326
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.846588
last_received_ts = 159.846115
last_seq = 601
current_ts = 159.863266
current_received_ts = 159.862885
current_seq = 602
count = 327
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.863266
last_received_ts = 159.862885
last_seq = 602
current_ts = 159.879929
current_received_ts = 159.879547
current_seq = 603
count = 328
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.879929
last_received_ts = 159.879547
last_seq = 603
current_ts = 159.896606
current_received_ts = 159.896210
current_seq = 604
count = 329
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.896606
last_received_ts = 159.896210
last_seq = 604
current_ts = 159.913269
current_received_ts = 159.912888
current_seq = 605
count = 330
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.913269
last_received_ts = 159.912888
last_seq = 605
current_ts = 159.929932
current_received_ts = 159.929520
current_seq = 606
count = 331
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.929932
last_received_ts = 159.929520
last_seq = 606
current_ts = 159.946594
current_received_ts = 159.946213
current_seq = 607
count = 332
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.946594
last_received_ts = 159.946213
last_seq = 607
current_ts = 159.963272
current_received_ts = 159.962875
current_seq = 608
count = 333
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.963272
last_received_ts = 159.962875
last_seq = 608
current_ts = 159.979919
current_received_ts = 159.979507
current_seq = 609
count = 334
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.979919
last_received_ts = 159.979507
last_seq = 609
current_ts = 159.996597
current_received_ts = 159.996216
current_seq = 610
count = 335
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 159.996597
last_received_ts = 159.996216
last_seq = 610
current_ts = 160.013275
current_received_ts = 160.012878
current_seq = 611
count = 336
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.013275
last_received_ts = 160.012878
last_seq = 611
current_ts = 160.029938
current_received_ts = 160.029541
current_seq = 612
count = 337
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.029938
last_received_ts = 160.029541
last_seq = 612
current_ts = 160.046600
current_received_ts = 160.046219
current_seq = 613
count = 338
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.046600
last_received_ts = 160.046219
last_seq = 613
current_ts = 160.063263
current_received_ts = 160.062881
current_seq = 614
count = 339
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.063263
last_received_ts = 160.062881
last_seq = 614
current_ts = 160.079926
current_received_ts = 160.079544
current_seq = 615
count = 340
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.079926
last_received_ts = 160.079544
last_seq = 615
current_ts = 160.096588
current_received_ts = 160.096222
current_seq = 616
count = 341
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.096588
last_received_ts = 160.096222
last_seq = 616
current_ts = 160.113266
current_received_ts = 160.112885
current_seq = 617
count = 342
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.113266
last_received_ts = 160.112885
last_seq = 617
current_ts = 160.129929
current_received_ts = 160.129547
current_seq = 618
count = 343
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.129929
last_received_ts = 160.129547
last_seq = 618
current_ts = 160.146591
current_received_ts = 160.146225
current_seq = 619
count = 344
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.146591
last_received_ts = 160.146225
last_seq = 619
current_ts = 160.163269
current_received_ts = 160.162827
current_seq = 620
count = 345
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.163269
last_received_ts = 160.162827
last_seq = 620
current_ts = 160.179932
current_received_ts = 160.179550
current_seq = 621
count = 346
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.179932
last_received_ts = 160.179550
last_seq = 621
current_ts = 160.196594
current_received_ts = 160.196228
current_seq = 622
count = 347
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.196594
last_received_ts = 160.196228
last_seq = 622
current_ts = 160.213272
current_received_ts = 160.212875
current_seq = 623
count = 348
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.213272
last_received_ts = 160.212875
last_seq = 623
current_ts = 160.229935
current_received_ts = 160.229538
current_seq = 624
count = 349
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.229935
last_received_ts = 160.229538
last_seq = 624
current_ts = 160.246597
current_received_ts = 160.246155
current_seq = 625
count = 350
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.246597
last_received_ts = 160.246155
last_seq = 625
current_ts = 160.263275
current_received_ts = 160.262878
current_seq = 626
count = 351
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.263275
last_received_ts = 160.262878
last_seq = 626
current_ts = 160.279938
current_received_ts = 160.279556
current_seq = 627
count = 352
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.279938
last_received_ts = 160.279556
last_seq = 627
current_ts = 160.296600
current_received_ts = 160.296249
current_seq = 628
count = 353
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.296600
last_received_ts = 160.296249
last_seq = 628
current_ts = 160.313278
current_received_ts = 160.312881
current_seq = 629
count = 354
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.313278
last_received_ts = 160.312881
last_seq = 629
current_ts = 160.329926
current_received_ts = 160.329559
current_seq = 630
count = 355
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.329926
last_received_ts = 160.329559
last_seq = 630
current_ts = 160.346603
current_received_ts = 160.346222
current_seq = 631
count = 356
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.346603
last_received_ts = 160.346222
last_seq = 631
current_ts = 160.363281
current_received_ts = 160.362885
current_seq = 632
count = 357
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.363281
last_received_ts = 160.362885
last_seq = 632
current_ts = 160.379944
current_received_ts = 160.379486
current_seq = 633
count = 358
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.379944
last_received_ts = 160.379486
last_seq = 633
current_ts = 160.396606
current_received_ts = 160.396240
current_seq = 634
count = 359
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.396606
last_received_ts = 160.396240
last_seq = 634
current_ts = 160.413269
current_received_ts = 160.412888
current_seq = 635
count = 360
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.413269
last_received_ts = 160.412888
last_seq = 635
current_ts = 160.429947
current_received_ts = 160.429474
current_seq = 636
count = 361
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.429947
last_received_ts = 160.429474
last_seq = 636
current_ts = 160.446609
current_received_ts = 160.446228
current_seq = 637
count = 362
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.446609
last_received_ts = 160.446228
last_seq = 637
current_ts = 160.463272
current_received_ts = 160.462891
current_seq = 638
count = 363
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.463272
last_received_ts = 160.462891
last_seq = 638
current_ts = 160.479935
current_received_ts = 160.479553
current_seq = 639
count = 364
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.479935
last_received_ts = 160.479553
last_seq = 639
current_ts = 160.496613
current_received_ts = 160.496246
current_seq = 640
count = 365
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.496613
last_received_ts = 160.496246
last_seq = 640
current_ts = 160.513260
current_received_ts = 160.512894
current_seq = 641
count = 366
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.513260
last_received_ts = 160.512894
last_seq = 641
current_ts = 160.529938
current_received_ts = 160.529556
current_seq = 642
count = 367
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.529938
last_received_ts = 160.529556
last_seq = 642
current_ts = 160.546600
current_received_ts = 160.546234
current_seq = 643
count = 368
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.546600
last_received_ts = 160.546234
last_seq = 643
current_ts = 160.563263
current_received_ts = 160.562851
current_seq = 644
count = 369
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.563263
last_received_ts = 160.562851
last_seq = 644
current_ts = 160.579941
current_received_ts = 160.579544
current_seq = 645
count = 370
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.579941
last_received_ts = 160.579544
last_seq = 645
current_ts = 160.596603
current_received_ts = 160.596237
current_seq = 646
count = 371
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.596603
last_received_ts = 160.596237
last_seq = 646
current_ts = 160.613281
current_received_ts = 160.612808
current_seq = 647
count = 372
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.613281
last_received_ts = 160.612808
last_seq = 647
current_ts = 160.629944
current_received_ts = 160.629562
current_seq = 648
count = 373
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.629944
last_received_ts = 160.629562
last_seq = 648
current_ts = 160.646606
current_received_ts = 160.646240
current_seq = 649
count = 374
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.646606
last_received_ts = 160.646240
last_seq = 649
current_ts = 160.663284
current_received_ts = 160.662903
current_seq = 650
count = 375
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.663284
last_received_ts = 160.662903
last_seq = 650
current_ts = 160.679947
current_received_ts = 160.679550
current_seq = 651
count = 376
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.679947
last_received_ts = 160.679550
last_seq = 651
current_ts = 160.696609
current_received_ts = 160.696167
current_seq = 652
count = 377
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.696609
last_received_ts = 160.696167
last_seq = 652
current_ts = 160.713287
current_received_ts = 160.712891
current_seq = 653
count = 378
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.713287
last_received_ts = 160.712891
last_seq = 653
current_ts = 160.729935
current_received_ts = 160.729553
current_seq = 654
count = 379
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.729935
last_received_ts = 160.729553
last_seq = 654
current_ts = 160.746613
current_received_ts = 160.746246
current_seq = 655
count = 380
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.746613
last_received_ts = 160.746246
last_seq = 655
current_ts = 160.763275
current_received_ts = 160.762894
current_seq = 656
count = 381
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.763275
last_received_ts = 160.762894
last_seq = 656
current_ts = 160.779953
current_received_ts = 160.779556
current_seq = 657
count = 382
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.779953
last_received_ts = 160.779556
last_seq = 657
current_ts = 160.796616
current_received_ts = 160.796265
current_seq = 658
count = 383
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.796616
last_received_ts = 160.796265
last_seq = 658
current_ts = 160.813278
current_received_ts = 160.812897
current_seq = 659
count = 384
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.813278
last_received_ts = 160.812897
last_seq = 659
current_ts = 160.829941
current_received_ts = 160.829559
current_seq = 660
count = 385
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.829941
last_received_ts = 160.829559
last_seq = 660
current_ts = 160.846603
current_received_ts = 160.846237
current_seq = 661
count = 386
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.846603
last_received_ts = 160.846237
last_seq = 661
current_ts = 160.863266
current_received_ts = 160.862900
current_seq = 662
count = 387
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.863266
last_received_ts = 160.862900
last_seq = 662
current_ts = 160.879944
current_received_ts = 160.879501
current_seq = 663
count = 388
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.879944
last_received_ts = 160.879501
last_seq = 663
current_ts = 160.896606
current_received_ts = 160.896240
current_seq = 664
count = 389
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 51us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.896606
last_received_ts = 160.896240
last_seq = 664
current_ts = 160.913269
current_received_ts = 160.912903
current_seq = 665
count = 390
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.913269
last_received_ts = 160.912903
last_seq = 665
current_ts = 160.929947
current_received_ts = 160.929443
current_seq = 666
count = 391
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.929947
last_received_ts = 160.929443
last_seq = 666
current_ts = 160.946609
current_received_ts = 160.946243
current_seq = 667
count = 392
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.946609
last_received_ts = 160.946243
last_seq = 667
current_ts = 160.963287
current_received_ts = 160.962906
current_seq = 668
count = 393
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.963287
last_received_ts = 160.962906
last_seq = 668
current_ts = 160.979950
current_received_ts = 160.979584
current_seq = 669
count = 394
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.979950
last_received_ts = 160.979584
last_seq = 669
current_ts = 160.996613
current_received_ts = 160.996246
current_seq = 670
count = 395
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 160.996613
last_received_ts = 160.996246
last_seq = 670
current_ts = 161.013275
current_received_ts = 161.012909
current_seq = 671
count = 396
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.013275
last_received_ts = 161.012909
last_seq = 671
current_ts = 161.029953
current_received_ts = 161.029572
current_seq = 672
count = 397
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.029953
last_received_ts = 161.029572
last_seq = 672
current_ts = 161.046616
current_received_ts = 161.046249
current_seq = 673
count = 398
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.046616
last_received_ts = 161.046249
last_seq = 673
current_ts = 161.063278
current_received_ts = 161.062897
current_seq = 674
count = 399
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.063278
last_received_ts = 161.062897
last_seq = 674
current_ts = 161.079956
current_received_ts = 161.079575
current_seq = 675
count = 400
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.079956
last_received_ts = 161.079575
last_seq = 675
current_ts = 161.096619
current_received_ts = 161.096252
current_seq = 676
count = 401
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.096619
last_received_ts = 161.096252
last_seq = 676
current_ts = 161.113281
current_received_ts = 161.112839
current_seq = 677
count = 402
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.113281
last_received_ts = 161.112839
last_seq = 677
current_ts = 161.129959
current_received_ts = 161.129578
current_seq = 678
count = 403
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 52us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.129959
last_received_ts = 161.129578
last_seq = 678
current_ts = 161.146622
current_received_ts = 161.146149
current_seq = 679
count = 404
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 54us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.146622
last_received_ts = 161.146149
last_seq = 679
current_ts = 161.163284
current_received_ts = 161.164108
current_seq = 680
count = 405
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 53us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.163284
last_received_ts = 161.164108
last_seq = 680
current_ts = 161.179947
current_received_ts = 161.179428
current_seq = 681
count = 406
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 39us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.179947
last_received_ts = 161.179428
last_seq = 681
current_ts = 161.196625
current_received_ts = 161.196045
current_seq = 682
count = 407
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 34us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.196625
last_received_ts = 161.196045
last_seq = 682
current_ts = 161.213287
current_received_ts = 161.212738
current_seq = 683
count = 408
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 32us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.213287
last_received_ts = 161.212738
last_seq = 683
current_ts = 161.229950
current_received_ts = 161.229401
current_seq = 684
count = 409
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 32us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.229950
last_received_ts = 161.229401
last_seq = 684
current_ts = 161.246628
current_received_ts = 161.246078
current_seq = 685
count = 410
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 31us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.246628
last_received_ts = 161.246078
last_seq = 685
current_ts = 161.263290
current_received_ts = 161.262726
current_seq = 686
count = 411
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 32us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.263290
last_received_ts = 161.262726
last_seq = 686
current_ts = 161.279953
current_received_ts = 161.279404
current_seq = 687
count = 412
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 32us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.279953
last_received_ts = 161.279404
last_seq = 687
current_ts = 161.296631
current_received_ts = 161.296066
current_seq = 688
count = 413
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 32us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.296631
last_received_ts = 161.296066
last_seq = 688
current_ts = 161.313293
current_received_ts = 161.312729
current_seq = 689
count = 414
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 33us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.313293
last_received_ts = 161.312729
last_seq = 689
current_ts = 161.329956
current_received_ts = 161.329407
current_seq = 690
count = 415
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 32us
(kms_flip:2841) DEBUG: name = flip
last_ts = 161.329956
last_received_ts = 161.329407
last_seq = 690
current_ts = 161.346619
current_received_ts = 161.346069
current_seq = 691
count = 416
seq_step = 1
(kms_flip:2841) DEBUG: Vblank took 702us
(kms_flip:2841) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:2841) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2841) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2841) igt_core-INFO: Stack trace:
(kms_flip:2841) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2841) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:2841) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:2841) igt_core-INFO:   #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2043()
(kms_flip:2841) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:2841) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2841) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2841) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A3: FAIL (7.164s)

Dmesg

<6> [154.543480] [IGT] kms_flip: starting dynamic subtest B-HDMI-A3

<7> [154.544082] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:561]

<7> [154.544306] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:586]

<7> [154.544792] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.545725] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.576336] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.576852] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.584804] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.585193] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.606744] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.607070] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509

<7> [154.614058] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [154.620936] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:150:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0

<7> [154.621107] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:144:cursor A] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0

<7> [154.621284] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:150:pipe A] min cdclk: 74250 kHz -> 0 kHz

<7> [154.621434] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz

<7> [154.621613] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0

<7> [154.621773] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:150:pipe A] enable: no [modeset]

<7> [154.621930] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:34:plane 1A] fb: [NOFB], visible: no

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

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

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

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

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

<7> [154.623438] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A

<7> [154.625343] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D

<7> [154.625726] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A]

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

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

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

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

<7> [154.626551] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DDI B/PHY B]

<7> [154.626725] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST A]

<7> [154.626908] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST B]

<7> [154.627075] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST C]

<7> [154.627227] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST D]

<7> [154.627379] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DDI C/PHY C]

<7> [154.627532] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST A]

<7> [154.627691] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST B]

<7> [154.627844] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST C]

<7> [154.627999] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST D]

<7> [154.628210] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI D/PHY D]

<7> [154.628382] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A]

<7> [154.628535] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B]

<7> [154.628739] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C]

<7> [154.628904] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D]

<7> [154.629056] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:555:HDMI-A-3]

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

<7> [154.629501] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_A

<7> [154.629781] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2

<7> [154.629990] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:150:pipe A]

<7> [154.630414] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]

<7> [154.630584] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C]

<7> [154.630782] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:504:pipe D]

<7> [154.630986] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]

<7> [154.631015] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:555:HDMI-A-3]

<7> [154.631089] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:555:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)

<7> [154.631292] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)

<7> [154.631452] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:268:pipe B] hw max bpp: 24, pipe bpp: 24, dithering: 0

<7> [154.631615] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:546:DDI D/PHY D] [CRTC:268:pipe B]

<7> [154.631795] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.enable (expected no, found yes)

<7> [154.631962] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.active (expected no, found yes)

<7> [154.632115] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)

<7> [154.632267] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in lane_count (expected 0, found 4)

<7> [154.632433] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)

<7> [154.632589] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)

<7> [154.632782] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)

<7> [154.632980] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)

<7> [154.633130] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)

<7> [154.633283] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)

<7> [154.633449] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)

<7> [154.633611] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)

<7> [154.633795] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)

<7> [154.633961] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)

<7> [154.634140] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)

<7> [154.634292] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)

<7> [154.634459] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)

<7> [154.634632] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)

<7> [154.634862] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)

<7> [154.635017] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)

<7> [154.635171] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)

<7> [154.635338] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)

<7> [154.635503] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)

<7> [154.635676] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)

<7> [154.635827] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)

<7> [154.635978] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)

<7> [154.636128] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)

<7> [154.636279] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)

<7> [154.636430] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)

<7> [154.636580] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)

<7> [154.636802] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)

<7> [154.636954] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)

<7> [154.637104] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)

<7> [154.637256] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24)

<7> [154.637407] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)

<7> [154.637559] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)

<7> [154.637751] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:268:pipe B] fastset requirement not met in port_clock (expected 0, found 148500)

<7> [154.637963] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:268:pipe B] fastset requirement not met, forcing full modeset

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

<7> [154.638286] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:268:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2

<7> [154.638461] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:152:plane 1B] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963

<7> [154.638639] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:262:cursor B] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85

<7> [154.638830] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm

<7> [154.638976] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0

<7> [154.639122] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0

<7> [154.639267] i915 0000:03:00.0: [drm:skl_print_plane_changes [i915]] [PLANE:152:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0

<7> [154.639431] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:268:pipe B] data rate 594000 num active planes 1

<7> [154.639580] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624

<7> [154.639782] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1

<7> [154.639976] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:268:pipe B] min cdclk: 0 kHz -> 74250 kHz

<7> [154.640141] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz

<7> [154.640290] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0

<7> [154.640440] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:268:pipe B] enable: yes [modeset]

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

<7> [154.640840] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0

<7> [154.640990] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>

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

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

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

<7> [154.641614] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0

<7> [154.641809] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2

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

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

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

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

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

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

<7> [154.642934] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [154.643099] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5

<7> [154.643253] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [154.643408] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 74250

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

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

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

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

<7> [154.644183] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [154.646356] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:152:plane 1B] fb: [FB:561] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

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

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

<7> [154.646827] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:182:plane 2B] fb: [NOFB], visible: no

<7> [154.646980] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:212:plane 3B] fb: [NOFB], visible: no

<7> [154.647134] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:242:plane 4B] fb: [NOFB], visible: no

<7> [154.647293] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:252:plane 5B] fb: [NOFB], visible: no

<7> [154.647446] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:262:cursor B] fb: [NOFB], visible: no

<7> [154.648048] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2

<7> [154.648230] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_B

<7> [154.648434] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:506:DDI A/PHY A]

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

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

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

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

<7> [154.649211] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:519:DDI B/PHY B]

<7> [154.649364] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:521:DP-MST A]

<7> [154.649516] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST B]

<7> [154.649676] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST C]

<7> [154.649829] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST D]

<7> [154.649982] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:534:DDI C/PHY C]

<7> [154.650141] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:536:DP-MST A]

<7> [154.650294] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST B]

<7> [154.650447] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST C]

<7> [154.650609] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST D]

<7> [154.650763] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:546:DDI D/PHY D]

<7> [154.650917] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:548:DP-MST A]

<7> [154.651069] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST B]

<7> [154.651222] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST C]

<7> [154.651377] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST D]

<7> [154.651530] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3

<7> [154.651913] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D

<7> [154.652195] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe B

<7> [154.671245] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:555:HDMI-A-3]

<7> [154.671518] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:268:pipe B]

<6> [161.709367] [IGT] kms_flip: finished subtest B-HDMI-A3, FAIL

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