Results for igt@kms_flip@flip-vs-expired-vblank@b-dp4

Machine description: shard-dg2-433

Result: Fail

i915_display_info20 igt_runner20 results20.json results20-xe-load.json i915_display_info_post_exec20 boot20 dmesg20

DetailValue
Duration 1.70 seconds
Hostname 
shard-dg2-433
Igt-Version 
IGT-Version: 1.30-g5d806121f (x86_64) (Linux: 6.14.0-rc6-xe+ x86_64)
Out 
Starting dynamic subtest: B-DP4
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2055 __igt_fail_assert()
  #1 ../tests/kms_flip.c:905 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1831 run_test()
  #3 ../tests/kms_flip.c:2064 __igt_unique____real_main1987()
  #4 ../tests/kms_flip.c:1987 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-DP4: FAIL (1.696s)
Err 
Starting dynamic subtest: B-DP4
(kms_flip:4236) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:910:
(kms_flip:4236) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest B-DP4 failed.
**** DEBUG ****
(kms_flip:4236) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:4236) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=3, pitch=7680)
(kms_flip:4236) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:4236) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:4236) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=4, pitch=7680)
(kms_flip:4236) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:4236) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x5736729b8710, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x5736729b8710, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x573672973290, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x573672973290, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x5736729b8710, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x5736729b8710, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x573672973290, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) intel_allocator_simple-DEBUG: <ial: 0x573672973290, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:4236) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
(kms_flip:4236) DEBUG: No stale events found
(kms_flip:4236) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:4236) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:4236) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 132.839508
current_received_ts = 132.838898
current_seq = 1201
count = 0
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 32us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.839508
last_received_ts = 132.838898
last_seq = 1201
current_ts = 132.856171
current_received_ts = 132.855591
current_seq = 1202
count = 1
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.856171
last_received_ts = 132.855591
last_seq = 1202
current_ts = 132.872849
current_received_ts = 132.872253
current_seq = 1203
count = 2
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.872849
last_received_ts = 132.872253
last_seq = 1203
current_ts = 132.889511
current_received_ts = 132.888916
current_seq = 1204
count = 3
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.889511
last_received_ts = 132.888916
last_seq = 1204
current_ts = 132.906189
current_received_ts = 132.905579
current_seq = 1205
count = 4
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.906189
last_received_ts = 132.905579
last_seq = 1205
current_ts = 132.922852
current_received_ts = 132.922256
current_seq = 1206
count = 5
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.922852
last_received_ts = 132.922256
last_seq = 1206
current_ts = 132.939514
current_received_ts = 132.938919
current_seq = 1207
count = 6
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.939514
last_received_ts = 132.938919
last_seq = 1207
current_ts = 132.956192
current_received_ts = 132.955597
current_seq = 1208
count = 7
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.956192
last_received_ts = 132.955597
last_seq = 1208
current_ts = 132.972855
current_received_ts = 132.972260
current_seq = 1209
count = 8
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.972855
last_received_ts = 132.972260
last_seq = 1209
current_ts = 132.989532
current_received_ts = 132.988922
current_seq = 1210
count = 9
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 132.989532
last_received_ts = 132.988922
last_seq = 1210
current_ts = 133.006195
current_received_ts = 133.005585
current_seq = 1211
count = 10
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.006195
last_received_ts = 133.005585
last_seq = 1211
current_ts = 133.022858
current_received_ts = 133.022263
current_seq = 1212
count = 11
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.022858
last_received_ts = 133.022263
last_seq = 1212
current_ts = 133.039536
current_received_ts = 133.038925
current_seq = 1213
count = 12
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 25us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.039536
last_received_ts = 133.038925
last_seq = 1213
current_ts = 133.056198
current_received_ts = 133.055588
current_seq = 1214
count = 13
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.056198
last_received_ts = 133.055588
last_seq = 1214
current_ts = 133.072861
current_received_ts = 133.072266
current_seq = 1215
count = 14
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.072861
last_received_ts = 133.072266
last_seq = 1215
current_ts = 133.089539
current_received_ts = 133.088928
current_seq = 1216
count = 15
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.089539
last_received_ts = 133.088928
last_seq = 1216
current_ts = 133.106201
current_received_ts = 133.105591
current_seq = 1217
count = 16
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.106201
last_received_ts = 133.105591
last_seq = 1217
current_ts = 133.122864
current_received_ts = 133.122269
current_seq = 1218
count = 17
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.122864
last_received_ts = 133.122269
last_seq = 1218
current_ts = 133.139542
current_received_ts = 133.138931
current_seq = 1219
count = 18
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.139542
last_received_ts = 133.138931
last_seq = 1219
current_ts = 133.156204
current_received_ts = 133.155594
current_seq = 1220
count = 19
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 25us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.156204
last_received_ts = 133.155594
last_seq = 1220
current_ts = 133.172867
current_received_ts = 133.172272
current_seq = 1221
count = 20
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.172867
last_received_ts = 133.172272
last_seq = 1221
current_ts = 133.189545
current_received_ts = 133.188934
current_seq = 1222
count = 21
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.189545
last_received_ts = 133.188934
last_seq = 1222
current_ts = 133.206207
current_received_ts = 133.205597
current_seq = 1223
count = 22
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.206207
last_received_ts = 133.205597
last_seq = 1223
current_ts = 133.222870
current_received_ts = 133.222275
current_seq = 1224
count = 23
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.222870
last_received_ts = 133.222275
last_seq = 1224
current_ts = 133.239548
current_received_ts = 133.238937
current_seq = 1225
count = 24
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.239548
last_received_ts = 133.238937
last_seq = 1225
current_ts = 133.256210
current_received_ts = 133.255600
current_seq = 1226
count = 25
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.256210
last_received_ts = 133.255600
last_seq = 1226
current_ts = 133.272873
current_received_ts = 133.272278
current_seq = 1227
count = 26
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.272873
last_received_ts = 133.272278
last_seq = 1227
current_ts = 133.289551
current_received_ts = 133.288940
current_seq = 1228
count = 27
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.289551
last_received_ts = 133.288940
last_seq = 1228
current_ts = 133.306213
current_received_ts = 133.305603
current_seq = 1229
count = 28
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.306213
last_received_ts = 133.305603
last_seq = 1229
current_ts = 133.322876
current_received_ts = 133.322281
current_seq = 1230
count = 29
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.322876
last_received_ts = 133.322281
last_seq = 1230
current_ts = 133.339554
current_received_ts = 133.338943
current_seq = 1231
count = 30
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.339554
last_received_ts = 133.338943
last_seq = 1231
current_ts = 133.356216
current_received_ts = 133.355606
current_seq = 1232
count = 31
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.356216
last_received_ts = 133.355606
last_seq = 1232
current_ts = 133.372879
current_received_ts = 133.372284
current_seq = 1233
count = 32
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.372879
last_received_ts = 133.372284
last_seq = 1233
current_ts = 133.389557
current_received_ts = 133.388947
current_seq = 1234
count = 33
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.389557
last_received_ts = 133.388947
last_seq = 1234
current_ts = 133.406219
current_received_ts = 133.405609
current_seq = 1235
count = 34
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.406219
last_received_ts = 133.405609
last_seq = 1235
current_ts = 133.422882
current_received_ts = 133.422287
current_seq = 1236
count = 35
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.422882
last_received_ts = 133.422287
last_seq = 1236
current_ts = 133.439560
current_received_ts = 133.438950
current_seq = 1237
count = 36
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.439560
last_received_ts = 133.438950
last_seq = 1237
current_ts = 133.456223
current_received_ts = 133.455612
current_seq = 1238
count = 37
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.456223
last_received_ts = 133.455612
last_seq = 1238
current_ts = 133.472885
current_received_ts = 133.472351
current_seq = 1239
count = 38
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 173us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.472885
last_received_ts = 133.472351
last_seq = 1239
current_ts = 133.489548
current_received_ts = 133.489090
current_seq = 1240
count = 39
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 38us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.489548
last_received_ts = 133.489090
last_seq = 1240
current_ts = 133.506210
current_received_ts = 133.505661
current_seq = 1241
count = 40
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 27us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.506210
last_received_ts = 133.505661
last_seq = 1241
current_ts = 133.522888
current_received_ts = 133.522308
current_seq = 1242
count = 41
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 25us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.522888
last_received_ts = 133.522308
last_seq = 1242
current_ts = 133.539566
current_received_ts = 133.538956
current_seq = 1243
count = 42
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 20us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.539566
last_received_ts = 133.538956
last_seq = 1243
current_ts = 133.556229
current_received_ts = 133.555664
current_seq = 1244
count = 43
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 32us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.556229
last_received_ts = 133.555664
last_seq = 1244
current_ts = 133.572891
current_received_ts = 133.572311
current_seq = 1245
count = 44
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 27us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.572891
last_received_ts = 133.572311
last_seq = 1245
current_ts = 133.589569
current_received_ts = 133.588989
current_seq = 1246
count = 45
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 33us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.589569
last_received_ts = 133.588989
last_seq = 1246
current_ts = 133.606232
current_received_ts = 133.605652
current_seq = 1247
count = 46
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 31us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.606232
last_received_ts = 133.605652
last_seq = 1247
current_ts = 133.622894
current_received_ts = 133.622314
current_seq = 1248
count = 47
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 31us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.622894
last_received_ts = 133.622314
last_seq = 1248
current_ts = 133.639572
current_received_ts = 133.639130
current_seq = 1249
count = 48
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 199us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.639572
last_received_ts = 133.639130
last_seq = 1249
current_ts = 133.656235
current_received_ts = 133.655640
current_seq = 1250
count = 49
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 25us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.656235
last_received_ts = 133.655640
last_seq = 1250
current_ts = 133.672897
current_received_ts = 133.672302
current_seq = 1251
count = 50
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.672897
last_received_ts = 133.672302
last_seq = 1251
current_ts = 133.689575
current_received_ts = 133.688965
current_seq = 1252
count = 51
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 58us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.689575
last_received_ts = 133.688965
last_seq = 1252
current_ts = 133.706238
current_received_ts = 133.705627
current_seq = 1253
count = 52
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.706238
last_received_ts = 133.705627
last_seq = 1253
current_ts = 133.722900
current_received_ts = 133.722305
current_seq = 1254
count = 53
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.722900
last_received_ts = 133.722305
last_seq = 1254
current_ts = 133.739578
current_received_ts = 133.738968
current_seq = 1255
count = 54
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 43us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.739578
last_received_ts = 133.738968
last_seq = 1255
current_ts = 133.756241
current_received_ts = 133.755630
current_seq = 1256
count = 55
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.756241
last_received_ts = 133.755630
last_seq = 1256
current_ts = 133.772903
current_received_ts = 133.772308
current_seq = 1257
count = 56
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.772903
last_received_ts = 133.772308
last_seq = 1257
current_ts = 133.789581
current_received_ts = 133.788971
current_seq = 1258
count = 57
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 46us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.789581
last_received_ts = 133.788971
last_seq = 1258
current_ts = 133.806244
current_received_ts = 133.805634
current_seq = 1259
count = 58
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.806244
last_received_ts = 133.805634
last_seq = 1259
current_ts = 133.822922
current_received_ts = 133.822311
current_seq = 1260
count = 59
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 20us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.822922
last_received_ts = 133.822311
last_seq = 1260
current_ts = 133.839584
current_received_ts = 133.838974
current_seq = 1261
count = 60
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 38us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.839584
last_received_ts = 133.838974
last_seq = 1261
current_ts = 133.856247
current_received_ts = 133.855652
current_seq = 1262
count = 61
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.856247
last_received_ts = 133.855652
last_seq = 1262
current_ts = 133.872925
current_received_ts = 133.872314
current_seq = 1263
count = 62
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.872925
last_received_ts = 133.872314
last_seq = 1263
current_ts = 133.889587
current_received_ts = 133.888977
current_seq = 1264
count = 63
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 53us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.889587
last_received_ts = 133.888977
last_seq = 1264
current_ts = 133.906250
current_received_ts = 133.905640
current_seq = 1265
count = 64
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.906250
last_received_ts = 133.905640
last_seq = 1265
current_ts = 133.922928
current_received_ts = 133.922318
current_seq = 1266
count = 65
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.922928
last_received_ts = 133.922318
last_seq = 1266
current_ts = 133.939590
current_received_ts = 133.938980
current_seq = 1267
count = 66
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 40us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.939590
last_received_ts = 133.938980
last_seq = 1267
current_ts = 133.956253
current_received_ts = 133.955643
current_seq = 1268
count = 67
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.956253
last_received_ts = 133.955643
last_seq = 1268
current_ts = 133.972931
current_received_ts = 133.972321
current_seq = 1269
count = 68
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.972931
last_received_ts = 133.972321
last_seq = 1269
current_ts = 133.989594
current_received_ts = 133.988983
current_seq = 1270
count = 69
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 48us
(kms_flip:4236) DEBUG: name = flip
last_ts = 133.989594
last_received_ts = 133.988983
last_seq = 1270
current_ts = 134.006256
current_received_ts = 134.005646
current_seq = 1271
count = 70
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.006256
last_received_ts = 134.005646
last_seq = 1271
current_ts = 134.022934
current_received_ts = 134.022324
current_seq = 1272
count = 71
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.022934
last_received_ts = 134.022324
last_seq = 1272
current_ts = 134.039597
current_received_ts = 134.038986
current_seq = 1273
count = 72
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 223us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.039597
last_received_ts = 134.038986
last_seq = 1273
current_ts = 134.056259
current_received_ts = 134.055649
current_seq = 1274
count = 73
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.056259
last_received_ts = 134.055649
last_seq = 1274
current_ts = 134.072937
current_received_ts = 134.072327
current_seq = 1275
count = 74
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.072937
last_received_ts = 134.072327
last_seq = 1275
current_ts = 134.089600
current_received_ts = 134.088989
current_seq = 1276
count = 75
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 222us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.089600
last_received_ts = 134.088989
last_seq = 1276
current_ts = 134.106262
current_received_ts = 134.105667
current_seq = 1277
count = 76
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 24us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.106262
last_received_ts = 134.105667
last_seq = 1277
current_ts = 134.122940
current_received_ts = 134.122330
current_seq = 1278
count = 77
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.122940
last_received_ts = 134.122330
last_seq = 1278
current_ts = 134.139603
current_received_ts = 134.138992
current_seq = 1279
count = 78
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.139603
last_received_ts = 134.138992
last_seq = 1279
current_ts = 134.156265
current_received_ts = 134.155670
current_seq = 1280
count = 79
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.156265
last_received_ts = 134.155670
last_seq = 1280
current_ts = 134.172943
current_received_ts = 134.172333
current_seq = 1281
count = 80
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.172943
last_received_ts = 134.172333
last_seq = 1281
current_ts = 134.189606
current_received_ts = 134.188995
current_seq = 1282
count = 81
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 220us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.189606
last_received_ts = 134.188995
last_seq = 1282
current_ts = 134.206268
current_received_ts = 134.205673
current_seq = 1283
count = 82
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.206268
last_received_ts = 134.205673
last_seq = 1283
current_ts = 134.222946
current_received_ts = 134.222336
current_seq = 1284
count = 83
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.222946
last_received_ts = 134.222336
last_seq = 1284
current_ts = 134.239609
current_received_ts = 134.239014
current_seq = 1285
count = 84
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 23us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.239609
last_received_ts = 134.239014
last_seq = 1285
current_ts = 134.256271
current_received_ts = 134.255676
current_seq = 1286
count = 85
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 22us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.256271
last_received_ts = 134.255676
last_seq = 1286
current_ts = 134.272949
current_received_ts = 134.272339
current_seq = 1287
count = 86
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 222us
(kms_flip:4236) DEBUG: name = flip
last_ts = 134.272949
last_received_ts = 134.272339
last_seq = 1287
current_ts = 134.289612
current_received_ts = 134.289047
current_seq = 1288
count = 87
seq_step = 1
(kms_flip:4236) DEBUG: Vblank took 651us
(kms_flip:4236) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:910:
(kms_flip:4236) CRITICAL: Failed assertion: end - start < 500
(kms_flip:4236) igt_core-INFO: Stack trace:
(kms_flip:4236) igt_core-INFO:   #0 ../lib/igt_core.c:2055 __igt_fail_assert()
(kms_flip:4236) igt_core-INFO:   #1 ../tests/kms_flip.c:905 run_test_on_crtc_set.constprop.0()
(kms_flip:4236) igt_core-INFO:   #2 ../tests/kms_flip.c:1831 run_test()
(kms_flip:4236) igt_core-INFO:   #3 ../tests/kms_flip.c:2064 __igt_unique____real_main1987()
(kms_flip:4236) igt_core-INFO:   #4 ../tests/kms_flip.c:1987 main()
(kms_flip:4236) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:4236) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:4236) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-DP4: FAIL (1.696s)
Dmesg
<6> [132.687340] [IGT] kms_flip: starting dynamic subtest B-DP4
<7> [132.688980] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:287]
<7> [132.689869] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:293]
<7> [132.747137] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:82:pipe A]
<7> [132.747308] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [132.747541] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [132.747740] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [132.747924] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [132.748109] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 5190451/8388608 link 288358/524288, found tu 0, data 0/0 link 0/0)
<7> [132.748306] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000)
<7> [132.748486] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [132.748669] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [132.748853] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [132.749035] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [132.749224] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [132.749414] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [132.749607] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [132.749800] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [132.749993] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [132.750185] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [132.750420] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [132.750626] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [132.750831] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [132.751034] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [132.751255] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [132.751470] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [132.751690] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [132.751902] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [132.752115] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [132.752352] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [132.752586] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [132.752819] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [132.753051] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [132.753295] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [132.753487] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [132.753547] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [132.753611] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [132.753674] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [132.753737] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no)
<7> [132.753801] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [132.753864] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [132.753926] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [132.753989] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in port_clock (expected 270000, found 0)
<7> [132.754053] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:82:pipe A] fastset requirement not met, forcing full modeset
<7> [132.754129] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [132.754191] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:82:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [132.754281] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:77:cursor A] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [132.754352] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] Can change cdclk via squashing
<7> [132.754424] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [132.754494] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 0, actual 0
<7> [132.754562] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:82:pipe A] enable: no [modeset]
<7> [132.754633] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:32:plane 1A] fb: [NOFB], visible: no
<7> [132.754702] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:41:plane 2A] fb: [NOFB], visible: no
<7> [132.754769] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:50:plane 3A] fb: [NOFB], visible: no
<7> [132.754836] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:59:plane 4A] fb: [NOFB], visible: no
<7> [132.754903] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:68:plane 5A] fb: [NOFB], visible: no
<7> [132.754969] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:77:cursor A] fb: [NOFB], visible: no
<7> [132.755063] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C] Disable audio codec on [CRTC:82:pipe A]
<7> [132.782288] xe 0000:03:00.0: [drm:intel_audio_component_get_eld [xe]] Not valid for port C
<7> [132.783564] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [132.805009] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling DDI_IO_C
<7> [132.805483] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_C
<7> [132.805891] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:240:DDI A/PHY A]
<7> [132.806174] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:242:DP-MST A]
<7> [132.806472] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:243:DP-MST B]
<7> [132.806720] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:244:DP-MST C]
<7> [132.806965] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:245:DP-MST D]
<7> [132.807236] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:259:DDI B/PHY B]
<7> [132.807489] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:263:DDI C/PHY C]
<7> [132.807741] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:265:DP-MST A]
<7> [132.807983] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:266:DP-MST B]
<7> [132.808254] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:267:DP-MST C]
<7> [132.808517] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:268:DP-MST D]
<7> [132.808790] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:275:DDI D/PHY D]
<7> [132.809063] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:277:DP-MST A]
<7> [132.809364] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:278:DP-MST B]
<7> [132.809660] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:279:DP-MST C]
<7> [132.809951] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:280:DP-MST D]
<7> [132.810242] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:264:DP-4]
<7> [132.810561] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [132.810988] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [132.811408] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [132.811536] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:82:pipe A]
<7> [132.811635] xe 0000:03:00.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 163200 kHz, VCO 1305600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [132.811715] xe 0000:03:00.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=408
<7> [132.811796] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:134:pipe B]
<7> [132.811864] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:186:pipe C]
<7> [132.811915] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:238:pipe D]
<7> [132.811963] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:134:pipe B]
<7> [132.811977] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:264:DP-4]
<7> [132.812025] xe 0000:03:00.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:263:DDI C/PHY C][CRTC:134:pipe B] DP link limits: pixel clock 148500 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 36 max link_bpp 36.0000
<7> [132.812098] xe 0000:03:00.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 270000 bpp input 36 compressed 0.0000 link rate required 668250 available 1080000
<7> [132.812171] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:134:pipe B] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [132.812252] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:263:DDI C/PHY C] [CRTC:134:pipe B]
<7> [132.812333] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.enable (expected no, found yes)
<7> [132.812406] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.active (expected no, found yes)
<7> [132.812475] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)
<7> [132.812544] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in lane_count (expected 0, found 4)
<7> [132.812611] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 5190451/8388608 link 288358/524288)
<7> [132.812678] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000080)
<7> [132.812745] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [132.812811] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [132.812877] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [132.812943] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [132.813008] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [132.813073] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [132.813139] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [132.813204] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [132.813280] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [132.813350] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [132.813455] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [132.813665] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [132.813860] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [132.814052] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [132.814245] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [132.814424] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [132.814604] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [132.814782] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [132.814959] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [132.815126] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [132.815302] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [132.815461] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [132.815618] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [132.815777] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [132.815935] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [132.816088] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [132.816278] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [132.816432] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [132.816578] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in enhanced_framing (expected no, found yes)
<7> [132.816723] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [132.816868] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [132.817012] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [132.817154] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in port_clock (expected 0, found 270000)
<7> [132.817303] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:134:pipe B] fastset requirement not met, forcing full modeset
<7> [132.817490] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [132.817642] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:134:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2
<7> [132.817784] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [132.817843] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:129:cursor B] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [132.817900] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [132.817956] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [132.818011] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0
<7> [132.818065] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] 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> [132.818119] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:134:pipe B] data rate 594000 num active planes 1
<7> [132.818193] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 50000 required 624
<7> [132.818278] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] No SAGV, using single QGV point mask 0x1
<7> [132.818356] xe 0000:03:00.0: [drm:intel_plane_calc_min_cdclk [xe]] [PLANE:84:plane 1B] min cdclk (74250 kHz) > [CRTC:134:pipe B] min cdclk (0 kHz)
<7> [132.818430] xe 0000:03:00.0: [drm:intel_bw_calc_min_cdclk [xe]] new bandwidth min cdclk (11602 kHz) > old min cdclk (0 kHz)
<7> [132.818501] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] Can change cdclk via squashing
<7> [132.818570] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 204000 kHz, actual 204000 kHz
<7> [132.818637] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 0, actual 0
<7> [132.818705] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:134:pipe B] enable: yes [modeset]
<7> [132.818776] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB
<7> [132.818846] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: B, pipe bpp: 36, dithering: 0
<7> [132.818914] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [132.818981] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [132.819048] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [132.819114] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [132.819180] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 5190451, data_n: 8388608, link_m: 288358, link_n: 524288, tu: 64
<7> [132.819253] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [132.819320] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled
<7> [132.819385] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [132.819450] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [132.819515] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0
<7> [132.819580] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 0, infoframes enabled: 0x0
<7> [132.819645] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00
<7> [132.819710] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11
<7> [132.819775] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 17 50 51 07 00 00 00 00
<7> [132.819840] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [132.819904] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vblank delay: 0, framestart delay: 1, MSA timing delay: 0
<7> [132.819969] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [132.820034] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [132.820098] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [132.820163] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [132.820232] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [132.820297] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [132.820362] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [132.820427] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 270000, pipe src: 1920x1080+0+0, pixel rate 148500
<7> [132.820492] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0
<7> [132.820557] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [132.820621] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [132.820686] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [132.820750] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dpll_hw_state: dpll: 0x41eb0, dpll_md: 0x18000000, fp0: 0x88228fe, fp1: 0x2b000020
<7> [132.820815] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [132.820879] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [132.820943] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [132.821007] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [132.821071] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [132.821135] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [132.821199] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [132.821271] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [132.821335] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [132.821398] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [132.821462] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [132.821526] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [132.821591] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:84:plane 1B] fb: [FB:287] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [132.821656] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [132.821720] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [132.821785] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:93:plane 2B] fb: [NOFB], visible: no
<7> [132.821849] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:102:plane 3B] fb: [NOFB], visible: no
<7> [132.821913] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:111:plane 4B] fb: [NOFB], visible: no
<7> [132.821978] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:120:plane 5B] fb: [NOFB], visible: no
<7> [132.822042] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:129:cursor B] fb: [NOFB], visible: no
<7> [132.822369] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [132.822489] xe 0000:03:00.0: [drm:intel_audio_component_get_power [xe]] restored AUD_FREQ_CNTRL to 0x8010
<7> [132.822495] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_B
<7> [132.822640] xe 0000:03:00.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 204000 kHz, VCO 1305600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [132.822723] xe 0000:03:00.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=510
<7> [132.822794] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:240:DDI A/PHY A]
<7> [132.822860] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:242:DP-MST A]
<7> [132.822923] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:243:DP-MST B]
<7> [132.822985] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:244:DP-MST C]
<7> [132.823045] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:245:DP-MST D]
<7> [132.823104] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:259:DDI B/PHY B]
<7> [132.823163] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:263:DDI C/PHY C]
<7> [132.823227] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:265:DP-MST A]
<7> [132.823285] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:266:DP-MST B]
<7> [132.823343] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:267:DP-MST C]
<7> [132.823400] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:268:DP-MST D]
<7> [132.823456] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:275:DDI D/PHY D]
<7> [132.823513] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:277:DP-MST A]
<7> [132.823569] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:278:DP-MST B]
<7> [132.823625] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:279:DP-MST C]
<7> [132.823681] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:280:DP-MST D]
<7> [132.823737] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x3
<7> [132.823867] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_C
<7> [132.825179] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling DDI_IO_C
<7> [132.827557] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX C/DDI C/PHY C: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [132.837550] xe 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00
<7> [132.838931] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX C/DDI C/PHY C: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [132.840194] xe 0000:03:00.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] Using LINK_BW_SET value 0a
<7> [132.841648] xe 0000:03:00.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [132.841723] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] Using DP training pattern TPS1
<7> [132.848264] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] Clock recovery OK
<7> [132.848492] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] Using DP training pattern TPS3
<7> [132.856069] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] Channel EQ done. DP Training successful
<7> [132.856469] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C][DPRX] Link Training passed at link rate = 270000, lane count = 4
<7> [132.857222] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe B
<7> [132.874087] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:264:DP-4][ENCODER:263:DDI C/PHY C] Enable audio codec on [CRTC:134:pipe B], 40 bytes ELD
<7> [132.890856] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:264:DP-4]
<7> [132.891034] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:134:pipe B]
<7> [132.900657] xe 0000:03:00.0: [drm:intel_audio_component_get_power [xe]] restored AUD_FREQ_CNTRL to 0x8010
<6> [134.712144] [IGT] kms_flip: finished subtest B-DP4, FAIL
Created at 2025-03-13 13:55:19