Results for igt@kms_flip@2x-flip-vs-expired-vblank@ac-hdmi-a1-hdmi-a2

Result: Fail

integration-manifest git-log-oneline i915_display_info10 igt_runner10 runtimes10 results10.json results10-i915-load.json guc_logs10.tar boot10 dmesg10

DetailValue
Duration 9.25 seconds
Hostname
shard-glk6
Igt-Version
IGT-Version: 2.4-gf29c30f54 (x86_64) (Linux: 7.1.0-rc3-Patchwork_166493v2-gdee34cfbffbf+ x86_64)
Out
Starting dynamic subtest: AC-HDMI-A1-HDMI-A2
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Stack trace:
  #0 ../lib/igt_core.c:2074 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:2029 run_pair()
  #3 ../tests/kms_flip.c:2193 __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 AC-HDMI-A1-HDMI-A2: FAIL (9.254s)
Err
Starting dynamic subtest: AC-HDMI-A1-HDMI-A2
[127.559915] (kms_flip:2282) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[127.560091] (kms_flip:2282) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest AC-HDMI-A1-HDMI-A2 failed.
**** DEBUG ****
[125.542110] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.799911
last_received_ts = 125.799583
last_seq = 2731
current_ts = 125.816589
current_received_ts = 125.816360
current_seq = 2732
count = 345
seq_step = 1
[125.542156] (kms_flip:2282) DEBUG: Vblank took 20us
[125.558782] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.816589
last_received_ts = 125.816360
last_seq = 2732
current_ts = 125.833260
current_received_ts = 125.833000
current_seq = 2733
count = 346
seq_step = 1
[125.558829] (kms_flip:2282) DEBUG: Vblank took 21us
[125.575290] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.833260
last_received_ts = 125.833000
last_seq = 2733
current_ts = 125.849930
current_received_ts = 125.849541
current_seq = 2734
count = 347
seq_step = 1
[125.575336] (kms_flip:2282) DEBUG: Vblank took 21us
[125.592100] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.849930
last_received_ts = 125.849541
last_seq = 2734
current_ts = 125.866592
current_received_ts = 125.866348
current_seq = 2735
count = 348
seq_step = 1
[125.592148] (kms_flip:2282) DEBUG: Vblank took 22us
[125.608804] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.866592
last_received_ts = 125.866348
last_seq = 2735
current_ts = 125.883263
current_received_ts = 125.882996
current_seq = 2736
count = 349
seq_step = 1
[125.608851] (kms_flip:2282) DEBUG: Vblank took 22us
[125.625697] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.883263
last_received_ts = 125.882996
last_seq = 2736
current_ts = 125.899918
current_received_ts = 125.899948
current_seq = 2737
count = 350
seq_step = 1
[125.625801] (kms_flip:2282) DEBUG: Vblank took 19us
[125.642105] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.899918
last_received_ts = 125.899948
last_seq = 2737
current_ts = 125.916588
current_received_ts = 125.916351
current_seq = 2738
count = 351
seq_step = 1
[125.642158] (kms_flip:2282) DEBUG: Vblank took 23us
[125.658774] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.916588
last_received_ts = 125.916351
last_seq = 2738
current_ts = 125.933266
current_received_ts = 125.932999
current_seq = 2739
count = 352
seq_step = 1
[125.658822] (kms_flip:2282) DEBUG: Vblank took 22us
[125.675331] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.933266
last_received_ts = 125.932999
last_seq = 2739
current_ts = 125.949921
current_received_ts = 125.949577
current_seq = 2740
count = 353
seq_step = 1
[125.675387] (kms_flip:2282) DEBUG: Vblank took 26us
[125.692126] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.949921
last_received_ts = 125.949577
last_seq = 2740
current_ts = 125.966599
current_received_ts = 125.966377
current_seq = 2741
count = 354
seq_step = 1
[125.692175] (kms_flip:2282) DEBUG: Vblank took 22us
[125.708710] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.966599
last_received_ts = 125.966377
last_seq = 2741
current_ts = 125.983269
current_received_ts = 125.982964
current_seq = 2742
count = 355
seq_step = 1
[125.708816] (kms_flip:2282) DEBUG: Vblank took 23us
[125.725280] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.983269
last_received_ts = 125.982964
last_seq = 2742
current_ts = 125.999931
current_received_ts = 125.999535
current_seq = 2743
count = 356
seq_step = 1
[125.725326] (kms_flip:2282) DEBUG: Vblank took 20us
[125.742106] (kms_flip:2282) DEBUG: name = flip
last_ts = 125.999931
last_received_ts = 125.999535
last_seq = 2743
current_ts = 126.016586
current_received_ts = 126.016357
current_seq = 2744
count = 357
seq_step = 1
[125.742158] (kms_flip:2282) DEBUG: Vblank took 24us
[125.758843] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.016586
last_received_ts = 126.016357
last_seq = 2744
current_ts = 126.033264
current_received_ts = 126.033096
current_seq = 2745
count = 358
seq_step = 1
[125.758898] (kms_flip:2282) DEBUG: Vblank took 25us
[125.775252] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.033264
last_received_ts = 126.033096
last_seq = 2745
current_ts = 126.049927
current_received_ts = 126.049507
current_seq = 2746
count = 359
seq_step = 1
[125.775304] (kms_flip:2282) DEBUG: Vblank took 24us
[125.792103] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.049927
last_received_ts = 126.049507
last_seq = 2746
current_ts = 126.066605
current_received_ts = 126.066360
current_seq = 2747
count = 360
seq_step = 1
[125.792149] (kms_flip:2282) DEBUG: Vblank took 21us
[125.808803] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.066605
last_received_ts = 126.066360
last_seq = 2747
current_ts = 126.083260
current_received_ts = 126.083061
current_seq = 2748
count = 361
seq_step = 1
[125.808853] (kms_flip:2282) DEBUG: Vblank took 23us
[125.825332] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.083260
last_received_ts = 126.083061
last_seq = 2748
current_ts = 126.099937
current_received_ts = 126.099586
current_seq = 2749
count = 362
seq_step = 1
[125.825384] (kms_flip:2282) DEBUG: Vblank took 24us
[125.841955] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.099937
last_received_ts = 126.099586
last_seq = 2749
current_ts = 126.116600
current_received_ts = 126.116211
current_seq = 2750
count = 363
seq_step = 1
[125.842005] (kms_flip:2282) DEBUG: Vblank took 22us
[125.858882] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.116600
last_received_ts = 126.116211
last_seq = 2750
current_ts = 126.133263
current_received_ts = 126.133141
current_seq = 2751
count = 364
seq_step = 1
[125.858929] (kms_flip:2282) DEBUG: Vblank took 21us
[125.875355] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.133263
last_received_ts = 126.133141
last_seq = 2751
current_ts = 126.149925
current_received_ts = 126.149612
current_seq = 2752
count = 365
seq_step = 1
[125.875407] (kms_flip:2282) DEBUG: Vblank took 22us
[125.892095] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.149925
last_received_ts = 126.149612
last_seq = 2752
current_ts = 126.166595
current_received_ts = 126.166351
current_seq = 2753
count = 366
seq_step = 1
[125.892142] (kms_flip:2282) DEBUG: Vblank took 20us
[125.908703] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.166595
last_received_ts = 126.166351
last_seq = 2753
current_ts = 126.183266
current_received_ts = 126.182961
current_seq = 2754
count = 367
seq_step = 1
[125.908810] (kms_flip:2282) DEBUG: Vblank took 23us
[125.925279] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.183266
last_received_ts = 126.182961
last_seq = 2754
current_ts = 126.199936
current_received_ts = 126.199539
current_seq = 2755
count = 368
seq_step = 1
[125.925324] (kms_flip:2282) DEBUG: Vblank took 21us
[125.942121] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.199936
last_received_ts = 126.199539
last_seq = 2755
current_ts = 126.216606
current_received_ts = 126.216377
current_seq = 2756
count = 369
seq_step = 1
[125.942166] (kms_flip:2282) DEBUG: Vblank took 20us
[125.958794] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.216606
last_received_ts = 126.216377
last_seq = 2756
current_ts = 126.233261
current_received_ts = 126.233055
current_seq = 2757
count = 370
seq_step = 1
[125.958841] (kms_flip:2282) DEBUG: Vblank took 21us
[125.975333] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.233261
last_received_ts = 126.233055
last_seq = 2757
current_ts = 126.249931
current_received_ts = 126.249588
current_seq = 2758
count = 371
seq_step = 1
[125.975390] (kms_flip:2282) DEBUG: Vblank took 25us
[125.992119] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.249931
last_received_ts = 126.249588
last_seq = 2758
current_ts = 126.266602
current_received_ts = 126.266380
current_seq = 2759
count = 372
seq_step = 1
[125.992166] (kms_flip:2282) DEBUG: Vblank took 21us
[126.008866] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.266602
last_received_ts = 126.266380
last_seq = 2759
current_ts = 126.283272
current_received_ts = 126.283127
current_seq = 2760
count = 373
seq_step = 1
[126.008918] (kms_flip:2282) DEBUG: Vblank took 23us
[126.025639] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.283272
last_received_ts = 126.283127
last_seq = 2760
current_ts = 126.299934
current_received_ts = 126.299904
current_seq = 2761
count = 374
seq_step = 1
[126.025686] (kms_flip:2282) DEBUG: Vblank took 20us
[126.042149] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.299934
last_received_ts = 126.299904
last_seq = 2761
current_ts = 126.316620
current_received_ts = 126.316406
current_seq = 2762
count = 375
seq_step = 1
[126.042202] (kms_flip:2282) DEBUG: Vblank took 24us
[126.058795] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.316620
last_received_ts = 126.316406
last_seq = 2762
current_ts = 126.333275
current_received_ts = 126.333054
current_seq = 2763
count = 376
seq_step = 1
[126.058897] (kms_flip:2282) DEBUG: Vblank took 22us
[126.075299] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.333275
last_received_ts = 126.333054
last_seq = 2763
current_ts = 126.349945
current_received_ts = 126.349564
current_seq = 2764
count = 377
seq_step = 1
[126.075348] (kms_flip:2282) DEBUG: Vblank took 22us
[126.092108] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.349945
last_received_ts = 126.349564
last_seq = 2764
current_ts = 126.366600
current_received_ts = 126.366371
current_seq = 2765
count = 378
seq_step = 1
[126.092155] (kms_flip:2282) DEBUG: Vblank took 21us
[126.108675] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.366600
last_received_ts = 126.366371
last_seq = 2765
current_ts = 126.383270
current_received_ts = 126.382942
current_seq = 2766
count = 379
seq_step = 1
[126.108787] (kms_flip:2282) DEBUG: Vblank took 86us
[126.125271] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.383270
last_received_ts = 126.382942
last_seq = 2766
current_ts = 126.399940
current_received_ts = 126.399536
current_seq = 2767
count = 380
seq_step = 1
[126.125315] (kms_flip:2282) DEBUG: Vblank took 19us
[126.142118] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.399940
last_received_ts = 126.399536
last_seq = 2767
current_ts = 126.416595
current_received_ts = 126.416382
current_seq = 2768
count = 381
seq_step = 1
[126.142167] (kms_flip:2282) DEBUG: Vblank took 22us
[126.158861] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.416595
last_received_ts = 126.416382
last_seq = 2768
current_ts = 126.433273
current_received_ts = 126.433121
current_seq = 2769
count = 382
seq_step = 1
[126.158913] (kms_flip:2282) DEBUG: Vblank took 24us
[126.175334] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.433273
last_received_ts = 126.433121
last_seq = 2769
current_ts = 126.449936
current_received_ts = 126.449593
current_seq = 2770
count = 383
seq_step = 1
[126.175389] (kms_flip:2282) DEBUG: Vblank took 24us
[126.192110] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.449936
last_received_ts = 126.449593
last_seq = 2770
current_ts = 126.466614
current_received_ts = 126.466377
current_seq = 2771
count = 384
seq_step = 1
[126.192156] (kms_flip:2282) DEBUG: Vblank took 21us
[126.208786] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.466614
last_received_ts = 126.466377
last_seq = 2771
current_ts = 126.483269
current_received_ts = 126.483055
current_seq = 2772
count = 385
seq_step = 1
[126.208832] (kms_flip:2282) DEBUG: Vblank took 22us
[126.225833] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.483269
last_received_ts = 126.483055
last_seq = 2772
current_ts = 126.499939
current_received_ts = 126.499985
current_seq = 2773
count = 386
seq_step = 1
[126.225888] (kms_flip:2282) DEBUG: Vblank took 24us
[126.242161] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.499939
last_received_ts = 126.499985
last_seq = 2773
current_ts = 126.516609
current_received_ts = 126.516426
current_seq = 2774
count = 387
seq_step = 1
[126.242218] (kms_flip:2282) DEBUG: Vblank took 25us
[126.260012] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.516609
last_received_ts = 126.516426
last_seq = 2774
current_ts = 126.533272
current_received_ts = 126.534279
current_seq = 2775
count = 388
seq_step = 1
[126.260083] (kms_flip:2282) DEBUG: Vblank took 44us
[126.275227] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.533272
last_received_ts = 126.534279
last_seq = 2775
current_ts = 126.549934
current_received_ts = 126.549500
current_seq = 2776
count = 389
seq_step = 1
[126.275274] (kms_flip:2282) DEBUG: Vblank took 21us
[126.292108] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.549934
last_received_ts = 126.549500
last_seq = 2776
current_ts = 126.566612
current_received_ts = 126.566376
current_seq = 2777
count = 390
seq_step = 1
[126.292153] (kms_flip:2282) DEBUG: Vblank took 20us
[126.308780] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.566612
last_received_ts = 126.566376
last_seq = 2777
current_ts = 126.583275
current_received_ts = 126.583046
current_seq = 2778
count = 391
seq_step = 1
[126.308883] (kms_flip:2282) DEBUG: Vblank took 23us
[126.325302] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.583275
last_received_ts = 126.583046
last_seq = 2778
current_ts = 126.599953
current_received_ts = 126.599571
current_seq = 2779
count = 392
seq_step = 1
[126.325351] (kms_flip:2282) DEBUG: Vblank took 22us
[126.342100] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.599953
last_received_ts = 126.599571
last_seq = 2779
current_ts = 126.616608
current_received_ts = 126.616371
current_seq = 2780
count = 393
seq_step = 1
[126.342146] (kms_flip:2282) DEBUG: Vblank took 20us
[126.358832] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.616608
last_received_ts = 126.616371
last_seq = 2780
current_ts = 126.633278
current_received_ts = 126.633102
current_seq = 2781
count = 394
seq_step = 1
[126.358885] (kms_flip:2282) DEBUG: Vblank took 24us
[126.375334] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.633278
last_received_ts = 126.633102
last_seq = 2781
current_ts = 126.649940
current_received_ts = 126.649597
current_seq = 2782
count = 395
seq_step = 1
[126.375389] (kms_flip:2282) DEBUG: Vblank took 24us
[126.392158] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.649940
last_received_ts = 126.649597
last_seq = 2782
current_ts = 126.666611
current_received_ts = 126.666420
current_seq = 2783
count = 396
seq_step = 1
[126.392214] (kms_flip:2282) DEBUG: Vblank took 25us
[126.408620] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.666611
last_received_ts = 126.666420
last_seq = 2783
current_ts = 126.683273
current_received_ts = 126.682892
current_seq = 2784
count = 397
seq_step = 1
[126.408673] (kms_flip:2282) DEBUG: Vblank took 24us
[126.425653] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.683273
last_received_ts = 126.682892
last_seq = 2784
current_ts = 126.699944
current_received_ts = 126.699921
current_seq = 2785
count = 398
seq_step = 1
[126.425758] (kms_flip:2282) DEBUG: Vblank took 76us
[126.442114] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.699944
last_received_ts = 126.699921
last_seq = 2785
current_ts = 126.716606
current_received_ts = 126.716385
current_seq = 2786
count = 399
seq_step = 1
[126.442160] (kms_flip:2282) DEBUG: Vblank took 20us
[126.458774] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.716606
last_received_ts = 126.716385
last_seq = 2786
current_ts = 126.733276
current_received_ts = 126.732994
current_seq = 2787
count = 400
seq_step = 1
[126.458824] (kms_flip:2282) DEBUG: Vblank took 23us
[126.475380] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.733276
last_received_ts = 126.732994
last_seq = 2787
current_ts = 126.749954
current_received_ts = 126.749649
current_seq = 2788
count = 401
seq_step = 1
[126.475431] (kms_flip:2282) DEBUG: Vblank took 23us
[126.492098] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.749954
last_received_ts = 126.749649
last_seq = 2788
current_ts = 126.766609
current_received_ts = 126.766373
current_seq = 2789
count = 402
seq_step = 1
[126.492145] (kms_flip:2282) DEBUG: Vblank took 21us
[126.508573] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.766609
last_received_ts = 126.766373
last_seq = 2789
current_ts = 126.783279
current_received_ts = 126.782845
current_seq = 2790
count = 403
seq_step = 1
[126.508622] (kms_flip:2282) DEBUG: Vblank took 22us
[126.525284] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.783279
last_received_ts = 126.782845
last_seq = 2790
current_ts = 126.799950
current_received_ts = 126.799561
current_seq = 2791
count = 404
seq_step = 1
[126.525330] (kms_flip:2282) DEBUG: Vblank took 20us
[126.542106] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.799950
last_received_ts = 126.799561
last_seq = 2791
current_ts = 126.816612
current_received_ts = 126.816383
current_seq = 2792
count = 405
seq_step = 1
[126.542153] (kms_flip:2282) DEBUG: Vblank took 21us
[126.558563] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.816612
last_received_ts = 126.816383
last_seq = 2792
current_ts = 126.833275
current_received_ts = 126.832832
current_seq = 2793
count = 406
seq_step = 1
[126.558615] (kms_flip:2282) DEBUG: Vblank took 23us
[126.575275] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.833275
last_received_ts = 126.832832
last_seq = 2793
current_ts = 126.849953
current_received_ts = 126.849548
current_seq = 2794
count = 407
seq_step = 1
[126.575318] (kms_flip:2282) DEBUG: Vblank took 19us
[126.592102] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.849953
last_received_ts = 126.849548
last_seq = 2794
current_ts = 126.866615
current_received_ts = 126.866379
current_seq = 2795
count = 408
seq_step = 1
[126.592149] (kms_flip:2282) DEBUG: Vblank took 21us
[126.608825] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.866615
last_received_ts = 126.866379
last_seq = 2795
current_ts = 126.883286
current_received_ts = 126.883102
current_seq = 2796
count = 409
seq_step = 1
[126.608873] (kms_flip:2282) DEBUG: Vblank took 22us
[126.625637] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.883286
last_received_ts = 126.883102
last_seq = 2796
current_ts = 126.899948
current_received_ts = 126.899918
current_seq = 2797
count = 410
seq_step = 1
[126.625684] (kms_flip:2282) DEBUG: Vblank took 21us
[126.642065] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.899948
last_received_ts = 126.899918
last_seq = 2797
current_ts = 126.916618
current_received_ts = 126.916344
current_seq = 2798
count = 411
seq_step = 1
[126.642118] (kms_flip:2282) DEBUG: Vblank took 23us
[126.658911] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.916618
last_received_ts = 126.916344
last_seq = 2798
current_ts = 126.933289
current_received_ts = 126.933182
current_seq = 2799
count = 412
seq_step = 1
[126.658966] (kms_flip:2282) DEBUG: Vblank took 26us
[126.675230] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.933289
last_received_ts = 126.933182
last_seq = 2799
current_ts = 126.949959
current_received_ts = 126.949509
current_seq = 2800
count = 413
seq_step = 1
[126.675277] (kms_flip:2282) DEBUG: Vblank took 21us
[126.692122] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.949959
last_received_ts = 126.949509
last_seq = 2800
current_ts = 126.966621
current_received_ts = 126.966400
current_seq = 2801
count = 414
seq_step = 1
[126.692172] (kms_flip:2282) DEBUG: Vblank took 23us
[126.708851] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.966621
last_received_ts = 126.966400
last_seq = 2801
current_ts = 126.983284
current_received_ts = 126.983131
current_seq = 2802
count = 415
seq_step = 1
[126.708901] (kms_flip:2282) DEBUG: Vblank took 23us
[126.725342] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.983284
last_received_ts = 126.983131
last_seq = 2802
current_ts = 126.999954
current_received_ts = 126.999619
current_seq = 2803
count = 416
seq_step = 1
[126.725399] (kms_flip:2282) DEBUG: Vblank took 26us
[126.742053] (kms_flip:2282) DEBUG: name = flip
last_ts = 126.999954
last_received_ts = 126.999619
last_seq = 2803
current_ts = 127.016624
current_received_ts = 127.016335
current_seq = 2804
count = 417
seq_step = 1
[126.742099] (kms_flip:2282) DEBUG: Vblank took 22us
[126.758832] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.016624
last_received_ts = 127.016335
last_seq = 2804
current_ts = 127.033279
current_received_ts = 127.033112
current_seq = 2805
count = 418
seq_step = 1
[126.758881] (kms_flip:2282) DEBUG: Vblank took 22us
[126.775496] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.033279
last_received_ts = 127.033112
last_seq = 2805
current_ts = 127.049957
current_received_ts = 127.049767
current_seq = 2806
count = 419
seq_step = 1
[126.775542] (kms_flip:2282) DEBUG: Vblank took 19us
[126.792116] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.049957
last_received_ts = 127.049767
last_seq = 2806
current_ts = 127.066628
current_received_ts = 127.066399
current_seq = 2807
count = 420
seq_step = 1
[126.792166] (kms_flip:2282) DEBUG: Vblank took 22us
[126.808763] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.066628
last_received_ts = 127.066399
last_seq = 2807
current_ts = 127.083282
current_received_ts = 127.082985
current_seq = 2808
count = 421
seq_step = 1
[126.808812] (kms_flip:2282) DEBUG: Vblank took 22us
[126.825930] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.083282
last_received_ts = 127.082985
last_seq = 2808
current_ts = 127.099960
current_received_ts = 127.100204
current_seq = 2809
count = 422
seq_step = 1
[126.825985] (kms_flip:2282) DEBUG: Vblank took 25us
[126.842102] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.099960
last_received_ts = 127.100204
last_seq = 2809
current_ts = 127.116615
current_received_ts = 127.116386
current_seq = 2810
count = 423
seq_step = 1
[126.842147] (kms_flip:2282) DEBUG: Vblank took 21us
[126.858834] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.116615
last_received_ts = 127.116386
last_seq = 2810
current_ts = 127.133286
current_received_ts = 127.133118
current_seq = 2811
count = 424
seq_step = 1
[126.858885] (kms_flip:2282) DEBUG: Vblank took 23us
[126.875300] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.133286
last_received_ts = 127.133118
last_seq = 2811
current_ts = 127.149948
current_received_ts = 127.149582
current_seq = 2812
count = 425
seq_step = 1
[126.875348] (kms_flip:2282) DEBUG: Vblank took 22us
[126.892140] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.149948
last_received_ts = 127.149582
last_seq = 2812
current_ts = 127.166618
current_received_ts = 127.166420
current_seq = 2813
count = 426
seq_step = 1
[126.892192] (kms_flip:2282) DEBUG: Vblank took 23us
[126.908878] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.166618
last_received_ts = 127.166420
last_seq = 2813
current_ts = 127.183289
current_received_ts = 127.183159
current_seq = 2814
count = 427
seq_step = 1
[126.908933] (kms_flip:2282) DEBUG: Vblank took 25us
[126.925342] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.183289
last_received_ts = 127.183159
last_seq = 2814
current_ts = 127.199959
current_received_ts = 127.199623
current_seq = 2815
count = 428
seq_step = 1
[126.925397] (kms_flip:2282) DEBUG: Vblank took 25us
[126.942111] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.199959
last_received_ts = 127.199623
last_seq = 2815
current_ts = 127.216621
current_received_ts = 127.216393
current_seq = 2816
count = 429
seq_step = 1
[126.942161] (kms_flip:2282) DEBUG: Vblank took 21us
[126.958855] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.216621
last_received_ts = 127.216393
last_seq = 2816
current_ts = 127.233299
current_received_ts = 127.233139
current_seq = 2817
count = 430
seq_step = 1
[126.958904] (kms_flip:2282) DEBUG: Vblank took 21us
[126.975341] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.233299
last_received_ts = 127.233139
last_seq = 2817
current_ts = 127.249962
current_received_ts = 127.249626
current_seq = 2818
count = 431
seq_step = 1
[126.975396] (kms_flip:2282) DEBUG: Vblank took 26us
[126.992110] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.249962
last_received_ts = 127.249626
last_seq = 2818
current_ts = 127.266624
current_received_ts = 127.266396
current_seq = 2819
count = 432
seq_step = 1
[126.992159] (kms_flip:2282) DEBUG: Vblank took 22us
[127.008727] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.266624
last_received_ts = 127.266396
last_seq = 2819
current_ts = 127.283295
current_received_ts = 127.282982
current_seq = 2820
count = 433
seq_step = 1
[127.008775] (kms_flip:2282) DEBUG: Vblank took 22us
[127.025824] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.283295
last_received_ts = 127.282982
last_seq = 2820
current_ts = 127.299965
current_received_ts = 127.299995
current_seq = 2821
count = 434
seq_step = 1
[127.025879] (kms_flip:2282) DEBUG: Vblank took 24us
[127.042118] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.299965
last_received_ts = 127.299995
last_seq = 2821
current_ts = 127.316620
current_received_ts = 127.316406
current_seq = 2822
count = 435
seq_step = 1
[127.042166] (kms_flip:2282) DEBUG: Vblank took 22us
[127.058844] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.316620
last_received_ts = 127.316406
last_seq = 2822
current_ts = 127.333290
current_received_ts = 127.333138
current_seq = 2823
count = 436
seq_step = 1
[127.058890] (kms_flip:2282) DEBUG: Vblank took 21us
[127.075300] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.333290
last_received_ts = 127.333138
last_seq = 2823
current_ts = 127.349968
current_received_ts = 127.349586
current_seq = 2824
count = 437
seq_step = 1
[127.075350] (kms_flip:2282) DEBUG: Vblank took 22us
[127.092127] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.349968
last_received_ts = 127.349586
last_seq = 2824
current_ts = 127.366631
current_received_ts = 127.366417
current_seq = 2825
count = 438
seq_step = 1
[127.092177] (kms_flip:2282) DEBUG: Vblank took 22us
[127.108832] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.366631
last_received_ts = 127.366417
last_seq = 2825
current_ts = 127.383293
current_received_ts = 127.383118
current_seq = 2826
count = 439
seq_step = 1
[127.108881] (kms_flip:2282) DEBUG: Vblank took 22us
[127.125301] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.383293
last_received_ts = 127.383118
last_seq = 2826
current_ts = 127.399971
current_received_ts = 127.399590
current_seq = 2827
count = 440
seq_step = 1
[127.125349] (kms_flip:2282) DEBUG: Vblank took 22us
[127.142113] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.399971
last_received_ts = 127.399590
last_seq = 2827
current_ts = 127.416634
current_received_ts = 127.416405
current_seq = 2828
count = 441
seq_step = 1
[127.142163] (kms_flip:2282) DEBUG: Vblank took 22us
[127.158865] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.416634
last_received_ts = 127.416405
last_seq = 2828
current_ts = 127.433304
current_received_ts = 127.433151
current_seq = 2829
count = 442
seq_step = 1
[127.158917] (kms_flip:2282) DEBUG: Vblank took 24us
[127.175288] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.433304
last_received_ts = 127.433151
last_seq = 2829
current_ts = 127.449966
current_received_ts = 127.449577
current_seq = 2830
count = 443
seq_step = 1
[127.175344] (kms_flip:2282) DEBUG: Vblank took 24us
[127.192155] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.449966
last_received_ts = 127.449577
last_seq = 2830
current_ts = 127.466637
current_received_ts = 127.466438
current_seq = 2831
count = 444
seq_step = 1
[127.192211] (kms_flip:2282) DEBUG: Vblank took 25us
[127.208853] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.466637
last_received_ts = 127.466438
last_seq = 2831
current_ts = 127.483292
current_received_ts = 127.483139
current_seq = 2832
count = 445
seq_step = 1
[127.208906] (kms_flip:2282) DEBUG: Vblank took 23us
[127.225742] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.483292
last_received_ts = 127.483139
last_seq = 2832
current_ts = 127.499962
current_received_ts = 127.499969
current_seq = 2833
count = 446
seq_step = 1
[127.225796] (kms_flip:2282) DEBUG: Vblank took 25us
[127.242120] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.499962
last_received_ts = 127.499969
last_seq = 2833
current_ts = 127.516624
current_received_ts = 127.516411
current_seq = 2834
count = 447
seq_step = 1
[127.242169] (kms_flip:2282) DEBUG: Vblank took 22us
[127.258826] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.516624
last_received_ts = 127.516411
last_seq = 2834
current_ts = 127.533302
current_received_ts = 127.533119
current_seq = 2835
count = 448
seq_step = 1
[127.258873] (kms_flip:2282) DEBUG: Vblank took 21us
[127.275300] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.533302
last_received_ts = 127.533119
last_seq = 2835
current_ts = 127.549973
current_received_ts = 127.549591
current_seq = 2836
count = 449
seq_step = 1
[127.275348] (kms_flip:2282) DEBUG: Vblank took 22us
[127.292102] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.549973
last_received_ts = 127.549591
last_seq = 2836
current_ts = 127.566635
current_received_ts = 127.566399
current_seq = 2837
count = 450
seq_step = 1
[127.292149] (kms_flip:2282) DEBUG: Vblank took 21us
[127.308843] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.566635
last_received_ts = 127.566399
last_seq = 2837
current_ts = 127.583298
current_received_ts = 127.583130
current_seq = 2838
count = 451
seq_step = 1
[127.308898] (kms_flip:2282) DEBUG: Vblank took 26us
[127.325302] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.583298
last_received_ts = 127.583130
last_seq = 2838
current_ts = 127.599976
current_received_ts = 127.599594
current_seq = 2839
count = 452
seq_step = 1
[127.325354] (kms_flip:2282) DEBUG: Vblank took 24us
[127.342104] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.599976
last_received_ts = 127.599594
last_seq = 2839
current_ts = 127.616631
current_received_ts = 127.616394
current_seq = 2840
count = 453
seq_step = 1
[127.342154] (kms_flip:2282) DEBUG: Vblank took 22us
[127.358915] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.616631
last_received_ts = 127.616394
last_seq = 2840
current_ts = 127.633308
current_received_ts = 127.633209
current_seq = 2841
count = 454
seq_step = 1
[127.358972] (kms_flip:2282) DEBUG: Vblank took 26us
[127.375284] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.633308
last_received_ts = 127.633209
last_seq = 2841
current_ts = 127.649971
current_received_ts = 127.649582
current_seq = 2842
count = 455
seq_step = 1
[127.375330] (kms_flip:2282) DEBUG: Vblank took 22us
[127.392108] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.649971
last_received_ts = 127.649582
last_seq = 2842
current_ts = 127.666641
current_received_ts = 127.666405
current_seq = 2843
count = 456
seq_step = 1
[127.392156] (kms_flip:2282) DEBUG: Vblank took 22us
[127.408794] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.666641
last_received_ts = 127.666405
last_seq = 2843
current_ts = 127.683296
current_received_ts = 127.683090
current_seq = 2844
count = 457
seq_step = 1
[127.408844] (kms_flip:2282) DEBUG: Vblank took 23us
[127.425633] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.683296
last_received_ts = 127.683090
last_seq = 2844
current_ts = 127.699966
current_received_ts = 127.699928
current_seq = 2845
count = 458
seq_step = 1
[127.425736] (kms_flip:2282) DEBUG: Vblank took 75us
[127.442119] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.699966
last_received_ts = 127.699928
last_seq = 2845
current_ts = 127.716644
current_received_ts = 127.716415
current_seq = 2846
count = 459
seq_step = 1
[127.442167] (kms_flip:2282) DEBUG: Vblank took 21us
[127.458817] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.716644
last_received_ts = 127.716415
last_seq = 2846
current_ts = 127.733299
current_received_ts = 127.733116
current_seq = 2847
count = 460
seq_step = 1
[127.458864] (kms_flip:2282) DEBUG: Vblank took 21us
[127.475307] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.733299
last_received_ts = 127.733116
last_seq = 2847
current_ts = 127.749962
current_received_ts = 127.749603
current_seq = 2848
count = 461
seq_step = 1
[127.475356] (kms_flip:2282) DEBUG: Vblank took 22us
[127.492109] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.749962
last_received_ts = 127.749603
last_seq = 2848
current_ts = 127.766640
current_received_ts = 127.766403
current_seq = 2849
count = 462
seq_step = 1
[127.492159] (kms_flip:2282) DEBUG: Vblank took 22us
[127.508848] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.766640
last_received_ts = 127.766403
last_seq = 2849
current_ts = 127.783302
current_received_ts = 127.783150
current_seq = 2850
count = 463
seq_step = 1
[127.508897] (kms_flip:2282) DEBUG: Vblank took 22us
[127.525373] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.783302
last_received_ts = 127.783150
last_seq = 2850
current_ts = 127.799965
current_received_ts = 127.799667
current_seq = 2851
count = 464
seq_step = 1
[127.525429] (kms_flip:2282) DEBUG: Vblank took 25us
[127.542154] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.799965
last_received_ts = 127.799667
last_seq = 2851
current_ts = 127.816643
current_received_ts = 127.816452
current_seq = 2852
count = 465
seq_step = 1
[127.542206] (kms_flip:2282) DEBUG: Vblank took 23us
[127.558643] (kms_flip:2282) DEBUG: name = flip
last_ts = 127.816643
last_received_ts = 127.816452
last_seq = 2852
current_ts = 127.833298
current_received_ts = 127.832954
current_seq = 2853
count = 466
seq_step = 1
[127.559900] (kms_flip:2282) DEBUG: Vblank took 1237us
[127.559915] (kms_flip:2282) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[127.560091] (kms_flip:2282) CRITICAL: Failed assertion: end - start < 500
[127.568303] (kms_flip:2282) igt_core-INFO: Stack trace:
[127.605369] (kms_flip:2282) igt_core-INFO:   #0 ../lib/igt_core.c:2074 __igt_fail_assert()
[127.607438] (kms_flip:2282) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
[127.607592] (kms_flip:2282) igt_core-INFO:   #2 ../tests/kms_flip.c:2029 run_pair()
[127.607756] (kms_flip:2282) igt_core-INFO:   #3 ../tests/kms_flip.c:2193 __igt_unique____real_main2105()
[127.607825] (kms_flip:2282) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
[127.628327] (kms_flip:2282) igt_core-INFO:   #5 [__libc_init_first+0x8a]
[127.630911] (kms_flip:2282) igt_core-INFO:   #6 [__libc_start_main+0x8b]
[127.631483] (kms_flip:2282) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest AC-HDMI-A1-HDMI-A2: FAIL (9.254s)
Dmesg
<6> [119.225746] [IGT] kms_flip: starting dynamic subtest AC-HDMI-A1-HDMI-A2
<7> [119.226796] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:182]
<7> [119.228282] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:185]
<7> [119.284976] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A]
<7> [119.285475] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [119.288174] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [119.289145] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [119.289807] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [119.290219] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000)
<7> [119.290841] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [119.291228] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [119.291824] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [119.292217] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [119.293476] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [119.294202] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [119.294844] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [119.295241] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [119.295803] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [119.296195] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [119.296753] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0)
<7> [119.297146] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0)
<7> [119.299575] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [119.300078] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [119.300458] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [119.301157] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [119.301847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [119.302237] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [119.303194] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [119.303901] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [119.304295] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [119.304864] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [119.305252] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0)
<7> [119.305811] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0)
<7> [119.306204] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [119.307953] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [119.308387] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [119.309237] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [119.309887] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [119.310288] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_hdmi_sink (expected yes, found no)
<7> [119.310881] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_infoframe (expected yes, found no)
<7> [119.312228] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [119.313573] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [119.313975] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [119.314354] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in port_clock (expected 222750, found 0)
<7> [119.315091] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000)
<7> [119.315492] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000)
<7> [119.316198] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in avi infoframe
<7> [119.316904] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.317300] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [119.317305] i915 0000:00:02.0: colorspace: RGB
<7> [119.317310] i915 0000:00:02.0: scan mode: Underscan
<7> [119.317313] i915 0000:00:02.0: colorimetry: No Data
<7> [119.317316] i915 0000:00:02.0: picture aspect: No Data
<7> [119.317320] i915 0000:00:02.0: active aspect: Same as Picture
<7> [119.317323] i915 0000:00:02.0: itc: No Data
<7> [119.317326] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [119.317330] i915 0000:00:02.0: quantization range: Full
<7> [119.317333] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [119.317336] i915 0000:00:02.0: video code: 0
<7> [119.317339] i915 0000:00:02.0: ycc quantization range: Full
<7> [119.317343] i915 0000:00:02.0: hdmi content type: Graphics
<7> [119.317346] i915 0000:00:02.0: pixel repeat: 0
<7> [119.317349] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [119.317352] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.317953] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in spd infoframe
<7> [119.318347] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.318911] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [119.318915] i915 0000:00:02.0: vendor: Intel
<7> [119.318919] i915 0000:00:02.0: product: Integrated gfx
<7> [119.318923] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [119.318926] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.319323] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hdmi infoframe
<7> [119.322059] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.322817] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [119.322823] i915 0000:00:02.0: empty frame
<7> [119.322827] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.323222] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:78:pipe A] fastset requirement not met, forcing full modeset
<7> [119.324198] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:78:pipe A] releasing PORT PLL B
<7> [119.324933] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:78:pipe A] dbuf slices 0x1 -> 0x0, ddb (0 - 510) -> (0 - 0), active pipes 0x3 -> 0x2
<7> [119.325362] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:121:pipe B] dbuf slices 0x1 -> 0x1, ddb (510 - 1020) -> (0 - 1020), active pipes 0x3 -> 0x2
<7> [119.326012] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:72:cursor A] ddb ( 497 - 510) -> ( 0 - 0), size 13 -> 0
<7> [119.326403] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:115:cursor B] ddb (1007 - 1020) -> ( 988 - 1020), size 13 -> 32
<7> [119.327036] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:78:pipe A] min cdclk: 192000 kHz -> 0 kHz
<7> [119.327445] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:78:pipe A] enable: no [modeset]
<7> [119.328970] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:36:plane 1A] fb: [NOFB], visible: no
<7> [119.329386] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:45:plane 2A] fb: [NOFB], visible: no
<7> [119.330087] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:plane 3A] fb: [NOFB], visible: no
<7> [119.330484] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no
<7> [119.331132] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:72:cursor A] fb: [NOFB], visible: no
<7> [119.331860] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:166:HDMI-A-1][ENCODER:165:DDI B/PHY B] Disable audio codec on [CRTC:78:pipe A]
<7> [119.352014] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port B
<7> [119.353037] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [119.370599] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time
<7> [119.474044] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_B
<7> [119.475500] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL B (active 0x1, on? 1) for [CRTC:78:pipe A]
<7> [119.478774] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL B
<7> [119.479210] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B]
<7> [119.479994] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C]
<7> [119.480666] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:166:HDMI-A-1]
<7> [119.498764] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-b
<7> [119.500081] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:78:pipe A]
<7> [119.504178] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:121:pipe B]
<7> [119.504357] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [119.504901] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [119.506364] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [119.506924] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [119.507308] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in lane_lat_optim_mask (expected 0x0000000d, found 0x00000000)
<7> [119.507740] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [119.508129] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [119.508597] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [119.508980] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [119.509370] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [119.509785] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [119.510186] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [119.510592] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [119.510970] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [119.511348] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [119.511753] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0)
<7> [119.512134] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0)
<7> [119.512632] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [119.513018] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [119.513397] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [119.513812] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [119.514216] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [119.514615] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [119.515034] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [119.515412] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [119.515839] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [119.516219] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [119.516628] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0)
<7> [119.517006] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0)
<7> [119.517394] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [119.517793] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [119.518173] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [119.518579] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [119.518986] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [119.519366] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in has_hdmi_sink (expected yes, found no)
<7> [119.519771] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in has_infoframe (expected yes, found no)
<7> [119.520156] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [119.520559] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [119.520937] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [119.521313] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in port_clock (expected 222750, found 0)
<7> [119.521716] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000)
<7> [119.522116] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000)
<7> [119.522498] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in avi infoframe
<7> [119.522979] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.523364] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [119.523369] i915 0000:00:02.0: colorspace: RGB
<7> [119.523373] i915 0000:00:02.0: scan mode: Underscan
<7> [119.523376] i915 0000:00:02.0: colorimetry: No Data
<7> [119.523379] i915 0000:00:02.0: picture aspect: No Data
<7> [119.523382] i915 0000:00:02.0: active aspect: Same as Picture
<7> [119.523386] i915 0000:00:02.0: itc: No Data
<7> [119.523389] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [119.523393] i915 0000:00:02.0: quantization range: Full
<7> [119.523396] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [119.523399] i915 0000:00:02.0: video code: 0
<7> [119.523402] i915 0000:00:02.0: ycc quantization range: Full
<7> [119.523405] i915 0000:00:02.0: hdmi content type: Graphics
<7> [119.523408] i915 0000:00:02.0: pixel repeat: 0
<7> [119.523411] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [119.523415] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.523829] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in spd infoframe
<7> [119.524210] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.524628] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [119.524633] i915 0000:00:02.0: vendor: Intel
<7> [119.524637] i915 0000:00:02.0: product: Integrated gfx
<7> [119.524640] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [119.524644] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.525027] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:121:pipe B] fastset requirement not met in hdmi infoframe
<7> [119.525404] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.525813] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [119.525817] i915 0000:00:02.0: empty frame
<7> [119.525820] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.526210] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:121:pipe B] fastset requirement not met, forcing full modeset
<7> [119.526622] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:121:pipe B] releasing PORT PLL C
<7> [119.527067] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:121:pipe B] dbuf slices 0x1 -> 0x0, ddb (0 - 1020) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [119.527548] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:115:cursor B] ddb ( 988 - 1020) -> ( 0 - 0), size 32 -> 0
<7> [119.527972] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:121:pipe B] min cdclk: 192000 kHz -> 0 kHz
<7> [119.528409] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change
<7> [119.528910] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 79200 kHz, actual 79200 kHz
<7> [119.529304] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 4, actual 4
<7> [119.529720] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:121:pipe B] enable: no [modeset]
<7> [119.530100] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:79:plane 1B] fb: [NOFB], visible: no
<7> [119.530503] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:88:plane 2B] fb: [NOFB], visible: no
<7> [119.530905] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:97:plane 3B] fb: [NOFB], visible: no
<7> [119.531283] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:106:plane 4B] fb: [NOFB], visible: no
<7> [119.531687] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:115:cursor B] fb: [NOFB], visible: no
<7> [119.532231] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:176:HDMI-A-2][ENCODER:175:DDI C/PHY C] Disable audio codec on [CRTC:121:pipe B]
<7> [119.564909] i915 0000:00:02.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port C
<7> [119.565544] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [119.581569] i915 0000:00:02.0: [drm:intel_ddi_disable_transcoder_func [i915]] Quirk Increase DDI disabled time
<7> [119.689898] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_C
<7> [119.691125] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PORT PLL C (active 0x2, on? 1) for [CRTC:121:pipe B]
<7> [119.693086] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PORT PLL C
<7> [119.694918] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 79200 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 4
<7> [119.695363] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B]
<7> [119.696045] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C]
<7> [119.696482] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:176:HDMI-A-2]
<7> [119.697337] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling dpio-common-c
<7> [119.697807] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [119.698848] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:121:pipe B]
<7> [119.700815] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:164:pipe C]
<7> [119.701374] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:164:pipe C]
<7> [119.701433] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:176:HDMI-A-2]
<7> [119.701835] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)
<7> [119.702346] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:164:pipe C] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [119.702826] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:175:DDI C/PHY C] [CRTC:164:pipe C]
<7> [119.703318] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.enable (expected no, found yes)
<7> [119.703760] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.active (expected no, found yes)
<7> [119.704144] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)
<7> [119.705695] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in lane_count (expected 0, found 4)
<7> [119.706121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d)
<7> [119.706917] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [119.707320] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [119.707921] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [119.708324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [119.708759] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [119.709152] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [119.709687] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [119.710079] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [119.710457] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [119.711785] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [119.712199] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083)
<7> [119.712808] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088)
<7> [119.713212] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [119.713805] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [119.714212] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [119.714731] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [119.715126] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [119.715555] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [119.715941] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [119.716324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [119.717763] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [119.718183] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [119.718711] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [119.719133] i915 0000:00:02.0: [drm:gen9_enable_dc5 [i915]] Enabling DC5
<7> [119.720926] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083)
<7> [119.721432] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088)
<7> [119.722088] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 01
<7> [119.723610] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [119.724010] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [119.724389] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [119.725344] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on
<7> [119.726875] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [119.727312] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [119.727927] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in has_hdmi_sink (expected no, found yes)
<7> [119.728322] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in has_infoframe (expected no, found yes)
<7> [119.728996] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in dpll_hw_state
<7> [119.729398] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.729822] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: ebb0: 0x0, ebb4: 0x0,pll0: 0x0, pll1: 0x0, pll2: 0x0, pll3: 0x0, pll6: 0x0, pll8: 0x0, pll9: 0x0, pll10: 0x0, pcsdw12: 0x0
<7> [119.730204] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.730773] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d
<7> [119.731170] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [119.732491] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [119.733300] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [119.733909] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in port_clock (expected 0, found 222750)
<7> [119.734306] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)
<7> [119.734721] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)
<7> [119.735106] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in avi infoframe
<7> [119.735654] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.736043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.736420] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [119.736427] i915 0000:00:02.0: colorspace: RGB
<7> [119.736431] i915 0000:00:02.0: scan mode: Underscan
<7> [119.736434] i915 0000:00:02.0: colorimetry: No Data
<7> [119.736438] i915 0000:00:02.0: picture aspect: No Data
<7> [119.736441] i915 0000:00:02.0: active aspect: Same as Picture
<7> [119.736444] i915 0000:00:02.0: itc: No Data
<7> [119.736448] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [119.736451] i915 0000:00:02.0: quantization range: Full
<7> [119.736454] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [119.736457] i915 0000:00:02.0: video code: 0
<7> [119.736460] i915 0000:00:02.0: ycc quantization range: Full
<7> [119.736464] i915 0000:00:02.0: hdmi content type: Graphics
<7> [119.736467] i915 0000:00:02.0: pixel repeat: 0
<7> [119.736470] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [119.736474] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in spd infoframe
<7> [119.736909] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.738910] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.739328] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [119.739332] i915 0000:00:02.0: vendor: Intel
<7> [119.739336] i915 0000:00:02.0: product: Integrated gfx
<7> [119.739340] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [119.739343] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:164:pipe C] fastset requirement not met in hdmi infoframe
<7> [119.739933] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.740564] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.740984] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [119.740988] i915 0000:00:02.0: empty frame
<7> [119.740993] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:164:pipe C] fastset requirement not met, forcing full modeset
<7> [119.741456] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:164:pipe C] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 1020), active pipes 0x0 -> 0x4
<7> [119.742176] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:122:plane 1C] ddb ( 0 - 0) -> ( 0 - 988), size 0 -> 988
<7> [119.742629] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:158:cursor C] ddb ( 0 - 0) -> ( 988 - 1020), size 0 -> 32
<7> [119.743006] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:122:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [119.743377] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:122:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0
<7> [119.743915] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:122:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0
<7> [119.744297] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:122:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0
<7> [119.744719] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:122:plane 1C] min_ddb_uv 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [119.745147] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:164:pipe C] min cdclk: 0 kHz -> 192000 kHz
<7> [119.746607] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 18563 kHz -> 9282 kHz
<7> [119.747067] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] Modeset required for cdclk change
<7> [119.748158] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 316800 kHz, actual 316800 kHz
<7> [119.748938] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 13, actual 13
<7> [119.749337] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:164:pipe C] using pre-allocated PORT PLL C
<7> [119.749969] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:164:pipe C] reserving PORT PLL C
<7> [119.750381] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:164:pipe C] enable: yes [modeset]
<7> [119.750829] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [119.751209] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: C, pipe bpp: 36, dithering: 0
<7> [119.752658] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [119.753090] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [119.753468] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [119.753910] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [119.754295] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71
<7> [119.754834] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6
<7> [119.755229] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [119.755234] i915 0000:00:02.0: colorspace: RGB
<7> [119.755237] i915 0000:00:02.0: scan mode: Underscan
<7> [119.755241] i915 0000:00:02.0: colorimetry: No Data
<7> [119.755244] i915 0000:00:02.0: picture aspect: No Data
<7> [119.755247] i915 0000:00:02.0: active aspect: Same as Picture
<7> [119.755251] i915 0000:00:02.0: itc: No Data
<7> [119.755254] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [119.755258] i915 0000:00:02.0: quantization range: Full
<7> [119.755261] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [119.755264] i915 0000:00:02.0: video code: 0
<7> [119.755267] i915 0000:00:02.0: ycc quantization range: Full
<7> [119.755271] i915 0000:00:02.0: hdmi content type: Graphics
<7> [119.755274] i915 0000:00:02.0: pixel repeat: 0
<7> [119.755277] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [119.755281] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [119.755285] i915 0000:00:02.0: vendor: Intel
<7> [119.755288] i915 0000:00:02.0: product: Integrated gfx
<7> [119.755295] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [119.755299] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [119.755303] i915 0000:00:02.0: empty frame
<7> [119.755307] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00
<7> [119.755742] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00
<7> [119.756304] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [119.756721] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [119.757100] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [119.757478] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [119.758029] i915 0000:00:02.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> [119.758428] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9
<7> [119.758834] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9
<7> [119.759214] i915 0000:00:02.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=1083-1088 vt=1125, flags=0x9
<7> [119.759757] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9
<7> [119.760143] i915 0000:00:02.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=1083-1088 vt=1125, flags=0x9
<7> [119.760546] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pixel rate 148500, min cdclk 192000, min voltage level 0
<7> [119.760930] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0
<7> [119.761490] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 1, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [119.761902] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [119.762287] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [119.762825] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [119.763217] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [119.763622] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d
<7> [119.764003] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [119.764474] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [119.764889] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [119.765265] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [119.765807] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [119.766190] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [119.766771] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [119.767156] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:122:plane 1C] fb: [FB:182] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [119.767566] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [119.767949] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [119.768578] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:131:plane 2C] fb: [NOFB], visible: no
<7> [119.768973] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:140:plane 3C] fb: [NOFB], visible: no
<7> [119.769353] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:149:plane 4C] fb: [NOFB], visible: no
<7> [119.769754] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:158:cursor C] fb: [NOFB], visible: no
<7> [119.770882] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on
<7> [119.771284] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [119.772345] i915 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 01 to 00
<7> [119.773578] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [119.774048] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-c
<7> [119.774748] i915 0000:00:02.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 316800 kHz, VCO 633600 kHz, ref 19200 kHz, bypass 19200 kHz, voltage level 13
<7> [119.775192] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B]
<7> [119.775706] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C]
<7> [119.776256] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL C (active 0x4, on? 0) for [CRTC:164:pipe C]
<7> [119.776805] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL C
<7> [119.777782] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C
<7> [119.778320] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe C
<7> [119.813282] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:176:HDMI-A-2][ENCODER:175:DDI C/PHY C] Enable audio codec on [CRTC:164:pipe C], 32 bytes ELD
<7> [119.828029] i915 0000:00:02.0: [drm:intel_audio_component_get_power [i915]] restored AUD_FREQ_CNTRL to 0x10
<7> [119.829934] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000)
<7> [119.830372] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N
<7> [119.831144] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:176:HDMI-A-2]
<7> [119.831884] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:164:pipe C]
<7> [119.836327] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:78:pipe A]
<7> [119.836397] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:166:HDMI-A-1]
<7> [119.836954] i915 0000:00:02.0: [drm:intel_hdmi_compute_output_format [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)
<7> [119.837469] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:78:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [119.838057] i915 0000:00:02.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:165:DDI B/PHY B] [CRTC:78:pipe A]
<7> [119.838441] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [119.839645] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [119.840040] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [119.840910] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [119.841307] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in lane_lat_optim_mask (expected 0x00000000, found 0x0000000d)
<7> [119.841916] azx_init_pci: snd_hda_intel 0000:00:0e.0: Clearing TCSEL
<7> [119.841932] azx_init_pci: snd_hda_intel 0000:00:0e.0: SCH snoop: Enabled
<7> [119.842118] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [119.842782] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [119.843170] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [119.843739] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [119.844124] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [119.844708] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [119.845093] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [119.845479] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [119.847191] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [119.847965] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [119.848364] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083)
<7> [119.849045] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088)
<7> [119.849436] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [119.850043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [119.850431] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [119.851025] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [119.851417] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [119.852549] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [119.852944] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [119.853322] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [119.854172] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [119.854856] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [119.855244] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083)
<7> [119.855907] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088)
<7> [119.856296] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [119.856847] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [119.857232] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [119.857829] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [119.858213] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [119.859580] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)
<7> [119.859986] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)
<7> [119.860369] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [119.861155] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [119.861792] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [119.862179] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in port_clock (expected 0, found 222750)
<7> [119.862735] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)
<7> [119.863126] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)
<7> [119.863722] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in avi infoframe
<7> [119.864109] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.864489] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.865830] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [119.865836] i915 0000:00:02.0: colorspace: RGB
<7> [119.865840] i915 0000:00:02.0: scan mode: Underscan
<7> [119.865843] i915 0000:00:02.0: colorimetry: No Data
<7> [119.865846] i915 0000:00:02.0: picture aspect: No Data
<7> [119.865849] i915 0000:00:02.0: active aspect: Same as Picture
<7> [119.865852] i915 0000:00:02.0: itc: No Data
<7> [119.865856] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [119.865859] i915 0000:00:02.0: quantization range: Full
<7> [119.865862] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [119.865866] i915 0000:00:02.0: video code: 0
<7> [119.865869] i915 0000:00:02.0: ycc quantization range: Full
<7> [119.865872] i915 0000:00:02.0: hdmi content type: Graphics
<7> [119.865875] i915 0000:00:02.0: pixel repeat: 0
<7> [119.865878] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [119.865882] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in spd infoframe
<7> [119.866280] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.867073] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.867472] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [119.867476] i915 0000:00:02.0: vendor: Intel
<7> [119.867480] i915 0000:00:02.0: product: Integrated gfx
<7> [119.867483] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [119.867487] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:78:pipe A] fastset requirement not met in hdmi infoframe
<7> [119.868224] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [119.868782] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [119.869165] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [119.869169] i915 0000:00:02.0: empty frame
<7> [119.869174] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:78:pipe A] fastset requirement not met, forcing full modeset
<7> [119.869835] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:78:pipe A] dbuf slices 0x0 -> 0x1, ddb (0 - 0) -> (0 - 510), active pipes 0x4 -> 0x5
<7> [119.870250] i915 0000:00:02.0: [drm:skl_compute_wm [i915]] [CRTC:164:pipe C] dbuf slices 0x1 -> 0x1, ddb (0 - 1020) -> (510 - 1020), active pipes 0x4 -> 0x5
<7> [119.871996] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:36:plane 1A] ddb ( 0 - 0) -> ( 0 - 497), size 0 -> 497
<7> [119.872730] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:72:cursor A] ddb ( 0 - 0) -> ( 497 - 510), size 0 -> 13
<7> [119.873139] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36: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> [119.873704] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 1, 1, 2, 2, 2, 2, 2, 0, 0, 0
<7> [119.874083] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 16, 16, 33, 33, 33, 33, 33, 30, 0, 0
<7> [119.874459] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 17, 17, 17, 34, 34, 34, 34, 34, 31, 0, 0
<7> [119.874956] i915 0000:00:02.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:36:plane 1A] min_ddb_uv 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [119.875338] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:122:plane 1C] ddb ( 0 - 988) -> ( 510 - 1007), size 988 -> 497
<7> [119.875800] i915 0000:00:02.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:158:cursor C] ddb ( 988 - 1020) -> (1007 - 1020), size 32 -> 13
<7> [119.876221] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:78:pipe A] min cdclk: 0 kHz -> 192000 kHz
<7> [119.877524] i915 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [i915]] dbuf bandwidth min cdclk: 9282 kHz -> 18563 kHz
<7> [119.877946] i915 0000:00:02.0: [drm:bxt_get_dpll [i915]] [CRTC:78:pipe A] using pre-allocated PORT PLL B
<7> [119.878332] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:78:pipe A] reserving PORT PLL B
<7> [119.878840] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:78:pipe A] enable: yes [modeset]
<7> [119.879237] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [119.879693] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0
<7> [119.880084] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [119.880464] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [119.880935] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [119.881318] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [119.881777] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71
<7> [119.882159] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6
<7> [119.882680] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [119.882685] i915 0000:00:02.0: colorspace: RGB
<7> [119.882689] i915 0000:00:02.0: scan mode: Underscan
<7> [119.882692] i915 0000:00:02.0: colorimetry: No Data
<7> [119.882695] i915 0000:00:02.0: picture aspect: No Data
<7> [119.882699] i915 0000:00:02.0: active aspect: Same as Picture
<7> [119.882702] i915 0000:00:02.0: itc: No Data
<7> [119.882705] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [119.882708] i915 0000:00:02.0: quantization range: Full
<7> [119.882711] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [119.882714] i915 0000:00:02.0: video code: 0
<7> [119.882717] i915 0000:00:02.0: ycc quantization range: Full
<7> [119.882720] i915 0000:00:02.0: hdmi content type: Graphics
<7> [119.882723] i915 0000:00:02.0: pixel repeat: 0
<7> [119.882726] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [119.882730] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [119.882734] i915 0000:00:02.0: vendor: Intel
<7> [119.882737] i915 0000:00:02.0: product: Integrated gfx
<7> [119.882740] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [119.882744] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [119.882747] i915 0000:00:02.0: empty frame
<7> [119.882750] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 07 00 66 10 00 01 00 00 00 00 00 00 00 00
<7> [119.883143] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 05 e3 cd 0c 32 38 45 38 35 30 09 07 07 00 00 00
<7> [119.883669] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [119.884054] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [119.884429] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [119.884900] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [119.885280] i915 0000:00:02.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> [119.885756] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9
<7> [119.886139] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9
<7> [119.886609] i915 0000:00:02.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=1083-1088 vt=1125, flags=0x9
<7> [119.886991] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9
<7> [119.887375] i915 0000:00:02.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=1083-1088 vt=1125, flags=0x9
<7> [119.887858] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 222750, pixel rate 148500, min cdclk 192000, min voltage level 0
<7> [119.888245] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 59, ips linetime: 0
<7> [119.888713] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [119.889094] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [119.889472] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [119.889955] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [119.890337] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [119.890801] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: ebb0: 0x6200, ebb4: 0x2000,pll0: 0x21, pll1: 0x100, pll2: 0x1a6666, pll3: 0x10000, pll6: 0x30904, pll8: 0x8, pll9: 0xa, pll10: 0x8003c00, pcsdw12: 0x4d
<7> [119.891183] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [119.891646] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [119.892030] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [119.892408] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [119.892892] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [119.893278] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [119.893728] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [119.894108] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:36:plane 1A] fb: [FB:182] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [119.894489] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [119.894964] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [119.895350] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:45:plane 2A] fb: [NOFB], visible: no
<7> [119.895818] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:54:plane 3A] fb: [NOFB], visible: no
<7> [119.896199] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:63:plane 4A] fb: [NOFB], visible: no
<7> [119.896660] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:72:cursor A] fb: [NOFB], visible: no
<7> [119.897368] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling dpio-common-b
<7> [119.898339] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:165:DDI B/PHY B]
<7> [119.898759] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:175:DDI C/PHY C]
<7> [119.913323] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PORT PLL B (active 0x1, on? 0) for [CRTC:78:pipe A]
<7> [119.913837] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PORT PLL B
<7> [119.914410] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_B
<7> [119.915378] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [119.933683] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] reserved 16588800 bytes of contiguous stolen space for FBC, limit: 1
<7> [119.934137] i915 0000:00:02.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:36:plane 1A]
<7> [119.950337] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:166:HDMI-A-1][ENCODER:165:DDI B/PHY B] Enable audio codec on [CRTC:78:pipe A], 32 bytes ELD
<7> [119.966975] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 148500 (0x00090000)
<7> [119.967387] i915 0000:00:02.0: [drm:hsw_audio_config_update [i915]] using automatic N
<7> [119.967963] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:166:HDMI-A-1]
<7> [119.968978] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:78:pipe A]
<6> [128.479840] [IGT] kms_flip: finished subtest AC-HDMI-A1-HDMI-A2, FAIL
Created at 2026-05-15 05:04:05