Results for igt@kms_flip@flip-vs-absolute-wf_vblank-interruptible@b-hdmi-a4

Machine description: shard-dg1-14

Result: Fail

integration-manifest git-log-oneline i915_display_info9 igt_runner9 run9 runtimes9 results9.json boot9 dmesg9

DetailValue
Duration 7.11 seconds
Hostname 
shard-dg1-14
Igt-Version 
IGT-Version: 1.29-NO-GIT (x86_64) (Linux: 6.12.0-rc1-CI_DRM_15469-gfcdbbdcd11d4+ x86_64)
Out 
Starting dynamic subtest: B-HDMI-A4
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 16667us; measured 16460.7us +- 4.012us accuracy 0.07%
vblank interval differs from modeline! expected 16666.7us, measured 16461us +- 4.012us, difference 206.0us (51.3 sigma)
Stack trace:
  #0 ../lib/igt_core.c:2051 __igt_fail_assert()
  #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1845 run_test()
  #3 ../tests/kms_flip.c:2114 __igt_unique____real_main2001()
  #4 ../tests/kms_flip.c:2001 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-HDMI-A4: FAIL (7.112s)
Err 
Starting dynamic subtest: B-HDMI-A4
(kms_flip:1152) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:1152) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
(kms_flip:1152) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-HDMI-A4 failed.
**** DEBUG ****
(kms_flip:1152) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:1152) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=3, pitch=7680)
(kms_flip:1152) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:1152) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_flip:1152) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=11, pitch=7680)
(kms_flip:1152) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:1152) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:1152) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:1152) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) igt_fb-DEBUG: Test requirement passed: gem_has_contexts(fb->fd)
(kms_flip:1152) intel_allocator_reloc-DEBUG: Using reloc allocator
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:1152) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
(kms_flip:1152) DEBUG: No stale events found
(kms_flip:1152) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:1152) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:1152) INFO: Expected frametime: 16667us; measured 16460.7us +- 4.012us accuracy 0.07%
(kms_flip:1152) INFO: vblank interval differs from modeline! expected 16666.7us, measured 16461us +- 4.012us, difference 206.0us (51.3 sigma)
(kms_flip:1152) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 56.166508
current_received_ts = 56.166096
current_seq = 31
count = 0
seq_step = 1
(kms_flip:1152) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 56.314644
current_received_ts = 56.314178
current_seq = 40
count = 0
seq_step = 10
(kms_flip:1152) DEBUG: name = flip
last_ts = 56.166508
last_received_ts = 56.166096
last_seq = 31
current_ts = 56.331100
current_received_ts = 56.330650
current_seq = 41
count = 1
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 56.166508/31, current 56.331100/41: elapsed=164595.0us expected=164606.9us +- 823.0us, error 0.0%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 56.314644
last_received_ts = 56.314178
last_seq = 40
current_ts = 56.479252
current_received_ts = 56.478767
current_seq = 50
count = 1
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 56.314644/40, current 56.479252/50: elapsed=164606.0us expected=164606.9us +- 823.0us, error 0.0%
(kms_flip:1152) DEBUG: name = flip
last_ts = 56.331100
last_received_ts = 56.330650
last_seq = 41
current_ts = 56.495712
current_received_ts = 56.495205
current_seq = 51
count = 2
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 56.331100/41, current 56.495712/51: elapsed=164610.0us expected=164606.9us +- 823.0us, error 0.0%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 56.479252
last_received_ts = 56.478767
last_seq = 50
current_ts = 56.644039
current_received_ts = 56.643559
current_seq = 60
count = 2
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 56.479252/50, current 56.644039/60: elapsed=164791.0us expected=164606.9us +- 823.0us, error 0.1%
(kms_flip:1152) DEBUG: name = flip
last_ts = 56.495712
last_received_ts = 56.495205
last_seq = 51
current_ts = 56.660530
current_received_ts = 56.659962
current_seq = 61
count = 3
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 56.495712/51, current 56.660530/61: elapsed=164819.0us expected=164606.9us +- 823.0us, error 0.1%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 56.644039
last_received_ts = 56.643559
last_seq = 60
current_ts = 56.808891
current_received_ts = 56.808331
current_seq = 70
count = 3
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 56.644039/60, current 56.808891/70: elapsed=164849.0us expected=164606.9us +- 823.0us, error 0.1%
(kms_flip:1152) DEBUG: name = flip
last_ts = 56.660530
last_received_ts = 56.659962
last_seq = 61
current_ts = 56.825386
current_received_ts = 56.824898
current_seq = 71
count = 4
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 56.660530/61, current 56.825386/71: elapsed=164857.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 56.808891
last_received_ts = 56.808331
last_seq = 70
current_ts = 56.973747
current_received_ts = 56.973297
current_seq = 80
count = 4
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 56.808891/70, current 56.973747/80: elapsed=164856.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = flip
last_ts = 56.825386
last_received_ts = 56.824898
last_seq = 71
current_ts = 56.990242
current_received_ts = 56.989792
current_seq = 81
count = 5
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 56.825386/71, current 56.990242/81: elapsed=164856.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 56.973747
last_received_ts = 56.973297
last_seq = 80
current_ts = 57.138603
current_received_ts = 57.138142
current_seq = 90
count = 5
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 56.973747/80, current 57.138603/90: elapsed=164858.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = flip
last_ts = 56.990242
last_received_ts = 56.989792
last_seq = 81
current_ts = 57.155090
current_received_ts = 57.154629
current_seq = 91
count = 6
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 56.990242/81, current 57.155090/91: elapsed=164847.0us expected=164606.9us +- 823.0us, error 0.1%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 57.138603
last_received_ts = 57.138142
last_seq = 90
current_ts = 57.303471
current_received_ts = 57.303074
current_seq = 100
count = 6
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 57.138603/90, current 57.303471/100: elapsed=164867.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = flip
last_ts = 57.155090
last_received_ts = 57.154629
last_seq = 91
current_ts = 57.319958
current_received_ts = 57.320152
current_seq = 101
count = 7
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 57.155090/91, current 57.319958/101: elapsed=164868.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 57.303471
last_received_ts = 57.303074
last_seq = 100
current_ts = 57.468334
current_received_ts = 57.467869
current_seq = 110
count = 7
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 57.303471/100, current 57.468334/110: elapsed=164863.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = flip
last_ts = 57.319958
last_received_ts = 57.320152
last_seq = 101
current_ts = 57.484818
current_received_ts = 57.484383
current_seq = 111
count = 8
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 57.319958/101, current 57.484818/111: elapsed=164860.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 57.468334
last_received_ts = 57.467869
last_seq = 110
current_ts = 57.633339
current_received_ts = 57.632854
current_seq = 120
count = 8
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 57.468334/110, current 57.633339/120: elapsed=165006.0us expected=164606.9us +- 823.0us, error 0.2%
(kms_flip:1152) DEBUG: name = flip
last_ts = 57.484818
last_received_ts = 57.484383
last_seq = 111
current_ts = 57.649849
current_received_ts = 57.649372
current_seq = 121
count = 9
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 57.484818/111, current 57.649849/121: elapsed=165030.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 57.633339
last_received_ts = 57.632854
last_seq = 120
current_ts = 57.798424
current_received_ts = 57.797932
current_seq = 130
count = 9
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 57.633339/120, current 57.798424/130: elapsed=165082.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = flip
last_ts = 57.649849
last_received_ts = 57.649372
last_seq = 121
current_ts = 57.814930
current_received_ts = 57.814461
current_seq = 131
count = 10
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 57.649849/121, current 57.814930/131: elapsed=165082.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 57.798424
last_received_ts = 57.797932
last_seq = 130
current_ts = 57.963505
current_received_ts = 57.963062
current_seq = 140
count = 10
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 57.798424/130, current 57.963505/140: elapsed=165081.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = flip
last_ts = 57.814930
last_received_ts = 57.814461
last_seq = 131
current_ts = 57.980000
current_received_ts = 57.979576
current_seq = 141
count = 11
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 57.814930/131, current 57.980000/141: elapsed=165071.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 57.963505
last_received_ts = 57.963062
last_seq = 140
current_ts = 58.128586
current_received_ts = 58.128113
current_seq = 150
count = 11
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 57.963505/140, current 58.128586/150: elapsed=165082.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = flip
last_ts = 57.980000
last_received_ts = 57.979576
last_seq = 141
current_ts = 58.145092
current_received_ts = 58.144619
current_seq = 151
count = 12
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 57.980000/141, current 58.145092/151: elapsed=165092.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 58.128586
last_received_ts = 58.128113
last_seq = 150
current_ts = 58.293659
current_received_ts = 58.293194
current_seq = 160
count = 12
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 58.128586/150, current 58.293659/160: elapsed=165076.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = flip
last_ts = 58.145092
last_received_ts = 58.144619
last_seq = 151
current_ts = 58.310169
current_received_ts = 58.309692
current_seq = 161
count = 13
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 58.145092/151, current 58.310169/161: elapsed=165075.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 58.293659
last_received_ts = 58.293194
last_seq = 160
current_ts = 58.458748
current_received_ts = 58.458263
current_seq = 170
count = 13
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 58.293659/160, current 58.458748/170: elapsed=165085.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = flip
last_ts = 58.310169
last_received_ts = 58.309692
last_seq = 161
current_ts = 58.475250
current_received_ts = 58.474705
current_seq = 171
count = 14
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 58.310169/161, current 58.475250/171: elapsed=165084.0us expected=164606.9us +- 823.0us, error 0.3%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 58.458748
last_received_ts = 58.458263
last_seq = 170
current_ts = 58.623951
current_received_ts = 58.623466
current_seq = 180
count = 14
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 58.458748/170, current 58.623951/180: elapsed=165204.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = flip
last_ts = 58.475250
last_received_ts = 58.474705
last_seq = 171
current_ts = 58.640476
current_received_ts = 58.640083
current_seq = 181
count = 15
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 58.475250/171, current 58.640476/181: elapsed=165226.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 58.623951
last_received_ts = 58.623466
last_seq = 180
current_ts = 58.789227
current_received_ts = 58.788765
current_seq = 190
count = 15
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 58.623951/180, current 58.789227/190: elapsed=165278.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = flip
last_ts = 58.640476
last_received_ts = 58.640083
last_seq = 181
current_ts = 58.805744
current_received_ts = 58.805305
current_seq = 191
count = 16
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 58.640476/181, current 58.805744/191: elapsed=165268.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 58.789227
last_received_ts = 58.788765
last_seq = 190
current_ts = 58.954506
current_received_ts = 58.954090
current_seq = 200
count = 16
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 58.789227/190, current 58.954506/200: elapsed=165277.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = flip
last_ts = 58.805744
last_received_ts = 58.805305
last_seq = 191
current_ts = 58.971031
current_received_ts = 58.970577
current_seq = 201
count = 17
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 58.805744/191, current 58.971031/201: elapsed=165287.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 58.954506
last_received_ts = 58.954090
last_seq = 200
current_ts = 59.119781
current_received_ts = 59.119362
current_seq = 210
count = 17
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 58.954506/200, current 59.119781/210: elapsed=165276.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = flip
last_ts = 58.971031
last_received_ts = 58.970577
last_seq = 201
current_ts = 59.136311
current_received_ts = 59.135853
current_seq = 211
count = 18
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 58.971031/201, current 59.136311/211: elapsed=165278.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 59.119781
last_received_ts = 59.119362
last_seq = 210
current_ts = 59.285061
current_received_ts = 59.284576
current_seq = 220
count = 18
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 59.119781/210, current 59.285061/220: elapsed=165279.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = flip
last_ts = 59.136311
last_received_ts = 59.135853
last_seq = 211
current_ts = 59.301586
current_received_ts = 59.301113
current_seq = 221
count = 19
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 59.136311/211, current 59.301586/221: elapsed=165277.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 59.285061
last_received_ts = 59.284576
last_seq = 220
current_ts = 59.450336
current_received_ts = 59.449856
current_seq = 230
count = 19
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 59.285061/220, current 59.450336/230: elapsed=165278.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = flip
last_ts = 59.301586
last_received_ts = 59.301113
last_seq = 221
current_ts = 59.466866
current_received_ts = 59.466393
current_seq = 231
count = 20
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 59.301586/221, current 59.466866/231: elapsed=165278.0us expected=164606.9us +- 823.0us, error 0.4%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 59.450336
last_received_ts = 59.449856
last_seq = 230
current_ts = 59.615711
current_received_ts = 59.615227
current_seq = 240
count = 20
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 59.450336/230, current 59.615711/240: elapsed=165373.0us expected=164606.9us +- 823.0us, error 0.5%
(kms_flip:1152) DEBUG: name = flip
last_ts = 59.466866
last_received_ts = 59.466393
last_seq = 231
current_ts = 59.632256
current_received_ts = 59.631779
current_seq = 241
count = 21
seq_step = 1
(kms_flip:1152) DEBUG: flip ts/seq: last 59.466866/231, current 59.632256/241: elapsed=165390.0us expected=164606.9us +- 823.0us, error 0.5%
(kms_flip:1152) DEBUG: name = vblank
last_ts = 59.615711
last_received_ts = 59.615227
last_seq = 240
current_ts = 59.781155
current_received_ts = 59.780704
current_seq = 250
count = 21
seq_step = 10
(kms_flip:1152) DEBUG: vblank ts/seq: last 59.615711/240, current 59.781155/250: elapsed=165444.0us expected=164606.9us +- 823.0us, error 0.5%
(kms_flip:1152) DEBUG: inconsistent vblank ts/seq: last 59.615711/240, current 59.781155/250: elapsed=165444.0us expected=164606.9us
(kms_flip:1152) DEBUG: expected 66289, counted 210, encoder type 2
(kms_flip:1152) DEBUG: dropped frames, expected 66289, counted 210, encoder type 2
(kms_flip:1152) DEBUG: expected 66289, counted 210, encoder type 2
(kms_flip:1152) DEBUG: dropped frames, expected 66289, counted 210, encoder type 2
(kms_flip:1152) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:1152) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
(kms_flip:1152) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:1152) igt_core-INFO: Stack trace:
(kms_flip:1152) igt_core-INFO:   #0 ../lib/igt_core.c:2051 __igt_fail_assert()
(kms_flip:1152) igt_core-INFO:   #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0()
(kms_flip:1152) igt_core-INFO:   #2 ../tests/kms_flip.c:1845 run_test()
(kms_flip:1152) igt_core-INFO:   #3 ../tests/kms_flip.c:2114 __igt_unique____real_main2001()
(kms_flip:1152) igt_core-INFO:   #4 ../tests/kms_flip.c:2001 main()
(kms_flip:1152) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:1152) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:1152) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-HDMI-A4: FAIL (7.112s)
Dmesg
<6> [55.984894] [IGT] kms_flip: starting dynamic subtest B-HDMI-A4
<7> [55.986220] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:364]
<7> [55.986291] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:365]
<7> [55.986543] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [55.986949] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [56.003327] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [56.003636] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [56.007939] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [56.008254] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [56.023992] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [56.024335] [drm:i915_gem_do_execbuffer [i915]] EINVAL at eb_validate_vma:509
<7> [56.030512] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:100:pipe A]
<7> [56.030602] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [56.030737] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [56.030864] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [56.031066] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [56.031247] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [56.031388] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [56.031514] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [56.031640] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [56.031766] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [56.031893] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [56.032177] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [56.032350] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [56.032489] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [56.032616] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [56.032742] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [56.032867] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [56.033051] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [56.033179] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [56.033349] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [56.033475] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [56.033601] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [56.033726] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [56.033852] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [56.033977] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [56.034204] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [56.034333] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [56.034462] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [56.034591] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [56.034719] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [56.034848] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [56.034976] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [56.035140] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [56.035319] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [56.035461] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [56.035590] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [56.035719] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [56.035847] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:100:pipe A] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [56.035976] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:100:pipe A] fastset requirement not met, forcing full modeset
<7> [56.036139] i915 0000:03:00.0: [drm:intel_unreference_shared_dpll_crtc [i915]] [CRTC:100:pipe A] releasing DPLL 2
<7> [56.036284] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0x3), mbus joined? no->no
<7> [56.036416] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:100:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [56.036571] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] ddb ( 0 - 2012) -> ( 0 - 0), size 2012 -> 0
<7> [56.036704] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:95:cursor A] ddb (2012 - 2048) -> ( 0 - 0), size 36 -> 0
<7> [56.036861] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32: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> [56.036977] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] lines 1, 5, 5, 5, 8, 8, 9, 10, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [56.037145] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] blocks 16, 81, 81, 81, 129, 129, 145, 161, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [56.037265] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] min_ddb 19, 91, 91, 91, 143, 143, 161, 179, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [56.037396] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:100:pipe A] data rate 0 num active planes 0
<7> [56.037552] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 34000 required 0
<7> [56.037722] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New cdclk calculated to be logical 172800 kHz, actual 172800 kHz
<7> [56.037848] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New voltage level calculated to be logical 0, actual 0
<7> [56.037976] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:100:pipe A] enable: no [modeset]
<7> [56.038188] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:32:plane 1A] fb: [NOFB], visible: no
<7> [56.038317] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:41:plane 2A] fb: [NOFB], visible: no
<7> [56.038485] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:50:plane 3A] fb: [NOFB], visible: no
<7> [56.038610] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:59:plane 4A] fb: [NOFB], visible: no
<7> [56.038736] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:68:plane 5A] fb: [NOFB], visible: no
<7> [56.038861] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:77:plane 6A] fb: [NOFB], visible: no
<7> [56.038988] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:86:plane 7A] fb: [NOFB], visible: no
<7> [56.039164] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:cursor A] fb: [NOFB], visible: no
<7> [56.043822] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [56.060394] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_TC2
<7> [56.060550] i915 0000:03:00.0: [drm:intel_disable_shared_dpll [i915]] disable DPLL 2 (active 0x1, on? 1) for [CRTC:100:pipe A]
<7> [56.060703] i915 0000:03:00.0: [drm:intel_disable_shared_dpll [i915]] disabling DPLL 2
<7> [56.060846] i915 0000:03:00.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:32:plane 1A]
<7> [56.060974] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:312:DDI A/PHY A]
<7> [56.061093] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:314:DP-MST A]
<7> [56.061211] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:315:DP-MST B]
<7> [56.061329] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:316:DP-MST C]
<7> [56.061455] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:317:DP-MST D]
<7> [56.061627] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:331:DDI B/PHY B]
<7> [56.061748] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:335:DDI TC1/PHY C]
<7> [56.061883] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:337:DP-MST A]
<7> [56.062000] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:338:DP-MST B]
<7> [56.062118] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:339:DP-MST C]
<7> [56.062236] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:340:DP-MST D]
<7> [56.062355] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:347:DDI TC2/PHY D]
<7> [56.062583] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:349:DP-MST A]
<7> [56.062736] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:350:DP-MST B]
<7> [56.062857] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:351:DP-MST C]
<7> [56.062978] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:352:DP-MST D]
<7> [56.063098] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:356:HDMI-A-4]
<7> [56.063320] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [56.063517] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_3
<7> [56.063673] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [56.063823] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:100:pipe A]
<7> [56.064326] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:170:pipe B]
<7> [56.064500] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:240:pipe C]
<7> [56.064654] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:310:pipe D]
<7> [56.064809] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:170:pipe B]
<7> [56.064847] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:356:HDMI-A-4]
<7> [56.064900] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CONNECTOR:356:HDMI-A-4] Limiting display bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [56.065036] i915 0000:03:00.0: [drm:intel_hdmi_compute_clock [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [56.065150] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:170:pipe B] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [56.065280] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:347:DDI TC2/PHY D] [CRTC:170:pipe B]
<7> [56.065404] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.enable (expected no, found yes)
<7> [56.065571] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.active (expected no, found yes)
<7> [56.065701] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)
<7> [56.065830] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in lane_count (expected 0, found 4)
<7> [56.065959] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [56.066089] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [56.066218] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [56.066347] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [56.066484] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [56.066614] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [56.066743] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [56.066871] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [56.067000] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [56.067129] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [56.067258] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [56.067386] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [56.067559] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [56.067688] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [56.067817] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [56.067946] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [56.068074] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [56.068203] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [56.068331] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [56.068493] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [56.068637] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [56.068765] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [56.068894] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [56.069022] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [56.069151] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [56.069279] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [56.069408] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [56.069543] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [56.069672] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [56.069801] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [56.069930] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [56.070059] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [56.070187] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:170:pipe B] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [56.070317] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:170:pipe B] fastset requirement not met, forcing full modeset
<7> [56.070496] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0x3), mbus joined? no->no
<7> [56.070631] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:170:pipe B] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x2
<7> [56.070789] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:102:plane 1B] ddb ( 0 - 0) -> ( 0 - 2012), size 0 -> 2012
<7> [56.070908] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:165:cursor B] ddb ( 0 - 0) -> (2012 - 2048), size 0 -> 36
<7> [56.071027] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:102: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> [56.071146] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:102:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 5, 5, 5, 8, 8, 9, 10, 0, 0, 0
<7> [56.071266] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:102:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 81, 81, 81, 129, 129, 145, 161, 30, 0, 0
<7> [56.071386] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:102:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 91, 91, 91, 143, 143, 161, 179, 31, 0, 0
<7> [56.071511] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:170:pipe B] data rate 594000 num active planes 1
<7> [56.071671] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 34000 required 594
<7> [56.071801] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [56.071942] i915 0000:03:00.0: [drm:intel_plane_calc_min_cdclk [i915]] [PLANE:102:plane 1B] min cdclk (74250 kHz) > [CRTC:170:pipe B] min cdclk (0 kHz)
<7> [56.072073] i915 0000:03:00.0: [drm:intel_bw_calc_min_cdclk [i915]] new bandwidth min cdclk (11602 kHz) > old min cdclk (0 kHz)
<7> [56.072204] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New cdclk calculated to be logical 172800 kHz, actual 172800 kHz
<7> [56.072333] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New voltage level calculated to be logical 0, actual 0
<7> [56.072464] i915 0000:03:00.0: [drm:intel_find_shared_dpll [i915]] [CRTC:170:pipe B] allocated DPLL 2
<7> [56.072599] i915 0000:03:00.0: [drm:intel_reference_shared_dpll_crtc [i915]] [CRTC:170:pipe B] reserving DPLL 2
<7> [56.072727] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:170:pipe B] enable: yes [modeset]
<7> [56.072856] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [56.072985] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: B, pipe bpp: 24, dithering: 0
<7> [56.073114] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [56.073242] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [56.073371] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [56.073505] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [56.073674] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0
<7> [56.073803] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [56.073931] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, vmin: 0, vmax: 0, pipeline full: 0, guardband: 0 flipline: 0, vmin vblank: -1, vmax vblank: -2
<7> [56.074060] 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> [56.074190] 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> [56.074320] 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> [56.074450] 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> [56.074622] 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> [56.074752] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500
<7> [56.074881] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [56.075010] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [56.075138] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [56.075267] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [56.075396] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: cfgcr0: 0x2001d0, cfgcr1: 0xe84, div0: 0x0, mg_refclkin_ctl: 0x0, hg_clktop2_coreclkctl1: 0x0, mg_clktop2_hsclkctl: 0x0, mg_pll_div0: 0x0, mg_pll_div2: 0x0, mg_pll_lf: 0x0, mg_pll_frac_lock: 0x0, mg_pll_ssc: 0x0, mg_pll_bias: 0x0, mg_pll_tdc_coldst_bias: 0x0
<7> [56.075531] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [56.075660] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [56.075789] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [56.075917] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [56.076046] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [56.076174] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [56.076303] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [56.076431] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [56.076566] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [56.076727] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [56.076856] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [56.076984] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [56.077113] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:102:plane 1B] fb: [FB:364] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [56.077243] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [56.077371] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [56.077514] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:111:plane 2B] fb: [NOFB], visible: no
<7> [56.077690] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:120:plane 3B] fb: [NOFB], visible: no
<7> [56.077819] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:129:plane 4B] fb: [NOFB], visible: no
<7> [56.077990] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:138:plane 5B] fb: [NOFB], visible: no
<7> [56.078116] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:147:plane 6B] fb: [NOFB], visible: no
<7> [56.078242] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:156:plane 7B] fb: [NOFB], visible: no
<7> [56.078367] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:165:cursor B] fb: [NOFB], visible: no
<7> [56.078768] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [56.078906] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_3
<7> [56.079100] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:312:DDI A/PHY A]
<7> [56.079220] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:314:DP-MST A]
<7> [56.079339] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:315:DP-MST B]
<7> [56.079457] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:316:DP-MST C]
<7> [56.079617] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:317:DP-MST D]
<7> [56.079801] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:331:DDI B/PHY B]
<7> [56.079948] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:335:DDI TC1/PHY C]
<7> [56.080066] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:337:DP-MST A]
<7> [56.080185] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:338:DP-MST B]
<7> [56.080303] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:339:DP-MST C]
<7> [56.080420] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:340:DP-MST D]
<7> [56.080567] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:347:DDI TC2/PHY D]
<7> [56.080736] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:349:DP-MST A]
<7> [56.080857] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:350:DP-MST B]
<7> [56.080988] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:351:DP-MST C]
<7> [56.081107] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:352:DP-MST D]
<7> [56.081289] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [56.081471] i915 0000:03:00.0: [drm:intel_enable_shared_dpll [i915]] enable DPLL 2 (active 0x2, on? 0) for [CRTC:170:pipe B]
<7> [56.081628] i915 0000:03:00.0: [drm:intel_enable_shared_dpll [i915]] enabling DPLL 2
<7> [56.081831] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_TC2
<7> [56.082034] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe B
<7> [56.100241] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:356:HDMI-A-4]
<7> [56.100469] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:170:pipe B]
<6> [63.097330] [IGT] kms_flip: finished subtest B-HDMI-A4, FAIL
Created at 2024-10-02 19:55:13