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

Result: Fail

git-log-oneline i915_display_info4 igt_runner4 runtimes4 results4.json results4-i915-load.json guc_logs4.tar i915_display_info_post_exec4 boot4 dmesg4

DetailValue
Duration 2.23 seconds
Hostname 
shard-dg2-6
Igt-Version 
IGT-Version: 2.4-g02b0e01dd (x86_64) (Linux: 7.1.0-rc1-CI_DRM_18377-ga53aafc879e9+ x86_64)
Out 
Starting dynamic subtest: D-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest D-HDMI-A3: FAIL (2.227s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (25.262s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2352 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2961 igt_atexit_handler()
  #3 [erand48_r+0x1d6]
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2416 igt_exit()
  #6 [main+0x3f]
  #7 [__libc_init_first+0x8a]
  #8 [__libc_start_main+0x8b]
  #9 [_start+0x25]
Err 
Starting dynamic subtest: D-HDMI-A3
(kms_flip:2351) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2351) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2351) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest D-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:2351) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2351) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
(kms_flip:2351) DEBUG: No stale events found
(kms_flip:2351) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2351) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2351) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 289.909454
current_received_ts = 289.909088
current_seq = 215
count = 0
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 289.909454
last_received_ts = 289.909088
last_seq = 215
current_ts = 289.926117
current_received_ts = 289.925720
current_seq = 216
count = 1
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 289.926117
last_received_ts = 289.925720
last_seq = 216
current_ts = 289.942780
current_received_ts = 289.942352
current_seq = 217
count = 2
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 289.942780
last_received_ts = 289.942352
last_seq = 217
current_ts = 289.959442
current_received_ts = 289.959106
current_seq = 218
count = 3
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 289.959442
last_received_ts = 289.959106
last_seq = 218
current_ts = 289.976105
current_received_ts = 289.975739
current_seq = 219
count = 4
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 289.976105
last_received_ts = 289.975739
last_seq = 219
current_ts = 289.992767
current_received_ts = 289.992371
current_seq = 220
count = 5
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 289.992767
last_received_ts = 289.992371
last_seq = 220
current_ts = 290.009430
current_received_ts = 290.009094
current_seq = 221
count = 6
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 61us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.009430
last_received_ts = 290.009094
last_seq = 221
current_ts = 290.026123
current_received_ts = 290.025757
current_seq = 222
count = 7
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.026123
last_received_ts = 290.025757
last_seq = 222
current_ts = 290.042786
current_received_ts = 290.042328
current_seq = 223
count = 8
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.042786
last_received_ts = 290.042328
last_seq = 223
current_ts = 290.059448
current_received_ts = 290.059113
current_seq = 224
count = 9
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 60us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.059448
last_received_ts = 290.059113
last_seq = 224
current_ts = 290.076111
current_received_ts = 290.075714
current_seq = 225
count = 10
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.076111
last_received_ts = 290.075714
last_seq = 225
current_ts = 290.092804
current_received_ts = 290.092346
current_seq = 226
count = 11
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.092804
last_received_ts = 290.092346
last_seq = 226
current_ts = 290.109467
current_received_ts = 290.109100
current_seq = 227
count = 12
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 59us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.109467
last_received_ts = 290.109100
last_seq = 227
current_ts = 290.126129
current_received_ts = 290.125763
current_seq = 228
count = 13
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.126129
last_received_ts = 290.125763
last_seq = 228
current_ts = 290.142792
current_received_ts = 290.142365
current_seq = 229
count = 14
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 60us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.142792
last_received_ts = 290.142365
last_seq = 229
current_ts = 290.159454
current_received_ts = 290.159119
current_seq = 230
count = 15
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 97us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.159454
last_received_ts = 290.159119
last_seq = 230
current_ts = 290.176117
current_received_ts = 290.175781
current_seq = 231
count = 16
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 60us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.176117
last_received_ts = 290.175781
last_seq = 231
current_ts = 290.192810
current_received_ts = 290.192352
current_seq = 232
count = 17
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.192810
last_received_ts = 290.192352
last_seq = 232
current_ts = 290.209473
current_received_ts = 290.209137
current_seq = 233
count = 18
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.209473
last_received_ts = 290.209137
last_seq = 233
current_ts = 290.226135
current_received_ts = 290.225677
current_seq = 234
count = 19
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.226135
last_received_ts = 290.225677
last_seq = 234
current_ts = 290.242798
current_received_ts = 290.242371
current_seq = 235
count = 20
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.242798
last_received_ts = 290.242371
last_seq = 235
current_ts = 290.259491
current_received_ts = 290.259094
current_seq = 236
count = 21
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.259491
last_received_ts = 290.259094
last_seq = 236
current_ts = 290.276154
current_received_ts = 290.275757
current_seq = 237
count = 22
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.276154
last_received_ts = 290.275757
last_seq = 237
current_ts = 290.292816
current_received_ts = 290.292328
current_seq = 238
count = 23
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.292816
last_received_ts = 290.292328
last_seq = 238
current_ts = 290.309479
current_received_ts = 290.309113
current_seq = 239
count = 24
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.309479
last_received_ts = 290.309113
last_seq = 239
current_ts = 290.326141
current_received_ts = 290.325745
current_seq = 240
count = 25
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.326141
last_received_ts = 290.325745
last_seq = 240
current_ts = 290.342834
current_received_ts = 290.342316
current_seq = 241
count = 26
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.342834
last_received_ts = 290.342316
last_seq = 241
current_ts = 290.359497
current_received_ts = 290.359100
current_seq = 242
count = 27
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.359497
last_received_ts = 290.359100
last_seq = 242
current_ts = 290.376160
current_received_ts = 290.375763
current_seq = 243
count = 28
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.376160
last_received_ts = 290.375763
last_seq = 243
current_ts = 290.392822
current_received_ts = 290.392365
current_seq = 244
count = 29
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.392822
last_received_ts = 290.392365
last_seq = 244
current_ts = 290.409485
current_received_ts = 290.409149
current_seq = 245
count = 30
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.409485
last_received_ts = 290.409149
last_seq = 245
current_ts = 290.426178
current_received_ts = 290.425751
current_seq = 246
count = 31
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.426178
last_received_ts = 290.425751
last_seq = 246
current_ts = 290.442841
current_received_ts = 290.442413
current_seq = 247
count = 32
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.442841
last_received_ts = 290.442413
last_seq = 247
current_ts = 290.459503
current_received_ts = 290.459167
current_seq = 248
count = 33
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.459503
last_received_ts = 290.459167
last_seq = 248
current_ts = 290.476166
current_received_ts = 290.475769
current_seq = 249
count = 34
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.476166
last_received_ts = 290.475769
last_seq = 249
current_ts = 290.492859
current_received_ts = 290.492401
current_seq = 250
count = 35
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.492859
last_received_ts = 290.492401
last_seq = 250
current_ts = 290.509521
current_received_ts = 290.509155
current_seq = 251
count = 36
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.509521
last_received_ts = 290.509155
last_seq = 251
current_ts = 290.526184
current_received_ts = 290.525757
current_seq = 252
count = 37
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.526184
last_received_ts = 290.525757
last_seq = 252
current_ts = 290.542847
current_received_ts = 290.542419
current_seq = 253
count = 38
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.542847
last_received_ts = 290.542419
last_seq = 253
current_ts = 290.559540
current_received_ts = 290.559174
current_seq = 254
count = 39
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.559540
last_received_ts = 290.559174
last_seq = 254
current_ts = 290.576202
current_received_ts = 290.575775
current_seq = 255
count = 40
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.576202
last_received_ts = 290.575775
last_seq = 255
current_ts = 290.592865
current_received_ts = 290.592407
current_seq = 256
count = 41
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.592865
last_received_ts = 290.592407
last_seq = 256
current_ts = 290.609528
current_received_ts = 290.609161
current_seq = 257
count = 42
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.609528
last_received_ts = 290.609161
last_seq = 257
current_ts = 290.626190
current_received_ts = 290.625824
current_seq = 258
count = 43
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.626190
last_received_ts = 290.625824
last_seq = 258
current_ts = 290.642853
current_received_ts = 290.642426
current_seq = 259
count = 44
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.642853
last_received_ts = 290.642426
last_seq = 259
current_ts = 290.659515
current_received_ts = 290.659180
current_seq = 260
count = 45
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.659515
last_received_ts = 290.659180
last_seq = 260
current_ts = 290.676208
current_received_ts = 290.675781
current_seq = 261
count = 46
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.676208
last_received_ts = 290.675781
last_seq = 261
current_ts = 290.692871
current_received_ts = 290.692444
current_seq = 262
count = 47
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.692871
last_received_ts = 290.692444
last_seq = 262
current_ts = 290.709534
current_received_ts = 290.709198
current_seq = 263
count = 48
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.709534
last_received_ts = 290.709198
last_seq = 263
current_ts = 290.726196
current_received_ts = 290.725800
current_seq = 264
count = 49
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.726196
last_received_ts = 290.725800
last_seq = 264
current_ts = 290.742889
current_received_ts = 290.742462
current_seq = 265
count = 50
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.742889
last_received_ts = 290.742462
last_seq = 265
current_ts = 290.759552
current_received_ts = 290.759186
current_seq = 266
count = 51
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.759552
last_received_ts = 290.759186
last_seq = 266
current_ts = 290.776215
current_received_ts = 290.775787
current_seq = 267
count = 52
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.776215
last_received_ts = 290.775787
last_seq = 267
current_ts = 290.792877
current_received_ts = 290.792450
current_seq = 268
count = 53
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.792877
last_received_ts = 290.792450
last_seq = 268
current_ts = 290.809570
current_received_ts = 290.809204
current_seq = 269
count = 54
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.809570
last_received_ts = 290.809204
last_seq = 269
current_ts = 290.826233
current_received_ts = 290.825806
current_seq = 270
count = 55
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.826233
last_received_ts = 290.825806
last_seq = 270
current_ts = 290.842896
current_received_ts = 290.842499
current_seq = 271
count = 56
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.842896
last_received_ts = 290.842499
last_seq = 271
current_ts = 290.859558
current_received_ts = 290.859192
current_seq = 272
count = 57
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.859558
last_received_ts = 290.859192
last_seq = 272
current_ts = 290.876221
current_received_ts = 290.875824
current_seq = 273
count = 58
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.876221
last_received_ts = 290.875824
last_seq = 273
current_ts = 290.892883
current_received_ts = 290.892456
current_seq = 274
count = 59
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.892883
last_received_ts = 290.892456
last_seq = 274
current_ts = 290.909576
current_received_ts = 290.909180
current_seq = 275
count = 60
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 59us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.909576
last_received_ts = 290.909180
last_seq = 275
current_ts = 290.926239
current_received_ts = 290.925873
current_seq = 276
count = 61
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 60us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.926239
last_received_ts = 290.925873
last_seq = 276
current_ts = 290.942902
current_received_ts = 290.942535
current_seq = 277
count = 62
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 59us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.942902
last_received_ts = 290.942535
last_seq = 277
current_ts = 290.959595
current_received_ts = 290.959167
current_seq = 278
count = 63
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.959595
last_received_ts = 290.959167
last_seq = 278
current_ts = 290.976257
current_received_ts = 290.975830
current_seq = 279
count = 64
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.976257
last_received_ts = 290.975830
last_seq = 279
current_ts = 290.992920
current_received_ts = 290.992554
current_seq = 280
count = 65
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 290.992920
last_received_ts = 290.992554
last_seq = 280
current_ts = 291.009583
current_received_ts = 291.009125
current_seq = 281
count = 66
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.009583
last_received_ts = 291.009125
last_seq = 281
current_ts = 291.026245
current_received_ts = 291.025848
current_seq = 282
count = 67
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.026245
last_received_ts = 291.025848
last_seq = 282
current_ts = 291.042908
current_received_ts = 291.042511
current_seq = 283
count = 68
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.042908
last_received_ts = 291.042511
last_seq = 283
current_ts = 291.059601
current_received_ts = 291.059235
current_seq = 284
count = 69
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.059601
last_received_ts = 291.059235
last_seq = 284
current_ts = 291.076263
current_received_ts = 291.075867
current_seq = 285
count = 70
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.076263
last_received_ts = 291.075867
last_seq = 285
current_ts = 291.092926
current_received_ts = 291.092529
current_seq = 286
count = 71
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.092926
last_received_ts = 291.092529
last_seq = 286
current_ts = 291.109589
current_received_ts = 291.109222
current_seq = 287
count = 72
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.109589
last_received_ts = 291.109222
last_seq = 287
current_ts = 291.126251
current_received_ts = 291.125854
current_seq = 288
count = 73
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.126251
last_received_ts = 291.125854
last_seq = 288
current_ts = 291.142944
current_received_ts = 291.142517
current_seq = 289
count = 74
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.142944
last_received_ts = 291.142517
last_seq = 289
current_ts = 291.159607
current_received_ts = 291.159241
current_seq = 290
count = 75
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.159607
last_received_ts = 291.159241
last_seq = 290
current_ts = 291.176270
current_received_ts = 291.175873
current_seq = 291
count = 76
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.176270
last_received_ts = 291.175873
last_seq = 291
current_ts = 291.192932
current_received_ts = 291.192535
current_seq = 292
count = 77
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.192932
last_received_ts = 291.192535
last_seq = 292
current_ts = 291.209625
current_received_ts = 291.209229
current_seq = 293
count = 78
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.209625
last_received_ts = 291.209229
last_seq = 293
current_ts = 291.226288
current_received_ts = 291.225861
current_seq = 294
count = 79
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.226288
last_received_ts = 291.225861
last_seq = 294
current_ts = 291.242950
current_received_ts = 291.242523
current_seq = 295
count = 80
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.242950
last_received_ts = 291.242523
last_seq = 295
current_ts = 291.259613
current_received_ts = 291.259247
current_seq = 296
count = 81
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.259613
last_received_ts = 291.259247
last_seq = 296
current_ts = 291.276306
current_received_ts = 291.275879
current_seq = 297
count = 82
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.276306
last_received_ts = 291.275879
last_seq = 297
current_ts = 291.292969
current_received_ts = 291.292572
current_seq = 298
count = 83
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.292969
last_received_ts = 291.292572
last_seq = 298
current_ts = 291.309631
current_received_ts = 291.309265
current_seq = 299
count = 84
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.309631
last_received_ts = 291.309265
last_seq = 299
current_ts = 291.326294
current_received_ts = 291.325806
current_seq = 300
count = 85
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 53us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.326294
last_received_ts = 291.325806
last_seq = 300
current_ts = 291.342957
current_received_ts = 291.342560
current_seq = 301
count = 86
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.342957
last_received_ts = 291.342560
last_seq = 301
current_ts = 291.359619
current_received_ts = 291.359283
current_seq = 302
count = 87
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.359619
last_received_ts = 291.359283
last_seq = 302
current_ts = 291.376312
current_received_ts = 291.375885
current_seq = 303
count = 88
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 54us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.376312
last_received_ts = 291.375885
last_seq = 303
current_ts = 291.392975
current_received_ts = 291.392548
current_seq = 304
count = 89
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 55us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.392975
last_received_ts = 291.392548
last_seq = 304
current_ts = 291.409637
current_received_ts = 291.410126
current_seq = 305
count = 90
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.409637
last_received_ts = 291.410126
last_seq = 305
current_ts = 291.426300
current_received_ts = 291.425934
current_seq = 306
count = 91
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 90us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.426300
last_received_ts = 291.425934
last_seq = 306
current_ts = 291.442963
current_received_ts = 291.442627
current_seq = 307
count = 92
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 60us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.442963
last_received_ts = 291.442627
last_seq = 307
current_ts = 291.459656
current_received_ts = 291.459320
current_seq = 308
count = 93
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.459656
last_received_ts = 291.459320
last_seq = 308
current_ts = 291.476318
current_received_ts = 291.475952
current_seq = 309
count = 94
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 96us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.476318
last_received_ts = 291.475952
last_seq = 309
current_ts = 291.492981
current_received_ts = 291.492615
current_seq = 310
count = 95
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.492981
last_received_ts = 291.492615
last_seq = 310
current_ts = 291.509644
current_received_ts = 291.509308
current_seq = 311
count = 96
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.509644
last_received_ts = 291.509308
last_seq = 311
current_ts = 291.526306
current_received_ts = 291.525970
current_seq = 312
count = 97
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 103us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.526306
last_received_ts = 291.525970
last_seq = 312
current_ts = 291.542999
current_received_ts = 291.542633
current_seq = 313
count = 98
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.542999
last_received_ts = 291.542633
last_seq = 313
current_ts = 291.559662
current_received_ts = 291.559326
current_seq = 314
count = 99
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.559662
last_received_ts = 291.559326
last_seq = 314
current_ts = 291.576324
current_received_ts = 291.575989
current_seq = 315
count = 100
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 59us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.576324
last_received_ts = 291.575989
last_seq = 315
current_ts = 291.593018
current_received_ts = 291.592621
current_seq = 316
count = 101
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.593018
last_received_ts = 291.592621
last_seq = 316
current_ts = 291.609680
current_received_ts = 291.609253
current_seq = 317
count = 102
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.609680
last_received_ts = 291.609253
last_seq = 317
current_ts = 291.626343
current_received_ts = 291.625977
current_seq = 318
count = 103
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.626343
last_received_ts = 291.625977
last_seq = 318
current_ts = 291.643005
current_received_ts = 291.642639
current_seq = 319
count = 104
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.643005
last_received_ts = 291.642639
last_seq = 319
current_ts = 291.659698
current_received_ts = 291.659332
current_seq = 320
count = 105
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 92us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.659698
last_received_ts = 291.659332
last_seq = 320
current_ts = 291.676361
current_received_ts = 291.675964
current_seq = 321
count = 106
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.676361
last_received_ts = 291.675964
last_seq = 321
current_ts = 291.693024
current_received_ts = 291.692627
current_seq = 322
count = 107
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.693024
last_received_ts = 291.692627
last_seq = 322
current_ts = 291.709686
current_received_ts = 291.709320
current_seq = 323
count = 108
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 56us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.709686
last_received_ts = 291.709320
last_seq = 323
current_ts = 291.726349
current_received_ts = 291.725983
current_seq = 324
count = 109
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.726349
last_received_ts = 291.725983
last_seq = 324
current_ts = 291.743011
current_received_ts = 291.742645
current_seq = 325
count = 110
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.743011
last_received_ts = 291.742645
last_seq = 325
current_ts = 291.759705
current_received_ts = 291.759338
current_seq = 326
count = 111
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 59us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.759705
last_received_ts = 291.759338
last_seq = 326
current_ts = 291.776367
current_received_ts = 291.776062
current_seq = 327
count = 112
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.776367
last_received_ts = 291.776062
last_seq = 327
current_ts = 291.793030
current_received_ts = 291.792664
current_seq = 328
count = 113
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.793030
last_received_ts = 291.792664
last_seq = 328
current_ts = 291.809692
current_received_ts = 291.809296
current_seq = 329
count = 114
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.809692
last_received_ts = 291.809296
last_seq = 329
current_ts = 291.826385
current_received_ts = 291.826050
current_seq = 330
count = 115
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 58us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.826385
last_received_ts = 291.826050
last_seq = 330
current_ts = 291.843048
current_received_ts = 291.842682
current_seq = 331
count = 116
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 57us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.843048
last_received_ts = 291.842682
last_seq = 331
current_ts = 291.859711
current_received_ts = 291.859283
current_seq = 332
count = 117
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 90us
(kms_flip:2351) DEBUG: name = flip
last_ts = 291.859711
last_received_ts = 291.859283
last_seq = 332
current_ts = 291.876373
current_received_ts = 291.876923
current_seq = 333
count = 118
seq_step = 1
(kms_flip:2351) DEBUG: Vblank took 906us
(kms_flip:2351) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2351) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2351) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2351) igt_core-INFO: Stack trace:
(kms_flip:2351) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2351) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2351) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2351) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2351) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2351) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2351) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2351) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest D-HDMI-A3: FAIL (2.227s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (25.262s)
(kms_flip:2351) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352:
(kms_flip:2351) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:2351) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:2351) igt_kms-CRITICAL: DPMS property not found on 556
Dmesg
<6> [289.530513] [IGT] kms_flip: starting dynamic subtest D-HDMI-A3
<7> [289.530900] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:559]
<7> [289.531048] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:561]
<7> [289.531434] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.531818] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.553033] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.553393] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.560656] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.560950] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.581722] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.582020] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [289.587099] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [289.587303] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C]
<7> [289.587443] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe B]
<7> [289.587525] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [289.587701] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [289.587854] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [289.588007] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [289.588161] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [289.588437] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [289.588591] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [289.588744] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [289.588897] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [289.589050] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [289.589266] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [289.589504] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [289.589658] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [289.589812] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [289.589967] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [289.590120] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [289.590369] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [289.590522] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [289.590675] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [289.590827] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [289.590980] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [289.591133] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [289.591397] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [289.591569] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [289.591722] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [289.591876] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [289.592028] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [289.592185] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [289.592370] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [289.592522] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [289.592675] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [289.592828] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [289.592982] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [289.593135] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [289.593340] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [289.593497] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [289.593649] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [289.593803] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe B] fastset requirement not met, forcing full modeset
<7> [289.593976] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [289.594125] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [289.594519] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor B] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [289.594715] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe B] min cdclk: 74250 kHz -> 0 kHz
<7> [289.594869] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [289.595019] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [289.595172] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe B] enable: no [modeset]
<7> [289.595373] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1B] fb: [NOFB], visible: no
<7> [289.595595] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2B] fb: [NOFB], visible: no
<7> [289.595747] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3B] fb: [NOFB], visible: no
<7> [289.595899] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4B] fb: [NOFB], visible: no
<7> [289.596051] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5B] fb: [NOFB], visible: no
<7> [289.596227] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor B] fb: [NOFB], visible: no
<7> [289.596508] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [289.613444] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [289.613672] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [289.613825] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [289.613977] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [289.614129] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [289.614288] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [289.614440] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [289.614592] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [289.614743] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [289.614894] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [289.615045] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [289.615222] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [289.615387] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [289.615539] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [289.615690] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [289.615841] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [289.615992] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [289.616163] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [289.616383] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [289.616534] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [289.616685] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [289.616836] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [289.617028] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [289.617321] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_B
<7> [289.617537] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [289.617733] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe B]
<7> [289.618110] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [289.618294] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [289.618327] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:556:HDMI-A-3]
<7> [289.618403] i915 0000:03:00.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [289.618567] i915 0000:03:00.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [289.618715] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [289.618872] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:505:pipe D]
<7> [289.619021] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.enable (expected no, found yes)
<7> [289.619184] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.active (expected no, found yes)
<7> [289.619341] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in cpu_transcoder (expected -1, found 3)
<7> [289.619498] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in lane_count (expected 0, found 4)
<7> [289.619654] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [289.619810] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [289.619966] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [289.620123] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [289.620289] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [289.620451] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [289.620607] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [289.620763] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [289.620919] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [289.621075] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [289.621237] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [289.621394] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [289.621550] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [289.621706] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [289.621863] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [289.622020] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [289.622180] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [289.622336] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [289.622493] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [289.622649] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [289.622806] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [289.622962] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [289.623118] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [289.623284] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [289.623441] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [289.623597] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [289.623753] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [289.623910] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [289.624066] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [289.624227] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [289.624384] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [289.624540] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [289.624696] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [289.624853] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] fastset requirement not met, forcing full modeset
<7> [289.625035] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [289.625193] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:505:pipe D] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x8
<7> [289.625372] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:389:plane 1D] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [289.625523] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:499:cursor D] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [289.625675] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [289.625826] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [289.625978] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0
<7> [289.626129] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0
<7> [289.626300] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:505:pipe D] data rate 594000 num active planes 1
<7> [289.626455] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [289.626608] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [289.626777] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:505:pipe D] min cdclk: 0 kHz -> 74250 kHz
<7> [289.626947] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [289.627101] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [289.627306] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:505:pipe D] enable: yes [modeset]
<7> [289.627462] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [289.627617] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: D, pipe bpp: 24, dithering: 0
<7> [289.627772] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [289.627927] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [289.628082] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [289.628242] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [289.628397] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [289.628553] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [289.628708] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [289.628863] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 41, vsync end: 36
<7> [289.629019] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125
<7> [289.629174] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [289.629334] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [289.629491] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [289.629647] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [289.629804] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [289.629960] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [289.630116] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [289.630276] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [289.630431] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [289.630586] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [289.630742] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [289.630897] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [289.631052] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [289.631213] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [289.631368] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [289.631523] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [289.631678] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [289.631833] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [289.631988] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [289.632143] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [289.632304] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [289.632459] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [289.632614] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [289.632769] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [289.632923] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [289.633078] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [289.633239] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:389:plane 1D] fb: [FB:559] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [289.633396] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [289.633551] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [289.633707] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:419:plane 2D] fb: [NOFB], visible: no
<7> [289.633863] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:449:plane 3D] fb: [NOFB], visible: no
<7> [289.634018] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:479:plane 4D] fb: [NOFB], visible: no
<7> [289.634173] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:489:plane 5D] fb: [NOFB], visible: no
<7> [289.634332] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:499:cursor D] fb: [NOFB], visible: no
<7> [289.634911] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [289.635095] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_D
<7> [289.635315] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [289.635470] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [289.635624] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [289.635779] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [289.635933] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [289.636088] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [289.636251] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [289.636406] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [289.636561] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [289.636715] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [289.636869] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [289.637024] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [289.637184] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [289.637339] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [289.637494] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [289.637648] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [289.637803] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [289.637957] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [289.638111] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [289.638269] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [289.638424] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xd
<7> [289.638774] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [289.639060] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe D
<7> [289.658104] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [289.658382] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:505:pipe D]
<6> [291.758145] [IGT] kms_flip: finished subtest D-HDMI-A3, FAIL
<6> [291.759250] [IGT] kms_flip: finished subtest flip-vs-expired-vblank-interruptible, FAIL
<7> [291.766074] i915 0000:03:00.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:559] from all active usage due to RMFB ioctl
<7> [291.766381] i915 0000:03:00.0: [drm:atomic_remove_fb] Disabling [PLANE:389:plane 1D] because [FB:559] is removed
<7> [291.766430] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:389:plane 1D] ddb ( 0 - 1963) -> ( 0 - 0), size 1963 -> 0
<7> [291.766619] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [291.766767] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] lines 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [291.766915] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] blocks 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [291.767151] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] min_ddb 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [291.767339] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:505:pipe D] data rate 0 num active planes 0
<7> [291.767500] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 0
<7> [291.767660] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<6> [291.776110] [IGT] kms_flip: exiting, ret=98
<7> [291.792309] i915 0000:03:00.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [291.792563] i915 0000:03:00.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [291.792760] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [291.793001] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:151:pipe A]
<7> [291.793203] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [291.793415] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [291.793625] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [291.793835] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [291.794154] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [291.794365] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [291.794575] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [291.794784] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [291.795067] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [291.795278] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [291.795489] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [291.795698] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [291.795908] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [291.796126] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [291.796336] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [291.796546] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [291.796756] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [291.796973] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [291.797190] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [291.797399] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [291.797609] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [291.797818] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [291.798033] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [291.798243] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [291.798453] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [291.798662] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [291.798872] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [291.799091] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [291.799301] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [291.799511] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [291.799720] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [291.799937] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [291.800147] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [291.800358] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [291.800568] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [291.800779] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [291.801154] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [291.801425] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [291.801636] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.enable (expected yes, found no)
<7> [291.801847] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.active (expected yes, found no)
<7> [291.802064] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in cpu_transcoder (expected 3, found -1)
<7> [291.802274] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in lane_count (expected 4, found 0)
<7> [291.802484] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [291.802695] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [291.802904] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [291.803122] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [291.803332] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [291.803547] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [291.803758] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [291.803975] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [291.804186] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [291.804396] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [291.804605] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [291.804814] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [291.805155] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [291.805365] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [291.805574] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [291.806590] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [291.806807] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [291.807025] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [291.807237] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [291.807424] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [291.807611] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [291.807797] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [291.808018] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [291.808205] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [291.808391] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [291.808577] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [291.808766] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [291.808959] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [291.809146] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [291.809333] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [291.809520] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [291.809707] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [291.809895] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [291.810090] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] fastset requirement not met, forcing full modeset
<7> [291.810323] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0xd -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [291.810506] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x8 -> 0x1
<7> [291.810687] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:505:pipe D] dbuf slices 0xc -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x8 -> 0x1
<7> [291.810872] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [291.811062] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [291.811243] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [291.811424] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [291.811604] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0
<7> [291.811786] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0
<7> [291.811975] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:499:cursor D] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [291.812185] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 594000 num active planes 1
<7> [291.812351] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [291.812516] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [291.812698] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 74250 kHz
<7> [291.812863] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:505:pipe D] min cdclk: 74250 kHz -> 0 kHz
<7> [291.813141] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [291.813352] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [291.813520] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [291.813687] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [291.813854] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [291.814028] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [291.814195] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [291.814362] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [291.814530] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [291.814696] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [291.814863] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 41, vsync end: 36
<7> [291.815036] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125
<7> [291.815202] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [291.815370] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [291.815542] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [291.815710] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [291.815878] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [291.816052] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [291.816220] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [291.816386] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [291.816553] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [291.816719] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [291.816886] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [291.817059] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [291.817228] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [291.817379] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [291.817531] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [291.817683] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [291.817834] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [291.818021] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [291.818172] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [291.818323] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [291.818475] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [291.818626] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [291.818777] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [291.818965] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [291.819132] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [291.819283] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [291.819434] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:560] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [291.819587] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [291.819739] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [291.819891] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [291.820078] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [291.820229] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [291.820380] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [291.820532] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [291.820682] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:505:pipe D] enable: no [modeset]
<7> [291.820834] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:389:plane 1D] fb: [NOFB], visible: no
<7> [291.821020] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:419:plane 2D] fb: [NOFB], visible: no
<7> [291.821172] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:449:plane 3D] fb: [NOFB], visible: no
<7> [291.821323] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:479:plane 4D] fb: [NOFB], visible: no
<7> [291.821474] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:489:plane 5D] fb: [NOFB], visible: no
<7> [291.821626] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:499:cursor D] fb: [NOFB], visible: no
<7> [291.821891] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [291.822495] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe D
<7> [291.825045] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [291.825268] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [291.825422] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [291.825573] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [291.825724] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [291.825875] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [291.826094] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [291.826246] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [291.826396] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [291.826547] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [291.826697] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [291.826848] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [291.827039] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [291.827190] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [291.827342] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [291.827493] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [291.827644] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [291.827794] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [291.827986] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [291.828165] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [291.828316] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [291.828473] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xf
<7> [291.828838] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [291.829162] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [291.830897] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [291.831103] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]
<7> [291.847116] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [291.847692] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [291.848001] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [291.848931] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_D
<7> [291.849199] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:505:pipe D]
<7> [291.850263] i915 0000:03:00.0: [drm:drm_client_dev_restore] fbdev: ret=0
Created at 2026-04-29 13:24:31