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

Result: Fail

integration-manifest git-log-oneline i915_display_info8 igt_runner8 runtimes8 results8.json results8-i915-load.json guc_logs8.tar i915_display_info_post_exec8 boot8 dmesg8

DetailValue
Duration 7.10 seconds
Hostname
shard-dg2-3
Igt-Version
IGT-Version: 2.4-g0c1d7a873 (x86_64) (Linux: 7.1.0-rc2-Patchwork_164541v2-g1dac77f19ea5+ x86_64)
Out
Starting dynamic subtest: D-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:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest D-HDMI-A3: FAIL (7.100s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (30.205s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2352 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2961 igt_atexit_handler()
  #3 [erand48_r+0x1d6]
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2416 igt_exit()
  #6 [main+0x3f]
  #7 [__libc_init_first+0x8a]
  #8 [__libc_start_main+0x8b]
  #9 [_start+0x25]
Err
Starting dynamic subtest: D-HDMI-A3
(kms_flip:2277) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2277) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2277) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest D-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.566589
last_received_ts = 325.566193
last_seq = 901
current_ts = 325.583252
current_received_ts = 325.582855
current_seq = 902
count = 289
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 81us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.583252
last_received_ts = 325.582855
last_seq = 902
current_ts = 325.599915
current_received_ts = 325.599518
current_seq = 903
count = 290
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.599915
last_received_ts = 325.599518
last_seq = 903
current_ts = 325.616577
current_received_ts = 325.616150
current_seq = 904
count = 291
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.616577
last_received_ts = 325.616150
last_seq = 904
current_ts = 325.633240
current_received_ts = 325.632874
current_seq = 905
count = 292
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.633240
last_received_ts = 325.632874
last_seq = 905
current_ts = 325.649933
current_received_ts = 325.649536
current_seq = 906
count = 293
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.649933
last_received_ts = 325.649536
last_seq = 906
current_ts = 325.666565
current_received_ts = 325.666229
current_seq = 907
count = 294
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 51us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.666565
last_received_ts = 325.666229
last_seq = 907
current_ts = 325.683258
current_received_ts = 325.682861
current_seq = 908
count = 295
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.683258
last_received_ts = 325.682861
last_seq = 908
current_ts = 325.699921
current_received_ts = 325.699524
current_seq = 909
count = 296
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.699921
last_received_ts = 325.699524
last_seq = 909
current_ts = 325.716583
current_received_ts = 325.716217
current_seq = 910
count = 297
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.716583
last_received_ts = 325.716217
last_seq = 910
current_ts = 325.733246
current_received_ts = 325.732880
current_seq = 911
count = 298
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.733246
last_received_ts = 325.732880
last_seq = 911
current_ts = 325.749908
current_received_ts = 325.749481
current_seq = 912
count = 299
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.749908
last_received_ts = 325.749481
last_seq = 912
current_ts = 325.766571
current_received_ts = 325.766205
current_seq = 913
count = 300
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.766571
last_received_ts = 325.766205
last_seq = 913
current_ts = 325.783264
current_received_ts = 325.782867
current_seq = 914
count = 301
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 54us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.783264
last_received_ts = 325.782867
last_seq = 914
current_ts = 325.799927
current_received_ts = 325.799530
current_seq = 915
count = 302
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.799927
last_received_ts = 325.799530
last_seq = 915
current_ts = 325.816589
current_received_ts = 325.816223
current_seq = 916
count = 303
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.816589
last_received_ts = 325.816223
last_seq = 916
current_ts = 325.833252
current_received_ts = 325.832886
current_seq = 917
count = 304
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.833252
last_received_ts = 325.832886
last_seq = 917
current_ts = 325.849945
current_received_ts = 325.849548
current_seq = 918
count = 305
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.849945
last_received_ts = 325.849548
last_seq = 918
current_ts = 325.866577
current_received_ts = 325.866211
current_seq = 919
count = 306
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.866577
last_received_ts = 325.866211
last_seq = 919
current_ts = 325.883240
current_received_ts = 325.882874
current_seq = 920
count = 307
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.883240
last_received_ts = 325.882874
last_seq = 920
current_ts = 325.899933
current_received_ts = 325.899536
current_seq = 921
count = 308
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.899933
last_received_ts = 325.899536
last_seq = 921
current_ts = 325.916595
current_received_ts = 325.916229
current_seq = 922
count = 309
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.916595
last_received_ts = 325.916229
last_seq = 922
current_ts = 325.933258
current_received_ts = 325.932831
current_seq = 923
count = 310
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.933258
last_received_ts = 325.932831
last_seq = 923
current_ts = 325.949921
current_received_ts = 325.949524
current_seq = 924
count = 311
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.949921
last_received_ts = 325.949524
last_seq = 924
current_ts = 325.966583
current_received_ts = 325.966217
current_seq = 925
count = 312
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.966583
last_received_ts = 325.966217
last_seq = 925
current_ts = 325.983276
current_received_ts = 325.982880
current_seq = 926
count = 313
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.983276
last_received_ts = 325.982880
last_seq = 926
current_ts = 325.999939
current_received_ts = 325.999542
current_seq = 927
count = 314
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 325.999939
last_received_ts = 325.999542
last_seq = 927
current_ts = 326.016602
current_received_ts = 326.016144
current_seq = 928
count = 315
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 51us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.016602
last_received_ts = 326.016144
last_seq = 928
current_ts = 326.033264
current_received_ts = 326.032867
current_seq = 929
count = 316
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.033264
last_received_ts = 326.032867
last_seq = 929
current_ts = 326.049927
current_received_ts = 326.049561
current_seq = 930
count = 317
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.049927
last_received_ts = 326.049561
last_seq = 930
current_ts = 326.066589
current_received_ts = 326.066223
current_seq = 931
count = 318
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.066589
last_received_ts = 326.066223
last_seq = 931
current_ts = 326.083282
current_received_ts = 326.082886
current_seq = 932
count = 319
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.083282
last_received_ts = 326.082886
last_seq = 932
current_ts = 326.099945
current_received_ts = 326.099548
current_seq = 933
count = 320
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.099945
last_received_ts = 326.099548
last_seq = 933
current_ts = 326.116608
current_received_ts = 326.116241
current_seq = 934
count = 321
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.116608
last_received_ts = 326.116241
last_seq = 934
current_ts = 326.133270
current_received_ts = 326.132904
current_seq = 935
count = 322
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.133270
last_received_ts = 326.132904
last_seq = 935
current_ts = 326.149933
current_received_ts = 326.149506
current_seq = 936
count = 323
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.149933
last_received_ts = 326.149506
last_seq = 936
current_ts = 326.166595
current_received_ts = 326.166229
current_seq = 937
count = 324
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.166595
last_received_ts = 326.166229
last_seq = 937
current_ts = 326.183289
current_received_ts = 326.182892
current_seq = 938
count = 325
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.183289
last_received_ts = 326.182892
last_seq = 938
current_ts = 326.199951
current_received_ts = 326.199585
current_seq = 939
count = 326
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.199951
last_received_ts = 326.199585
last_seq = 939
current_ts = 326.216614
current_received_ts = 326.216248
current_seq = 940
count = 327
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.216614
last_received_ts = 326.216248
last_seq = 940
current_ts = 326.233276
current_received_ts = 326.232910
current_seq = 941
count = 328
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.233276
last_received_ts = 326.232910
last_seq = 941
current_ts = 326.249939
current_received_ts = 326.249573
current_seq = 942
count = 329
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.249939
last_received_ts = 326.249573
last_seq = 942
current_ts = 326.266602
current_received_ts = 326.266235
current_seq = 943
count = 330
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.266602
last_received_ts = 326.266235
last_seq = 943
current_ts = 326.283295
current_received_ts = 326.282806
current_seq = 944
count = 331
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.283295
last_received_ts = 326.282806
last_seq = 944
current_ts = 326.299957
current_received_ts = 326.299561
current_seq = 945
count = 332
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 54us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.299957
last_received_ts = 326.299561
last_seq = 945
current_ts = 326.316620
current_received_ts = 326.316254
current_seq = 946
count = 333
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.316620
last_received_ts = 326.316254
last_seq = 946
current_ts = 326.333282
current_received_ts = 326.332886
current_seq = 947
count = 334
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 94us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.333282
last_received_ts = 326.332886
last_seq = 947
current_ts = 326.349945
current_received_ts = 326.349579
current_seq = 948
count = 335
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.349945
last_received_ts = 326.349579
last_seq = 948
current_ts = 326.366608
current_received_ts = 326.366180
current_seq = 949
count = 336
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.366608
last_received_ts = 326.366180
last_seq = 949
current_ts = 326.383301
current_received_ts = 326.382904
current_seq = 950
count = 337
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.383301
last_received_ts = 326.382904
last_seq = 950
current_ts = 326.399963
current_received_ts = 326.399567
current_seq = 951
count = 338
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.399963
last_received_ts = 326.399567
last_seq = 951
current_ts = 326.416626
current_received_ts = 326.416260
current_seq = 952
count = 339
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 51us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.416626
last_received_ts = 326.416260
last_seq = 952
current_ts = 326.433289
current_received_ts = 326.432892
current_seq = 953
count = 340
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.433289
last_received_ts = 326.432892
last_seq = 953
current_ts = 326.449951
current_received_ts = 326.449585
current_seq = 954
count = 341
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 54us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.449951
last_received_ts = 326.449585
last_seq = 954
current_ts = 326.466614
current_received_ts = 326.466248
current_seq = 955
count = 342
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 80us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.466614
last_received_ts = 326.466248
last_seq = 955
current_ts = 326.483307
current_received_ts = 326.482910
current_seq = 956
count = 343
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.483307
last_received_ts = 326.482910
last_seq = 956
current_ts = 326.499969
current_received_ts = 326.499542
current_seq = 957
count = 344
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.499969
last_received_ts = 326.499542
last_seq = 957
current_ts = 326.516632
current_received_ts = 326.516235
current_seq = 958
count = 345
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.516632
last_received_ts = 326.516235
last_seq = 958
current_ts = 326.533295
current_received_ts = 326.532898
current_seq = 959
count = 346
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.533295
last_received_ts = 326.532898
last_seq = 959
current_ts = 326.549957
current_received_ts = 326.549500
current_seq = 960
count = 347
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.549957
last_received_ts = 326.549500
last_seq = 960
current_ts = 326.566620
current_received_ts = 326.566254
current_seq = 961
count = 348
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.566620
last_received_ts = 326.566254
last_seq = 961
current_ts = 326.583313
current_received_ts = 326.582916
current_seq = 962
count = 349
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.583313
last_received_ts = 326.582916
last_seq = 962
current_ts = 326.599976
current_received_ts = 326.599579
current_seq = 963
count = 350
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 54us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.599976
last_received_ts = 326.599579
last_seq = 963
current_ts = 326.616638
current_received_ts = 326.616272
current_seq = 964
count = 351
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.616638
last_received_ts = 326.616272
last_seq = 964
current_ts = 326.633301
current_received_ts = 326.632843
current_seq = 965
count = 352
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.633301
last_received_ts = 326.632843
last_seq = 965
current_ts = 326.649963
current_received_ts = 326.649597
current_seq = 966
count = 353
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.649963
last_received_ts = 326.649597
last_seq = 966
current_ts = 326.666626
current_received_ts = 326.666260
current_seq = 967
count = 354
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.666626
last_received_ts = 326.666260
last_seq = 967
current_ts = 326.683319
current_received_ts = 326.682953
current_seq = 968
count = 355
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 86us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.683319
last_received_ts = 326.682953
last_seq = 968
current_ts = 326.699951
current_received_ts = 326.699585
current_seq = 969
count = 356
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.699951
last_received_ts = 326.699585
last_seq = 969
current_ts = 326.716644
current_received_ts = 326.716248
current_seq = 970
count = 357
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.716644
last_received_ts = 326.716248
last_seq = 970
current_ts = 326.733307
current_received_ts = 326.732910
current_seq = 971
count = 358
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 80us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.733307
last_received_ts = 326.732910
last_seq = 971
current_ts = 326.749969
current_received_ts = 326.749573
current_seq = 972
count = 359
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.749969
last_received_ts = 326.749573
last_seq = 972
current_ts = 326.766632
current_received_ts = 326.766205
current_seq = 973
count = 360
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.766632
last_received_ts = 326.766205
last_seq = 973
current_ts = 326.783325
current_received_ts = 326.782928
current_seq = 974
count = 361
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 80us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.783325
last_received_ts = 326.782928
last_seq = 974
current_ts = 326.799957
current_received_ts = 326.799591
current_seq = 975
count = 362
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 54us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.799957
last_received_ts = 326.799591
last_seq = 975
current_ts = 326.816620
current_received_ts = 326.816284
current_seq = 976
count = 363
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 51us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.816620
last_received_ts = 326.816284
last_seq = 976
current_ts = 326.833313
current_received_ts = 326.832916
current_seq = 977
count = 364
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 104us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.833313
last_received_ts = 326.832916
last_seq = 977
current_ts = 326.849976
current_received_ts = 326.849579
current_seq = 978
count = 365
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.849976
last_received_ts = 326.849579
last_seq = 978
current_ts = 326.866638
current_received_ts = 326.866272
current_seq = 979
count = 366
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 81us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.866638
last_received_ts = 326.866272
last_seq = 979
current_ts = 326.883301
current_received_ts = 326.882935
current_seq = 980
count = 367
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 82us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.883301
last_received_ts = 326.882935
last_seq = 980
current_ts = 326.899994
current_received_ts = 326.899536
current_seq = 981
count = 368
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.899994
last_received_ts = 326.899536
last_seq = 981
current_ts = 326.916626
current_received_ts = 326.916290
current_seq = 982
count = 369
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.916626
last_received_ts = 326.916290
last_seq = 982
current_ts = 326.933319
current_received_ts = 326.932922
current_seq = 983
count = 370
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 87us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.933319
last_received_ts = 326.932922
last_seq = 983
current_ts = 326.949982
current_received_ts = 326.949585
current_seq = 984
count = 371
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.949982
last_received_ts = 326.949585
last_seq = 984
current_ts = 326.966644
current_received_ts = 326.966278
current_seq = 985
count = 372
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.966644
last_received_ts = 326.966278
last_seq = 985
current_ts = 326.983307
current_received_ts = 326.982941
current_seq = 986
count = 373
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 85us
(kms_flip:2277) DEBUG: name = flip
last_ts = 326.983307
last_received_ts = 326.982941
last_seq = 986
current_ts = 327.000000
current_received_ts = 326.999603
current_seq = 987
count = 374
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 83us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.000000
last_received_ts = 326.999603
last_seq = 987
current_ts = 327.016632
current_received_ts = 327.016296
current_seq = 988
count = 375
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.016632
last_received_ts = 327.016296
last_seq = 988
current_ts = 327.033325
current_received_ts = 327.032867
current_seq = 989
count = 376
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.033325
last_received_ts = 327.032867
last_seq = 989
current_ts = 327.049988
current_received_ts = 327.049622
current_seq = 990
count = 377
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.049988
last_received_ts = 327.049622
last_seq = 990
current_ts = 327.066650
current_received_ts = 327.066284
current_seq = 991
count = 378
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 51us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.066650
last_received_ts = 327.066284
last_seq = 991
current_ts = 327.083313
current_received_ts = 327.082977
current_seq = 992
count = 379
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 83us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.083313
last_received_ts = 327.082977
last_seq = 992
current_ts = 327.100006
current_received_ts = 327.099609
current_seq = 993
count = 380
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.100006
last_received_ts = 327.099609
last_seq = 993
current_ts = 327.116669
current_received_ts = 327.116211
current_seq = 994
count = 381
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.116669
last_received_ts = 327.116211
last_seq = 994
current_ts = 327.133301
current_received_ts = 327.132935
current_seq = 995
count = 382
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 87us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.133301
last_received_ts = 327.132935
last_seq = 995
current_ts = 327.149994
current_received_ts = 327.149597
current_seq = 996
count = 383
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.149994
last_received_ts = 327.149597
last_seq = 996
current_ts = 327.166656
current_received_ts = 327.166290
current_seq = 997
count = 384
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.166656
last_received_ts = 327.166290
last_seq = 997
current_ts = 327.183319
current_received_ts = 327.182953
current_seq = 998
count = 385
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 80us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.183319
last_received_ts = 327.182953
last_seq = 998
current_ts = 327.199982
current_received_ts = 327.199615
current_seq = 999
count = 386
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.199982
last_received_ts = 327.199615
last_seq = 999
current_ts = 327.216675
current_received_ts = 327.216278
current_seq = 1000
count = 387
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.216675
last_received_ts = 327.216278
last_seq = 1000
current_ts = 327.233337
current_received_ts = 327.232941
current_seq = 1001
count = 388
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 82us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.233337
last_received_ts = 327.232941
last_seq = 1001
current_ts = 327.250000
current_received_ts = 327.249542
current_seq = 1002
count = 389
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.250000
last_received_ts = 327.249542
last_seq = 1002
current_ts = 327.266663
current_received_ts = 327.266296
current_seq = 1003
count = 390
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.266663
last_received_ts = 327.266296
last_seq = 1003
current_ts = 327.283325
current_received_ts = 327.282928
current_seq = 1004
count = 391
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 72us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.283325
last_received_ts = 327.282928
last_seq = 1004
current_ts = 327.299988
current_received_ts = 327.299622
current_seq = 1005
count = 392
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.299988
last_received_ts = 327.299622
last_seq = 1005
current_ts = 327.316650
current_received_ts = 327.316284
current_seq = 1006
count = 393
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 51us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.316650
last_received_ts = 327.316284
last_seq = 1006
current_ts = 327.333344
current_received_ts = 327.332947
current_seq = 1007
count = 394
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 74us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.333344
last_received_ts = 327.332947
last_seq = 1007
current_ts = 327.350006
current_received_ts = 327.349609
current_seq = 1008
count = 395
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.350006
last_received_ts = 327.349609
last_seq = 1008
current_ts = 327.366669
current_received_ts = 327.366302
current_seq = 1009
count = 396
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.366669
last_received_ts = 327.366302
last_seq = 1009
current_ts = 327.383331
current_received_ts = 327.382843
current_seq = 1010
count = 397
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.383331
last_received_ts = 327.382843
last_seq = 1010
current_ts = 327.399994
current_received_ts = 327.399628
current_seq = 1011
count = 398
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.399994
last_received_ts = 327.399628
last_seq = 1011
current_ts = 327.416656
current_received_ts = 327.416290
current_seq = 1012
count = 399
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.416656
last_received_ts = 327.416290
last_seq = 1012
current_ts = 327.433319
current_received_ts = 327.432983
current_seq = 1013
count = 400
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.433319
last_received_ts = 327.432983
last_seq = 1013
current_ts = 327.450012
current_received_ts = 327.449615
current_seq = 1014
count = 401
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.450012
last_received_ts = 327.449615
last_seq = 1014
current_ts = 327.466675
current_received_ts = 327.466278
current_seq = 1015
count = 402
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.466675
last_received_ts = 327.466278
last_seq = 1015
current_ts = 327.483337
current_received_ts = 327.482971
current_seq = 1016
count = 403
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 81us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.483337
last_received_ts = 327.482971
last_seq = 1016
current_ts = 327.500000
current_received_ts = 327.499634
current_seq = 1017
count = 404
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.500000
last_received_ts = 327.499634
last_seq = 1017
current_ts = 327.516693
current_received_ts = 327.516235
current_seq = 1018
count = 405
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.516693
last_received_ts = 327.516235
last_seq = 1018
current_ts = 327.533325
current_received_ts = 327.532959
current_seq = 1019
count = 406
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 76us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.533325
last_received_ts = 327.532959
last_seq = 1019
current_ts = 327.550018
current_received_ts = 327.549622
current_seq = 1020
count = 407
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 53us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.550018
last_received_ts = 327.549622
last_seq = 1020
current_ts = 327.566681
current_received_ts = 327.566315
current_seq = 1021
count = 408
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 52us
(kms_flip:2277) DEBUG: name = flip
last_ts = 327.566681
last_received_ts = 327.566315
last_seq = 1021
current_ts = 327.583344
current_received_ts = 327.582977
current_seq = 1022
count = 409
seq_step = 1
(kms_flip:2277) DEBUG: Vblank took 1029us
(kms_flip:2277) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2277) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2277) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2277) igt_core-INFO: Stack trace:
(kms_flip:2277) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2277) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2277) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2277) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2277) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2277) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2277) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2277) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest D-HDMI-A3: FAIL (7.100s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (30.205s)
(kms_flip:2277) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352:
(kms_flip:2277) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:2277) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:2277) igt_kms-CRITICAL: DPMS property not found on 556
Dmesg
<6> [320.601009] [IGT] kms_flip: starting dynamic subtest D-HDMI-A3
<7> [320.601441] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:561]
<7> [320.601610] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:563]
<7> [320.602030] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.602528] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.624446] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.624839] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.631809] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.632112] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.652614] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.652927] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [320.659604] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [320.659798] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C]
<7> [320.659922] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe B]
<7> [320.660006] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [320.660187] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [320.660341] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [320.660500] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [320.660654] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [320.660883] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [320.661037] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [320.661190] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [320.661343] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [320.661495] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [320.661647] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [320.661993] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [320.662149] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [320.662302] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [320.662455] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [320.662607] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [320.662799] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [320.662952] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [320.663105] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [320.663258] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [320.663411] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [320.663564] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [320.663756] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [320.663908] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [320.664065] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [320.664218] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [320.664371] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [320.664523] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [320.664682] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [320.664959] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [320.665112] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [320.665264] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [320.665417] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [320.665570] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [320.665830] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [320.665998] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [320.666151] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [320.666305] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe B] fastset requirement not met, forcing full modeset
<7> [320.666474] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [320.666622] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [320.666840] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor B] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [320.667039] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe B] min cdclk: 74250 kHz -> 0 kHz
<7> [320.667192] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [320.667342] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [320.667494] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe B] enable: no [modeset]
<7> [320.667646] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1B] fb: [NOFB], visible: no
<7> [320.667834] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2B] fb: [NOFB], visible: no
<7> [320.668056] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3B] fb: [NOFB], visible: no
<7> [320.668209] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4B] fb: [NOFB], visible: no
<7> [320.668360] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5B] fb: [NOFB], visible: no
<7> [320.668510] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor B] fb: [NOFB], visible: no
<7> [320.668938] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [320.683904] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [320.684129] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [320.684282] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [320.684434] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [320.684585] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [320.684748] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [320.684900] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [320.685050] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [320.685201] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [320.685352] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [320.685503] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [320.685654] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [320.685848] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [320.686000] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [320.686152] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [320.686303] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [320.686454] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [320.686625] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [320.686819] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [320.686970] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [320.687122] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [320.687273] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [320.687465] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [320.687756] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_B
<7> [320.687970] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [320.688166] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe B]
<7> [320.688524] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [320.688714] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [320.688758] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:556:HDMI-A-3]
<7> [320.688833] i915 0000:03:00.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [320.688993] i915 0000:03:00.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [320.689135] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [320.689288] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:505:pipe D]
<7> [320.689434] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.enable (expected no, found yes)
<7> [320.689587] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.active (expected no, found yes)
<7> [320.689779] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in cpu_transcoder (expected -1, found 3)
<7> [320.689933] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in lane_count (expected 0, found 4)
<7> [320.690086] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [320.690239] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [320.690391] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [320.690544] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [320.690737] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [320.690925] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [320.691077] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [320.691229] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [320.691382] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [320.691534] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [320.691711] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [320.691878] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [320.692031] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [320.692183] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [320.692335] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [320.692487] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [320.692640] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [320.692830] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [320.692983] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [320.693136] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [320.693289] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [320.693442] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [320.693596] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [320.693786] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [320.693940] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [320.694093] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [320.694245] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [320.694397] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [320.694551] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [320.694742] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [320.694898] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [320.695052] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [320.695205] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [320.695358] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] fastset requirement not met, forcing full modeset
<7> [320.695533] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [320.695760] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:505:pipe D] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x8
<7> [320.695936] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:389:plane 1D] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [320.696084] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:499:cursor D] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [320.696232] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [320.696380] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [320.696528] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0
<7> [320.696682] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] 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> [320.696878] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:505:pipe D] data rate 594000 num active planes 1
<7> [320.697029] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [320.697180] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [320.697345] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:505:pipe D] min cdclk: 0 kHz -> 74250 kHz
<7> [320.697513] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [320.697663] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [320.697854] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:505:pipe D] enable: yes [modeset]
<7> [320.698006] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [320.698159] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: D, pipe bpp: 24, dithering: 0
<7> [320.698310] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [320.698461] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [320.698613] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [320.698804] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [320.698956] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [320.699107] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [320.699258] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [320.699410] 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> [320.699562] 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> [320.699748] 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> [320.699900] 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> [320.700054] 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> [320.700205] 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> [320.700358] 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> [320.700509] 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> [320.700662] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [320.700849] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [320.701000] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [320.701151] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [320.701304] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [320.701455] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [320.701607] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [320.701792] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [320.701944] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [320.702095] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [320.702247] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [320.702399] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [320.702551] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [320.702724] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [320.702889] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [320.703040] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [320.703192] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [320.703343] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [320.703493] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [320.703645] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [320.703832] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:389:plane 1D] fb: [FB:561] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [320.703985] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [320.704137] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [320.704290] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:419:plane 2D] fb: [NOFB], visible: no
<7> [320.704441] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:449:plane 3D] fb: [NOFB], visible: no
<7> [320.704593] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:479:plane 4D] fb: [NOFB], visible: no
<7> [320.704782] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:489:plane 5D] fb: [NOFB], visible: no
<7> [320.704933] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:499:cursor D] fb: [NOFB], visible: no
<7> [320.705512] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [320.705731] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_D
<7> [320.705937] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [320.706090] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [320.706241] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [320.706393] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [320.706544] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [320.706733] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [320.706912] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [320.707063] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [320.707214] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [320.707365] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [320.707515] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [320.707665] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [320.707857] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [320.708008] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [320.708159] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [320.708309] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [320.708460] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [320.708610] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [320.708799] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [320.708950] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [320.709101] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xd
<7> [320.709452] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [320.709769] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe D
<7> [320.745734] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [320.746039] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:505:pipe D]
<6> [327.703930] [IGT] kms_flip: finished subtest D-HDMI-A3, FAIL
<6> [327.704756] [IGT] kms_flip: finished subtest flip-vs-expired-vblank-interruptible, FAIL
<7> [327.716926] i915 0000:03:00.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:563] from all active usage due to RMFB ioctl
<7> [327.719304] i915 0000:03:00.0: [drm:atomic_remove_fb] Disabling [PLANE:389:plane 1D] because [FB:563] is removed
<7> [327.719466] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:389:plane 1D] ddb ( 0 - 1963) -> ( 0 - 0), size 1963 -> 0
<7> [327.720148] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [327.720805] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] lines 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [327.721406] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] blocks 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [327.722869] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] min_ddb 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [327.723584] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:505:pipe D] data rate 0 num active planes 0
<7> [327.724197] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 0
<7> [327.724834] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<6> [327.750973] [IGT] kms_flip: exiting, ret=98
<7> [327.781216] i915 0000:03:00.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [327.781489] i915 0000:03:00.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [327.781756] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [327.781996] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:151:pipe A]
<7> [327.782204] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [327.782422] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [327.782649] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [327.782867] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [327.783084] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [327.783302] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [327.783526] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [327.783743] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [327.783967] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [327.784184] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [327.784401] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [327.784625] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [327.784842] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [327.785059] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [327.785276] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [327.785468] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [327.785667] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [327.785859] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [327.786051] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [327.786242] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [327.786434] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [327.786632] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [327.786825] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [327.787016] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [327.787207] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [327.787399] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [327.787710] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [327.787989] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [327.788181] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [327.788381] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [327.788580] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [327.788774] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [327.788966] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [327.789159] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [327.789351] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [327.789551] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [327.789743] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [327.789936] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [327.790133] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.enable (expected yes, found no)
<7> [327.790323] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.active (expected yes, found no)
<7> [327.790496] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in cpu_transcoder (expected 3, found -1)
<7> [327.790674] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in lane_count (expected 4, found 0)
<7> [327.790847] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [327.791019] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [327.791190] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [327.791362] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [327.791541] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [327.791713] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [327.791885] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [327.792057] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [327.792228] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [327.792401] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [327.792580] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [327.792751] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [327.792923] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [327.793095] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [327.793266] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [327.793445] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [327.793624] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [327.793798] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [327.793973] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [327.794145] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [327.794317] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [327.794488] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [327.794749] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [327.795472] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [327.795643] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [327.795800] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [327.795956] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [327.796112] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [327.796268] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [327.796424] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [327.796586] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [327.796743] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [327.796899] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [327.797060] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] fastset requirement not met, forcing full modeset
<7> [327.797254] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0xd -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [327.797408] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x8 -> 0x1
<7> [327.797578] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:505:pipe D] dbuf slices 0xc -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x8 -> 0x1
<7> [327.797734] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [327.797884] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [327.798036] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [327.798187] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [327.798338] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0
<7> [327.798491] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0
<7> [327.798653] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:499:cursor D] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [327.798822] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 594000 num active planes 1
<7> [327.798977] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [327.799131] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [327.799300] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 74250 kHz
<7> [327.799454] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:505:pipe D] min cdclk: 74250 kHz -> 0 kHz
<7> [327.799636] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [327.799791] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [327.799947] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [327.800102] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [327.800269] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [327.800421] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [327.800614] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [327.800765] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [327.800917] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [327.801067] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [327.801218] 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> [327.801371] 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> [327.801552] 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> [327.801747] 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> [327.801905] 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> [327.802058] 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> [327.802210] 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> [327.802362] 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> [327.802520] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [327.802738] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [327.802889] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [327.803040] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [327.803191] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [327.803344] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [327.803495] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [327.803754] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [327.803907] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [327.804059] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [327.804211] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [327.804363] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [327.804592] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [327.804744] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [327.804896] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [327.805047] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [327.805198] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [327.805349] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [327.805501] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [327.805692] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [327.805844] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:559] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [327.805997] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [327.806149] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [327.806301] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [327.806453] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [327.806648] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [327.806800] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [327.806951] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [327.807103] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:505:pipe D] enable: no [modeset]
<7> [327.807254] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:389:plane 1D] fb: [NOFB], visible: no
<7> [327.807405] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:419:plane 2D] fb: [NOFB], visible: no
<7> [327.807624] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:449:plane 3D] fb: [NOFB], visible: no
<7> [327.807775] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:479:plane 4D] fb: [NOFB], visible: no
<7> [327.807927] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:489:plane 5D] fb: [NOFB], visible: no
<7> [327.808078] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:499:cursor D] fb: [NOFB], visible: no
<7> [327.808344] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [327.808676] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe D
<7> [327.813631] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [327.813853] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [327.814007] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [327.814159] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [327.814311] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [327.814463] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [327.814657] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [327.814809] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [327.814961] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [327.815112] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [327.815263] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [327.815414] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [327.815611] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [327.815763] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [327.815914] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [327.816065] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [327.816217] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [327.816368] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [327.816544] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [327.816740] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [327.816891] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [327.817048] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xf
<7> [327.817415] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [327.817740] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [327.835670] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [327.835832] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]
<7> [327.852338] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [327.852921] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [327.853187] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [327.854156] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_D
<7> [327.854385] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:505:pipe D]
<7> [327.854983] i915 0000:03:00.0: [drm:drm_client_dev_restore] fbdev: ret=0
Created at 2026-05-05 20:29:49