Results for igt@kms_flip@wf_vblank-ts-check-interruptible@a-hdmi-a1

Result: Fail

integration-manifest git-log-oneline i915_display_info21 igt_runner21 runtimes21 results21.json results21-i915-load.json i915_display_info_post_exec21 boot21 dmesg21

DetailValue
Duration 18.98 seconds
Hostname 
shard-snb6
Igt-Version 
IGT-Version: 2.2-g3f90f16d1 (x86_64) (Linux: 6.18.0-rc5-CI_DRM_17535-g08d90d400dab+ x86_64)
Out 
Starting dynamic subtest: A-HDMI-A1
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 16667us; measured 16640.4us +- 7.527us accuracy 0.14%
vblank interval differs from modeline! expected 16666.7us, measured 16640us +- 7.527us, difference 26.3us (3.5 sigma)
Event vblank: expected 456, counted 450, passrate = 48.89%, encoder type 2
Expected frametime: 16667us; measured 16858.7us +- 8.316us accuracy 0.15%
vblank interval differs from modeline! expected 16666.7us, measured 16859us +- 8.316us, difference 192.0us (23.1 sigma)
Event vblank: expected 447, counted 450, passrate = 48.89%, encoder type 2
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1889 run_test()
  #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045()
  #4 ../tests/kms_flip.c:2045 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-HDMI-A1: FAIL (18.983s)
Err 
Starting dynamic subtest: A-HDMI-A1
(kms_flip:2800) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1709:
(kms_flip:2800) CRITICAL: Failed assertion: !retried
(kms_flip:2800) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest A-HDMI-A1 failed.
**** DEBUG ****
(kms_flip:2800) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2800) intel_blt-DEBUG: Test requirement passed: cmds_info
(kms_flip:2800) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_flip:2800) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
(kms_flip:2800) DEBUG: No stale events found
(kms_flip:2800) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2800) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2800) INFO: Expected frametime: 16667us; measured 16640.4us +- 7.527us accuracy 0.14%
(kms_flip:2800) INFO: vblank interval differs from modeline! expected 16666.7us, measured 16640us +- 7.527us, difference 26.3us (3.5 sigma)
(kms_flip:2800) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 222.414200
current_received_ts = 222.413696
current_seq = 2851
count = 0
seq_step = 10
(kms_flip:2800) DEBUG: name = vblank
last_ts = 222.414200
last_received_ts = 222.413696
last_seq = 2851
current_ts = 222.580612
current_received_ts = 222.580109
current_seq = 2861
count = 1
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 222.414200/2851, current 222.580612/2861: elapsed=166407.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 222.580612
last_received_ts = 222.580109
last_seq = 2861
current_ts = 222.747009
current_received_ts = 222.746460
current_seq = 2871
count = 2
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 222.580612/2861, current 222.747009/2871: elapsed=166394.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 222.747009
last_received_ts = 222.746460
last_seq = 2871
current_ts = 222.913422
current_received_ts = 222.912903
current_seq = 2881
count = 3
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 222.747009/2871, current 222.913422/2881: elapsed=166411.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 222.913422
last_received_ts = 222.912903
last_seq = 2881
current_ts = 223.079803
current_received_ts = 223.079254
current_seq = 2891
count = 4
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 222.913422/2881, current 223.079803/2891: elapsed=166390.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 223.079803
last_received_ts = 223.079254
last_seq = 2891
current_ts = 223.246201
current_received_ts = 223.245728
current_seq = 2901
count = 5
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 223.079803/2891, current 223.246201/2901: elapsed=166399.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 223.246201
last_received_ts = 223.245728
last_seq = 2901
current_ts = 223.412613
current_received_ts = 223.412064
current_seq = 2911
count = 6
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 223.246201/2901, current 223.412613/2911: elapsed=166414.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 223.412613
last_received_ts = 223.412064
last_seq = 2911
current_ts = 223.579010
current_received_ts = 223.578522
current_seq = 2921
count = 7
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 223.412613/2911, current 223.579010/2921: elapsed=166399.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 223.579010
last_received_ts = 223.578522
last_seq = 2921
current_ts = 223.745407
current_received_ts = 223.744858
current_seq = 2931
count = 8
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 223.579010/2921, current 223.745407/2931: elapsed=166394.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 223.745407
last_received_ts = 223.744858
last_seq = 2931
current_ts = 223.911804
current_received_ts = 223.911285
current_seq = 2941
count = 9
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 223.745407/2931, current 223.911804/2941: elapsed=166400.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 223.911804
last_received_ts = 223.911285
last_seq = 2941
current_ts = 224.078217
current_received_ts = 224.077682
current_seq = 2951
count = 10
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 223.911804/2941, current 224.078217/2951: elapsed=166407.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 224.078217
last_received_ts = 224.077682
last_seq = 2951
current_ts = 224.244629
current_received_ts = 224.244064
current_seq = 2961
count = 11
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 224.078217/2951, current 224.244629/2961: elapsed=166405.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 224.244629
last_received_ts = 224.244064
last_seq = 2961
current_ts = 224.411026
current_received_ts = 224.410492
current_seq = 2971
count = 12
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 224.244629/2961, current 224.411026/2971: elapsed=166403.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 224.411026
last_received_ts = 224.410492
last_seq = 2971
current_ts = 224.577423
current_received_ts = 224.576904
current_seq = 2981
count = 13
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 224.411026/2971, current 224.577423/2981: elapsed=166400.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 224.577423
last_received_ts = 224.576904
last_seq = 2981
current_ts = 224.743820
current_received_ts = 224.743347
current_seq = 2991
count = 14
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 224.577423/2981, current 224.743820/2991: elapsed=166402.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 224.743820
last_received_ts = 224.743347
last_seq = 2991
current_ts = 224.910217
current_received_ts = 224.909698
current_seq = 3001
count = 15
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 224.743820/2991, current 224.910217/3001: elapsed=166389.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 224.910217
last_received_ts = 224.909698
last_seq = 3001
current_ts = 225.076630
current_received_ts = 225.076111
current_seq = 3011
count = 16
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 224.910217/3001, current 225.076630/3011: elapsed=166409.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 225.076630
last_received_ts = 225.076111
last_seq = 3011
current_ts = 225.243027
current_received_ts = 225.242416
current_seq = 3021
count = 17
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 225.076630/3011, current 225.243027/3021: elapsed=166403.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 225.243027
last_received_ts = 225.242416
last_seq = 3021
current_ts = 225.409424
current_received_ts = 225.408920
current_seq = 3031
count = 18
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 225.243027/3021, current 225.409424/3031: elapsed=166400.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 225.409424
last_received_ts = 225.408920
last_seq = 3031
current_ts = 225.575821
current_received_ts = 225.575272
current_seq = 3041
count = 19
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 225.409424/3031, current 225.575821/3041: elapsed=166392.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 225.575821
last_received_ts = 225.575272
last_seq = 3041
current_ts = 225.742233
current_received_ts = 225.741714
current_seq = 3051
count = 20
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 225.575821/3041, current 225.742233/3051: elapsed=166408.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 225.742233
last_received_ts = 225.741714
last_seq = 3051
current_ts = 225.908646
current_received_ts = 225.908096
current_seq = 3061
count = 21
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 225.742233/3051, current 225.908646/3061: elapsed=166415.0us expected=166403.8us +- 832.0us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 225.908646
last_received_ts = 225.908096
last_seq = 3061
current_ts = 226.077637
current_received_ts = 226.077133
current_seq = 3071
count = 22
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 225.908646/3061, current 226.077637/3071: elapsed=168992.0us expected=166403.8us +- 832.0us, error 1.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 225.908646/3061, current 226.077637/3071: elapsed=168992.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 226.077637
last_received_ts = 226.077133
last_seq = 3071
current_ts = 226.249603
current_received_ts = 226.249161
current_seq = 3081
count = 23
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 226.077637/3071, current 226.249603/3081: elapsed=171965.0us expected=166403.8us +- 832.0us, error 3.3%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 226.077637/3071, current 226.249603/3081: elapsed=171965.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 226.249603
last_received_ts = 226.249161
last_seq = 3081
current_ts = 226.421555
current_received_ts = 226.421082
current_seq = 3091
count = 24
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 226.249603/3081, current 226.421555/3091: elapsed=171953.0us expected=166403.8us +- 832.0us, error 3.3%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 226.249603/3081, current 226.421555/3091: elapsed=171953.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 226.421555
last_received_ts = 226.421082
last_seq = 3091
current_ts = 226.593521
current_received_ts = 226.593018
current_seq = 3101
count = 25
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 226.421555/3091, current 226.593521/3101: elapsed=171963.0us expected=166403.8us +- 832.0us, error 3.3%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 226.421555/3091, current 226.593521/3101: elapsed=171963.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 226.593521
last_received_ts = 226.593018
last_seq = 3101
current_ts = 226.765472
current_received_ts = 226.764954
current_seq = 3111
count = 26
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 226.593521/3101, current 226.765472/3111: elapsed=171959.0us expected=166403.8us +- 832.0us, error 3.3%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 226.593521/3101, current 226.765472/3111: elapsed=171959.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 226.765472
last_received_ts = 226.764954
last_seq = 3111
current_ts = 226.937424
current_received_ts = 226.936935
current_seq = 3121
count = 27
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 226.765472/3111, current 226.937424/3121: elapsed=171956.0us expected=166403.8us +- 832.0us, error 3.3%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 226.765472/3111, current 226.937424/3121: elapsed=171956.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 226.937424
last_received_ts = 226.936935
last_seq = 3121
current_ts = 227.108948
current_received_ts = 227.108444
current_seq = 3131
count = 28
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 226.937424/3121, current 227.108948/3131: elapsed=171510.0us expected=166403.8us +- 832.0us, error 3.1%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 226.937424/3121, current 227.108948/3131: elapsed=171510.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 227.108948
last_received_ts = 227.108444
last_seq = 3131
current_ts = 227.280212
current_received_ts = 227.279694
current_seq = 3141
count = 29
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 227.108948/3131, current 227.280212/3141: elapsed=171267.0us expected=166403.8us +- 832.0us, error 2.9%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 227.108948/3131, current 227.280212/3141: elapsed=171267.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 227.280212
last_received_ts = 227.279694
last_seq = 3141
current_ts = 227.451462
current_received_ts = 227.450897
current_seq = 3151
count = 30
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 227.280212/3141, current 227.451462/3151: elapsed=171252.0us expected=166403.8us +- 832.0us, error 2.9%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 227.280212/3141, current 227.451462/3151: elapsed=171252.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 227.451462
last_received_ts = 227.450897
last_seq = 3151
current_ts = 227.622742
current_received_ts = 227.622208
current_seq = 3161
count = 31
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 227.451462/3151, current 227.622742/3161: elapsed=171276.0us expected=166403.8us +- 832.0us, error 2.9%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 227.451462/3151, current 227.622742/3161: elapsed=171276.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 227.622742
last_received_ts = 227.622208
last_seq = 3161
current_ts = 227.794006
current_received_ts = 227.793457
current_seq = 3171
count = 32
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 227.622742/3161, current 227.794006/3171: elapsed=171266.0us expected=166403.8us +- 832.0us, error 2.9%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 227.622742/3161, current 227.794006/3171: elapsed=171266.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 227.794006
last_received_ts = 227.793457
last_seq = 3171
current_ts = 227.965256
current_received_ts = 227.964783
current_seq = 3181
count = 33
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 227.794006/3171, current 227.965256/3181: elapsed=171259.0us expected=166403.8us +- 832.0us, error 2.9%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 227.794006/3171, current 227.965256/3181: elapsed=171259.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 227.965256
last_received_ts = 227.964783
last_seq = 3181
current_ts = 228.136032
current_received_ts = 228.135529
current_seq = 3191
count = 34
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 227.965256/3181, current 228.136032/3191: elapsed=170774.0us expected=166403.8us +- 832.0us, error 2.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 227.965256/3181, current 228.136032/3191: elapsed=170774.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 228.136032
last_received_ts = 228.135529
last_seq = 3191
current_ts = 228.306702
current_received_ts = 228.306198
current_seq = 3201
count = 35
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 228.136032/3191, current 228.306702/3201: elapsed=170665.0us expected=166403.8us +- 832.0us, error 2.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 228.136032/3191, current 228.306702/3201: elapsed=170665.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 228.306702
last_received_ts = 228.306198
last_seq = 3201
current_ts = 228.477356
current_received_ts = 228.476898
current_seq = 3211
count = 36
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 228.306702/3201, current 228.477356/3211: elapsed=170656.0us expected=166403.8us +- 832.0us, error 2.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 228.306702/3201, current 228.477356/3211: elapsed=170656.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 228.477356
last_received_ts = 228.476898
last_seq = 3211
current_ts = 228.648026
current_received_ts = 228.647552
current_seq = 3221
count = 37
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 228.477356/3211, current 228.648026/3221: elapsed=170668.0us expected=166403.8us +- 832.0us, error 2.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 228.477356/3211, current 228.648026/3221: elapsed=170668.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 228.648026
last_received_ts = 228.647552
last_seq = 3221
current_ts = 228.818680
current_received_ts = 228.818176
current_seq = 3231
count = 38
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 228.648026/3221, current 228.818680/3231: elapsed=170657.0us expected=166403.8us +- 832.0us, error 2.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 228.648026/3221, current 228.818680/3231: elapsed=170657.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 228.818680
last_received_ts = 228.818176
last_seq = 3231
current_ts = 228.989334
current_received_ts = 228.988815
current_seq = 3241
count = 39
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 228.818680/3231, current 228.989334/3241: elapsed=170649.0us expected=166403.8us +- 832.0us, error 2.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 228.818680/3231, current 228.989334/3241: elapsed=170649.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 228.989334
last_received_ts = 228.988815
last_seq = 3241
current_ts = 229.159485
current_received_ts = 229.158920
current_seq = 3251
count = 40
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 228.989334/3241, current 229.159485/3251: elapsed=170155.0us expected=166403.8us +- 832.0us, error 2.3%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 228.989334/3241, current 229.159485/3251: elapsed=170155.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 229.159485
last_received_ts = 229.158920
last_seq = 3251
current_ts = 229.329620
current_received_ts = 229.329117
current_seq = 3261
count = 41
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 229.159485/3251, current 229.329620/3261: elapsed=170129.0us expected=166403.8us +- 832.0us, error 2.2%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 229.159485/3251, current 229.329620/3261: elapsed=170129.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 229.329620
last_received_ts = 229.329117
last_seq = 3261
current_ts = 229.499741
current_received_ts = 229.499207
current_seq = 3271
count = 42
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 229.329620/3261, current 229.499741/3271: elapsed=170128.0us expected=166403.8us +- 832.0us, error 2.2%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 229.329620/3261, current 229.499741/3271: elapsed=170128.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 229.499741
last_received_ts = 229.499207
last_seq = 3271
current_ts = 229.669876
current_received_ts = 229.669357
current_seq = 3281
count = 43
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 229.499741/3271, current 229.669876/3281: elapsed=170133.0us expected=166403.8us +- 832.0us, error 2.2%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 229.499741/3271, current 229.669876/3281: elapsed=170133.0us expected=166403.8us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 229.669876
last_received_ts = 229.669357
last_seq = 3281
current_ts = 229.839996
current_received_ts = 229.839478
current_seq = 3291
count = 44
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 229.669876/3281, current 229.839996/3291: elapsed=170128.0us expected=166403.8us +- 832.0us, error 2.2%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 229.669876/3281, current 229.839996/3291: elapsed=170128.0us expected=166403.8us
(kms_flip:2800) INFO: Event vblank: expected 456, counted 450, passrate = 48.89%, encoder type 2
(kms_flip:2800) DEBUG: dropped frames, expected 456, counted 450, passrate = 48.89%, encoder type 2
(kms_flip:2800) DEBUG: Retrying without a hotplug event
(kms_flip:2800) DEBUG: No stale events found
(kms_flip:2800) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2800) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2800) INFO: Expected frametime: 16667us; measured 16858.7us +- 8.316us accuracy 0.15%
(kms_flip:2800) INFO: vblank interval differs from modeline! expected 16666.7us, measured 16859us +- 8.316us, difference 192.0us (23.1 sigma)
(kms_flip:2800) DEBUG: name = vblank
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 233.494217
current_received_ts = 233.493698
current_seq = 3504
count = 0
seq_step = 10
(kms_flip:2800) DEBUG: name = vblank
last_ts = 233.494217
last_received_ts = 233.493698
last_seq = 3504
current_ts = 233.662811
current_received_ts = 233.662277
current_seq = 3514
count = 1
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 233.494217/3504, current 233.662811/3514: elapsed=168598.0us expected=168586.9us +- 842.9us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 233.662811
last_received_ts = 233.662277
last_seq = 3514
current_ts = 233.831390
current_received_ts = 233.830917
current_seq = 3524
count = 2
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 233.662811/3514, current 233.831390/3524: elapsed=168584.0us expected=168586.9us +- 842.9us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 233.831390
last_received_ts = 233.830917
last_seq = 3524
current_ts = 233.999985
current_received_ts = 233.999451
current_seq = 3534
count = 3
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 233.831390/3524, current 233.999985/3534: elapsed=168589.0us expected=168586.9us +- 842.9us, error 0.0%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 233.999985
last_received_ts = 233.999451
last_seq = 3534
current_ts = 234.168289
current_received_ts = 234.167709
current_seq = 3544
count = 4
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 233.999985/3534, current 234.168289/3544: elapsed=168312.0us expected=168586.9us +- 842.9us, error 0.2%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 234.168289
last_received_ts = 234.167709
last_seq = 3544
current_ts = 234.336609
current_received_ts = 234.336075
current_seq = 3554
count = 5
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 234.168289/3544, current 234.336609/3554: elapsed=168319.0us expected=168586.9us +- 842.9us, error 0.2%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 234.336609
last_received_ts = 234.336075
last_seq = 3554
current_ts = 234.504944
current_received_ts = 234.504456
current_seq = 3564
count = 6
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 234.336609/3554, current 234.504944/3564: elapsed=168330.0us expected=168586.9us +- 842.9us, error 0.2%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 234.504944
last_received_ts = 234.504456
last_seq = 3564
current_ts = 234.673248
current_received_ts = 234.672821
current_seq = 3574
count = 7
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 234.504944/3564, current 234.673248/3574: elapsed=168306.0us expected=168586.9us +- 842.9us, error 0.2%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 234.673248
last_received_ts = 234.672821
last_seq = 3574
current_ts = 234.841583
current_received_ts = 234.841080
current_seq = 3584
count = 8
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 234.673248/3574, current 234.841583/3584: elapsed=168325.0us expected=168586.9us +- 842.9us, error 0.2%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 234.841583
last_received_ts = 234.841080
last_seq = 3584
current_ts = 235.009872
current_received_ts = 235.009308
current_seq = 3594
count = 9
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 234.841583/3584, current 235.009872/3594: elapsed=168301.0us expected=168586.9us +- 842.9us, error 0.2%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 235.009872
last_received_ts = 235.009308
last_seq = 3594
current_ts = 235.177963
current_received_ts = 235.177521
current_seq = 3604
count = 10
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 235.009872/3594, current 235.177963/3604: elapsed=168083.0us expected=168586.9us +- 842.9us, error 0.3%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 235.177963
last_received_ts = 235.177521
last_seq = 3604
current_ts = 235.346024
current_received_ts = 235.345490
current_seq = 3614
count = 11
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 235.177963/3604, current 235.346024/3614: elapsed=168071.0us expected=168586.9us +- 842.9us, error 0.3%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 235.346024
last_received_ts = 235.345490
last_seq = 3614
current_ts = 235.514130
current_received_ts = 235.513626
current_seq = 3624
count = 12
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 235.346024/3614, current 235.514130/3624: elapsed=168091.0us expected=168586.9us +- 842.9us, error 0.3%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 235.514130
last_received_ts = 235.513626
last_seq = 3624
current_ts = 235.682205
current_received_ts = 235.681702
current_seq = 3634
count = 13
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 235.514130/3624, current 235.682205/3634: elapsed=168081.0us expected=168586.9us +- 842.9us, error 0.3%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 235.682205
last_received_ts = 235.681702
last_seq = 3634
current_ts = 235.850281
current_received_ts = 235.849792
current_seq = 3644
count = 14
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 235.682205/3634, current 235.850281/3644: elapsed=168077.0us expected=168586.9us +- 842.9us, error 0.3%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 235.850281
last_received_ts = 235.849792
last_seq = 3644
current_ts = 236.018341
current_received_ts = 236.017838
current_seq = 3654
count = 15
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 235.850281/3644, current 236.018341/3654: elapsed=168058.0us expected=168586.9us +- 842.9us, error 0.3%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 236.018341
last_received_ts = 236.017838
last_seq = 3654
current_ts = 236.186203
current_received_ts = 236.185699
current_seq = 3664
count = 16
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 236.018341/3654, current 236.186203/3664: elapsed=167872.0us expected=168586.9us +- 842.9us, error 0.4%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 236.186203
last_received_ts = 236.185699
last_seq = 3664
current_ts = 236.354065
current_received_ts = 236.353561
current_seq = 3674
count = 17
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 236.186203/3664, current 236.354065/3674: elapsed=167862.0us expected=168586.9us +- 842.9us, error 0.4%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 236.354065
last_received_ts = 236.353561
last_seq = 3674
current_ts = 236.521942
current_received_ts = 236.521439
current_seq = 3684
count = 18
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 236.354065/3674, current 236.521942/3684: elapsed=167874.0us expected=168586.9us +- 842.9us, error 0.4%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 236.521942
last_received_ts = 236.521439
last_seq = 3684
current_ts = 236.689819
current_received_ts = 236.689377
current_seq = 3694
count = 19
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 236.521942/3684, current 236.689819/3694: elapsed=167872.0us expected=168586.9us +- 842.9us, error 0.4%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 236.689819
last_received_ts = 236.689377
last_seq = 3694
current_ts = 236.857697
current_received_ts = 236.857162
current_seq = 3704
count = 20
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 236.689819/3694, current 236.857697/3704: elapsed=167879.0us expected=168586.9us +- 842.9us, error 0.4%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 236.857697
last_received_ts = 236.857162
last_seq = 3704
current_ts = 237.025528
current_received_ts = 237.025085
current_seq = 3714
count = 21
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 236.857697/3704, current 237.025528/3714: elapsed=167829.0us expected=168586.9us +- 842.9us, error 0.4%
(kms_flip:2800) DEBUG: name = vblank
last_ts = 237.025528
last_received_ts = 237.025085
last_seq = 3714
current_ts = 237.193222
current_received_ts = 237.192688
current_seq = 3724
count = 22
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 237.025528/3714, current 237.193222/3724: elapsed=167691.0us expected=168586.9us +- 842.9us, error 0.5%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 237.025528/3714, current 237.193222/3724: elapsed=167691.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 237.193222
last_received_ts = 237.192688
last_seq = 3724
current_ts = 237.360916
current_received_ts = 237.360382
current_seq = 3734
count = 23
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 237.193222/3724, current 237.360916/3734: elapsed=167696.0us expected=168586.9us +- 842.9us, error 0.5%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 237.193222/3724, current 237.360916/3734: elapsed=167696.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 237.360916
last_received_ts = 237.360382
last_seq = 3734
current_ts = 237.528610
current_received_ts = 237.528046
current_seq = 3744
count = 24
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 237.360916/3734, current 237.528610/3744: elapsed=167693.0us expected=168586.9us +- 842.9us, error 0.5%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 237.360916/3734, current 237.528610/3744: elapsed=167693.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 237.528610
last_received_ts = 237.528046
last_seq = 3744
current_ts = 237.696289
current_received_ts = 237.695786
current_seq = 3754
count = 25
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 237.528610/3744, current 237.696289/3754: elapsed=167680.0us expected=168586.9us +- 842.9us, error 0.5%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 237.528610/3744, current 237.696289/3754: elapsed=167680.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 237.696289
last_received_ts = 237.695786
last_seq = 3754
current_ts = 237.863983
current_received_ts = 237.863464
current_seq = 3764
count = 26
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 237.696289/3754, current 237.863983/3764: elapsed=167692.0us expected=168586.9us +- 842.9us, error 0.5%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 237.696289/3754, current 237.863983/3764: elapsed=167692.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 237.863983
last_received_ts = 237.863464
last_seq = 3764
current_ts = 238.031631
current_received_ts = 238.031158
current_seq = 3774
count = 27
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 237.863983/3764, current 238.031631/3774: elapsed=167658.0us expected=168586.9us +- 842.9us, error 0.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 237.863983/3764, current 238.031631/3774: elapsed=167658.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 238.031631
last_received_ts = 238.031158
last_seq = 3774
current_ts = 238.199173
current_received_ts = 238.198685
current_seq = 3784
count = 28
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 238.031631/3774, current 238.199173/3784: elapsed=167536.0us expected=168586.9us +- 842.9us, error 0.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 238.031631/3774, current 238.199173/3784: elapsed=167536.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 238.199173
last_received_ts = 238.198685
last_seq = 3784
current_ts = 238.366684
current_received_ts = 238.366119
current_seq = 3794
count = 29
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 238.199173/3784, current 238.366684/3794: elapsed=167518.0us expected=168586.9us +- 842.9us, error 0.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 238.199173/3784, current 238.366684/3794: elapsed=167518.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 238.366684
last_received_ts = 238.366119
last_seq = 3794
current_ts = 238.534225
current_received_ts = 238.533752
current_seq = 3804
count = 30
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 238.366684/3794, current 238.534225/3804: elapsed=167543.0us expected=168586.9us +- 842.9us, error 0.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 238.366684/3794, current 238.534225/3804: elapsed=167543.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 238.534225
last_received_ts = 238.533752
last_seq = 3804
current_ts = 238.701752
current_received_ts = 238.701248
current_seq = 3814
count = 31
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 238.534225/3804, current 238.701752/3814: elapsed=167521.0us expected=168586.9us +- 842.9us, error 0.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 238.534225/3804, current 238.701752/3814: elapsed=167521.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 238.701752
last_received_ts = 238.701248
last_seq = 3814
current_ts = 238.869278
current_received_ts = 238.868790
current_seq = 3824
count = 32
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 238.701752/3814, current 238.869278/3824: elapsed=167528.0us expected=168586.9us +- 842.9us, error 0.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 238.701752/3814, current 238.869278/3824: elapsed=167528.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 238.869278
last_received_ts = 238.868790
last_seq = 3824
current_ts = 239.036789
current_received_ts = 239.036255
current_seq = 3834
count = 33
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 238.869278/3824, current 239.036789/3834: elapsed=167502.0us expected=168586.9us +- 842.9us, error 0.6%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 238.869278/3824, current 239.036789/3834: elapsed=167502.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 239.036789
last_received_ts = 239.036255
last_seq = 3834
current_ts = 239.204178
current_received_ts = 239.203644
current_seq = 3844
count = 34
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 239.036789/3834, current 239.204178/3844: elapsed=167391.0us expected=168586.9us +- 842.9us, error 0.7%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 239.036789/3834, current 239.204178/3844: elapsed=167391.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 239.204178
last_received_ts = 239.203644
last_seq = 3844
current_ts = 239.371567
current_received_ts = 239.371078
current_seq = 3854
count = 35
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 239.204178/3844, current 239.371567/3854: elapsed=167393.0us expected=168586.9us +- 842.9us, error 0.7%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 239.204178/3844, current 239.371567/3854: elapsed=167393.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 239.371567
last_received_ts = 239.371078
last_seq = 3854
current_ts = 239.538956
current_received_ts = 239.538391
current_seq = 3864
count = 36
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 239.371567/3854, current 239.538956/3864: elapsed=167385.0us expected=168586.9us +- 842.9us, error 0.7%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 239.371567/3854, current 239.538956/3864: elapsed=167385.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 239.538956
last_received_ts = 239.538391
last_seq = 3864
current_ts = 239.706345
current_received_ts = 239.705750
current_seq = 3874
count = 37
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 239.538956/3864, current 239.706345/3874: elapsed=167394.0us expected=168586.9us +- 842.9us, error 0.7%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 239.538956/3864, current 239.706345/3874: elapsed=167394.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 239.706345
last_received_ts = 239.705750
last_seq = 3874
current_ts = 239.873734
current_received_ts = 239.873123
current_seq = 3884
count = 38
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 239.706345/3874, current 239.873734/3884: elapsed=167392.0us expected=168586.9us +- 842.9us, error 0.7%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 239.706345/3874, current 239.873734/3884: elapsed=167392.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 239.873734
last_received_ts = 239.873123
last_seq = 3884
current_ts = 240.041107
current_received_ts = 240.040604
current_seq = 3894
count = 39
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 239.873734/3884, current 240.041107/3894: elapsed=167361.0us expected=168586.9us +- 842.9us, error 0.7%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 239.873734/3884, current 240.041107/3894: elapsed=167361.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 240.041107
last_received_ts = 240.040604
last_seq = 3894
current_ts = 240.208374
current_received_ts = 240.207916
current_seq = 3904
count = 40
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 240.041107/3894, current 240.208374/3904: elapsed=167267.0us expected=168586.9us +- 842.9us, error 0.8%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 240.041107/3894, current 240.208374/3904: elapsed=167267.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 240.208374
last_received_ts = 240.207916
last_seq = 3904
current_ts = 240.375626
current_received_ts = 240.375122
current_seq = 3914
count = 41
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 240.208374/3904, current 240.375626/3914: elapsed=167256.0us expected=168586.9us +- 842.9us, error 0.8%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 240.208374/3904, current 240.375626/3914: elapsed=167256.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 240.375626
last_received_ts = 240.375122
last_seq = 3914
current_ts = 240.542892
current_received_ts = 240.542374
current_seq = 3924
count = 42
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 240.375626/3914, current 240.542892/3924: elapsed=167272.0us expected=168586.9us +- 842.9us, error 0.8%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 240.375626/3914, current 240.542892/3924: elapsed=167272.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 240.542892
last_received_ts = 240.542374
last_seq = 3924
current_ts = 240.710159
current_received_ts = 240.709641
current_seq = 3934
count = 43
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 240.542892/3924, current 240.710159/3934: elapsed=167268.0us expected=168586.9us +- 842.9us, error 0.8%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 240.542892/3924, current 240.710159/3934: elapsed=167268.0us expected=168586.9us
(kms_flip:2800) DEBUG: name = vblank
last_ts = 240.710159
last_received_ts = 240.709641
last_seq = 3934
current_ts = 240.877426
current_received_ts = 240.876923
current_seq = 3944
count = 44
seq_step = 10
(kms_flip:2800) DEBUG: vblank ts/seq: last 240.710159/3934, current 240.877426/3944: elapsed=167269.0us expected=168586.9us +- 842.9us, error 0.8%
(kms_flip:2800) DEBUG: inconsistent vblank ts/seq: last 240.710159/3934, current 240.877426/3944: elapsed=167269.0us expected=168586.9us
(kms_flip:2800) INFO: Event vblank: expected 447, counted 450, passrate = 48.89%, encoder type 2
(kms_flip:2800) DEBUG: dropped frames, expected 447, counted 450, passrate = 48.89%, encoder type 2
(kms_flip:2800) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1709:
(kms_flip:2800) CRITICAL: Failed assertion: !retried
(kms_flip:2800) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2800) igt_core-INFO: Stack trace:
(kms_flip:2800) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2800) igt_core-INFO:   #1 ../tests/kms_flip.c:428 run_test_on_crtc_set.constprop.0()
(kms_flip:2800) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:2800) igt_core-INFO:   #3 ../tests/kms_flip.c:2158 __igt_unique____real_main2045()
(kms_flip:2800) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:2800) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2800) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2800) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-HDMI-A1: FAIL (18.983s)
Dmesg
<6> [221.495364] [IGT] kms_flip: starting dynamic subtest A-HDMI-A1
<7> [221.496051] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:84]
<7> [221.496185] i915 0000:00:02.0: [drm:drm_mode_addfb2] [FB:86]
<7> [221.532949] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:49:pipe A]
<7> [221.533379] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:66:pipe B]
<7> [221.533617] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [221.534398] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [221.534999] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [221.535455] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in has_pch_encoder (expected yes, found no)
<7> [221.535819] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in fdi_lanes (expected 1, found 0)
<7> [221.536224] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in fdi_m_n (expected tu 64 data 6039797/8388608 link 125829/524288, found tu 0, data 0/0 link 0/0)
<7> [221.536544] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in output_types (expected 0x00000002, found 0x00000000)
<7> [221.536845] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [221.537124] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1024, found 0)
<7> [221.537364] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 1344, found 0)
<7> [221.537659] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1024, found 0)
<7> [221.538043] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 1344, found 0)
<7> [221.538410] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 1048, found 0)
<7> [221.538770] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 1184, found 0)
<7> [221.539128] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 768, found 0)
<7> [221.539370] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 768, found 0)
<7> [221.539610] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 771, found 0)
<7> [221.539875] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 777, found 0)
<7> [221.540116] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 806, found 0)
<7> [221.540358] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 806, found 0)
<7> [221.540624] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1024, found 0)
<7> [221.541028] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 1344, found 0)
<7> [221.541401] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1024, found 0)
<7> [221.541765] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 1344, found 0)
<7> [221.542116] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 1048, found 0)
<7> [221.542367] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 1184, found 0)
<7> [221.542607] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 768, found 0)
<7> [221.542872] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 768, found 0)
<7> [221.543112] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 771, found 0)
<7> [221.543352] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 777, found 0)
<7> [221.543590] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 806, found 0)
<7> [221.543980] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 806, found 0)
<7> [221.544465] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [221.545024] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)
<7> [221.545476] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [221.545960] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [221.546223] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 64800, found 0)
<7> [221.546473] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 64800, found 0)
<7> [221.546715] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:66:pipe B] fastset requirement not met in port_clock (expected 64800, found 0)
<7> [221.546972] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:66:pipe B] fastset requirement not met, forcing full modeset
<7> [221.547212] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:66:pipe B] releasing PCH DPLL A
<7> [221.547506] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:66:pipe B] min cdclk: 72000 kHz -> 0 kHz
<7> [221.547768] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:66:pipe B] enable: no [modeset]
<7> [221.548029] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:50:primary B] fb: [NOFB], visible: no
<7> [221.548742] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [221.559344] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found
<7> [221.559908] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found
<7> [221.560444] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found
<7> [221.576143] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x2, on? 1) for [CRTC:66:pipe B]
<7> [221.576633] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A
<7> [221.577376] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:68:CRT]
<7> [221.577858] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:69:HDMI D]
<7> [221.578310] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:77:DP D]
<7> [221.578759] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:67:VGA-1]
<7> [221.579404] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:66:pipe B]
<7> [221.579786] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:49:pipe A]
<7> [221.579815] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:70:HDMI-A-1]
<7> [221.579933] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)
<7> [221.580208] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:49:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [221.580470] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3
<7> [221.580722] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [221.581001] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [221.581256] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [221.581510] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes)
<7> [221.581827] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3)
<7> [221.582135] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288)
<7> [221.582370] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [221.582604] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [221.582862] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [221.583104] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [221.583348] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [221.583581] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [221.583814] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [221.584073] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [221.584385] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [221.584644] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [221.584912] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [221.585163] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [221.585396] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [221.585633] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [221.585898] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [221.586149] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [221.586382] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [221.586614] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [221.586948] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [221.587230] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [221.587464] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [221.587696] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [221.587963] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [221.588197] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [221.588441] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [221.588673] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [221.588946] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [221.589186] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [221.589499] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [221.589732] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [221.590036] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)
<7> [221.590291] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)
<7> [221.590545] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in dpll_hw_state
<7> [221.590809] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [221.591092] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0x84100010, dpll_md: 0x0, fp0: 0x10c09, fp1: 0x10c09
<7> [221.591346] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [221.591599] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06
<7> [221.591927] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [221.592209] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800)
<7> [221.592443] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800)
<7> [221.592675] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in port_clock (expected 0, found 223200)
<7> [221.592934] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)
<7> [221.593174] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)
<7> [221.593426] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in avi infoframe
<7> [221.593665] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [221.593931] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [221.594170] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [221.594174] i915 0000:00:02.0: colorspace: RGB
<7> [221.594176] i915 0000:00:02.0: scan mode: Underscan
<7> [221.594178] i915 0000:00:02.0: colorimetry: No Data
<7> [221.594181] i915 0000:00:02.0: picture aspect: 16:9
<7> [221.594183] i915 0000:00:02.0: active aspect: Same as Picture
<7> [221.594185] i915 0000:00:02.0: itc: No Data
<7> [221.594188] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [221.594190] i915 0000:00:02.0: quantization range: Default
<7> [221.594192] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [221.594194] i915 0000:00:02.0: video code: 16
<7> [221.594197] i915 0000:00:02.0: ycc quantization range: Full
<7> [221.594199] i915 0000:00:02.0: hdmi content type: Graphics
<7> [221.594201] i915 0000:00:02.0: pixel repeat: 0
<7> [221.594203] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [221.594206] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in spd infoframe
<7> [221.594514] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [221.594754] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [221.595023] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [221.595027] i915 0000:00:02.0: vendor: Intel
<7> [221.595029] i915 0000:00:02.0: product: Integrated gfx
<7> [221.595031] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [221.595034] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hdmi infoframe
<7> [221.595274] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [221.595512] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [221.595760] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [221.595763] i915 0000:00:02.0: empty frame
<7> [221.595766] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:49:pipe A] fastset requirement not met, forcing full modeset
<7> [221.596078] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:49:pipe A] min cdclk: 0 kHz -> 165334 kHz
<7> [221.596335] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:49:pipe A] allocated PCH DPLL A
<7> [221.596565] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:49:pipe A] reserving PCH DPLL A
<7> [221.596808] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:49:pipe A] enable: yes [modeset]
<7> [221.597096] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [221.597335] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0
<7> [221.597574] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [221.597812] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [221.597846] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on
<7> [221.598068] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [221.598310] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [221.598541] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64
<7> [221.598773] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71
<7> [221.599056] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6
<7> [221.599298] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [221.599301] i915 0000:00:02.0: colorspace: RGB
<7> [221.599303] i915 0000:00:02.0: scan mode: Underscan
<7> [221.599306] i915 0000:00:02.0: colorimetry: No Data
<7> [221.599308] i915 0000:00:02.0: picture aspect: 16:9
<7> [221.599310] i915 0000:00:02.0: active aspect: Same as Picture
<7> [221.599312] i915 0000:00:02.0: itc: No Data
<7> [221.599314] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [221.599316] i915 0000:00:02.0: quantization range: Default
<7> [221.599319] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [221.599321] i915 0000:00:02.0: video code: 16
<7> [221.599323] i915 0000:00:02.0: ycc quantization range: Full
<7> [221.599325] i915 0000:00:02.0: hdmi content type: Graphics
<7> [221.599327] i915 0000:00:02.0: pixel repeat: 0
<7> [221.599329] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [221.599332] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [221.599334] i915 0000:00:02.0: vendor: Intel
<7> [221.599337] i915 0000:00:02.0: product: Integrated gfx
<7> [221.599339] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [221.599341] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [221.599344] i915 0000:00:02.0: empty frame
<7> [221.599346] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00
<7> [221.599590] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51
<7> [221.599860] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00
<7> [221.600117] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1
<7> [221.600349] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [221.600580] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [221.600821] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [221.601084] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [221.601329] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [221.601561] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [221.601807] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [221.602065] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [221.602309] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pipe src: 1920x1080+0+0, pixel rate 148800, min cdclk 165334
<7> [221.602558] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0
<7> [221.602789] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [221.603055] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [221.603287] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06
<7> [221.603519] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [221.603759] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [221.604022] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [221.604265] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [221.604497] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [221.604728] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [221.604984] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [221.605267] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:primary A] fb: [FB:84] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [221.605500] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [221.605732] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [221.608128] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on
<7> [221.608384] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:68:CRT]
<7> [221.608617] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:69:HDMI D]
<7> [221.608894] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:77:DP D]
<7> [221.609840] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [221.611012] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100
<7> [221.611243] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done.
<7> [221.612148] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x200
<7> [221.612410] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done.
<7> [221.612637] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done.
<7> [221.612920] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:49:pipe A]
<7> [221.613196] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A
<7> [221.665004] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:70:HDMI-A-1][ENCODER:69:HDMI D] Enable audio codec on [CRTC:49:pipe A], 36 bytes ELD
<7> [221.681610] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults
<7> [221.682197] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000)
<7> [221.682736] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:70:HDMI-A-1]
<7> [221.683374] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:49:pipe A]
<7> [232.418362] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:49:pipe A]
<7> [232.418573] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [232.419184] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [232.420031] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [232.420864] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_pch_encoder (expected yes, found no)
<7> [232.421662] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in fdi_lanes (expected 3, found 0)
<7> [232.422370] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in fdi_m_n (expected tu 64 data 6934582/8388608 link 288940/524288, found tu 0, data 0/0 link 0/0)
<7> [232.422868] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [232.423337] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [232.423855] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [232.424322] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [232.424829] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [232.425107] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [232.425428] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [232.425809] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [232.426176] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [232.426538] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [232.426892] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [232.427160] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [232.427399] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [232.427639] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [232.427902] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [232.428160] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [232.428400] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [232.428638] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [232.428904] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [232.429174] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [232.429407] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [232.429648] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [232.430071] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [232.430324] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [232.430556] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [232.430822] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [232.431073] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [232.431321] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [232.431554] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [232.431820] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [232.432088] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_hdmi_sink (expected yes, found no)
<7> [232.432321] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_infoframe (expected yes, found no)
<7> [232.432568] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [232.432829] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148800, found 0)
<7> [232.433088] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148800, found 0)
<7> [232.433321] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in port_clock (expected 223200, found 0)
<7> [232.433553] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000)
<7> [232.433836] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000006, found 0x00000000)
<7> [232.434121] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in avi infoframe
<7> [232.434353] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [232.434585] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [232.434588] i915 0000:00:02.0: colorspace: RGB
<7> [232.434590] i915 0000:00:02.0: scan mode: Underscan
<7> [232.434592] i915 0000:00:02.0: colorimetry: No Data
<7> [232.434595] i915 0000:00:02.0: picture aspect: 16:9
<7> [232.434597] i915 0000:00:02.0: active aspect: Same as Picture
<7> [232.434599] i915 0000:00:02.0: itc: No Data
<7> [232.434601] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [232.434604] i915 0000:00:02.0: quantization range: Default
<7> [232.434626] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [232.434638] i915 0000:00:02.0: video code: 16
<7> [232.434642] i915 0000:00:02.0: ycc quantization range: Full
<7> [232.434646] i915 0000:00:02.0: hdmi content type: Graphics
<7> [232.434650] i915 0000:00:02.0: pixel repeat: 0
<7> [232.434654] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [232.434659] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [232.434947] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in spd infoframe
<7> [232.435197] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [232.435438] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [232.435440] i915 0000:00:02.0: vendor: Intel
<7> [232.435443] i915 0000:00:02.0: product: Integrated gfx
<7> [232.435445] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [232.435448] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [232.435711] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hdmi infoframe
<7> [232.435972] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [232.436210] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [232.436213] i915 0000:00:02.0: empty frame
<7> [232.436216] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [232.436454] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:49:pipe A] fastset requirement not met, forcing full modeset
<7> [232.436709] i915 0000:00:02.0: [drm:intel_dpll_crtc_put [i915]] [CRTC:49:pipe A] releasing PCH DPLL A
<7> [232.437009] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:49:pipe A] min cdclk: 165334 kHz -> 0 kHz
<7> [232.437254] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:49:pipe A] enable: no [modeset]
<7> [232.437493] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:primary A] fb: [NOFB], visible: no
<7> [232.437817] i915 0000:00:02.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:70:HDMI-A-1][ENCODER:69:HDMI D] Disable audio codec on [CRTC:49:pipe A]
<7> [232.460074] i915 0000:00:02.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [232.476981] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port B found
<7> [232.477474] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port C found
<7> [232.477984] i915 0000:00:02.0: [drm:g4x_dp_port_enabled [i915]] No pipe for DP port D found
<7> [232.489134] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disable PCH DPLL A (active 0x1, on? 1) for [CRTC:49:pipe A]
<7> [232.489487] i915 0000:00:02.0: [drm:intel_dpll_disable [i915]] disabling PCH DPLL A
<7> [232.490073] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:68:CRT]
<7> [232.490413] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:69:HDMI D]
<7> [232.490742] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:77:DP D]
<7> [232.491116] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:70:HDMI-A-1]
<7> [232.491558] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:49:pipe A]
<7> [232.492109] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:66:pipe B]
<7> [232.492313] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:49:pipe A]
<7> [232.492351] i915 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:70:HDMI-A-1]
<7> [232.492489] i915 0000:00:02.0: [drm:intel_hdmi_compute_clock [i915]] picking 12 bpc for HDMI output (pipe bpp: 36)
<7> [232.492922] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:49:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [232.493272] i915 0000:00:02.0: [drm:intel_fdi_atomic_check_link [i915]] checking fdi config on pipe A, lanes 3
<7> [232.493601] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [232.493967] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [232.494348] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [232.494737] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_pch_encoder (expected no, found yes)
<7> [232.495194] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in fdi_lanes (expected 0, found 3)
<7> [232.495781] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in fdi_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6934582/8388608 link 288940/524288)
<7> [232.496073] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [232.496314] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [232.496567] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [232.496822] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [232.497062] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [232.497302] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [232.497541] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [232.497798] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [232.498038] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [232.498277] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [232.498516] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [232.498781] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [232.499021] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [232.499262] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [232.499494] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [232.499757] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [232.499990] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [232.500223] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [232.500455] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [232.500719] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [232.500969] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [232.501202] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [232.501434] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [232.501695] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [232.501928] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [232.502160] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [232.502391] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [232.502661] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [232.502894] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [232.503126] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [232.503358] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_hdmi_sink (expected no, found yes)
<7> [232.503629] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in has_infoframe (expected no, found yes)
<7> [232.503862] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [232.504095] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148800)
<7> [232.504327] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148800)
<7> [232.504616] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in port_clock (expected 0, found 223200)
<7> [232.504857] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)
<7> [232.505090] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in infoframes.gcp (expected 0x00000000, found 0x00000006)
<7> [232.505323] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in avi infoframe
<7> [232.505587] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [232.505819] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [232.506050] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [232.506053] i915 0000:00:02.0: colorspace: RGB
<7> [232.506056] i915 0000:00:02.0: scan mode: Underscan
<7> [232.506058] i915 0000:00:02.0: colorimetry: No Data
<7> [232.506060] i915 0000:00:02.0: picture aspect: 16:9
<7> [232.506062] i915 0000:00:02.0: active aspect: Same as Picture
<7> [232.506064] i915 0000:00:02.0: itc: No Data
<7> [232.506066] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [232.506069] i915 0000:00:02.0: quantization range: Default
<7> [232.506071] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [232.506073] i915 0000:00:02.0: video code: 16
<7> [232.506075] i915 0000:00:02.0: ycc quantization range: Full
<7> [232.506078] i915 0000:00:02.0: hdmi content type: Graphics
<7> [232.506080] i915 0000:00:02.0: pixel repeat: 0
<7> [232.506082] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [232.506085] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in spd infoframe
<7> [232.506317] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [232.506587] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [232.506820] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [232.506823] i915 0000:00:02.0: vendor: Intel
<7> [232.506825] i915 0000:00:02.0: product: Integrated gfx
<7> [232.506827] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [232.506830] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] [CRTC:49:pipe A] fastset requirement not met in hdmi infoframe
<7> [232.507063] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] expected:
<7> [232.507295] i915 0000:00:02.0: [drm:intel_pipe_config_compare [i915]] found:
<7> [232.507556] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [232.507559] i915 0000:00:02.0: empty frame
<7> [232.507562] i915 0000:00:02.0: [drm:intel_atomic_check [i915]] [CRTC:49:pipe A] fastset requirement not met, forcing full modeset
<7> [232.507853] i915 0000:00:02.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:49:pipe A] min cdclk: 0 kHz -> 165334 kHz
<7> [232.508106] i915 0000:00:02.0: [drm:intel_find_dpll [i915]] [CRTC:49:pipe A] allocated PCH DPLL A
<7> [232.508337] i915 0000:00:02.0: [drm:intel_dpll_crtc_get [i915]] [CRTC:49:pipe A] reserving PCH DPLL A
<7> [232.508631] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [CRTC:49:pipe A] enable: yes [modeset]
<7> [232.508901] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [232.509143] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0
<7> [232.509384] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [232.509501] i915 0000:00:02.0: [drm:intel_power_well_disable [i915]] disabling always-on
<7> [232.509752] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [232.510075] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [232.510347] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [232.510626] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] fdi: lanes: 3; data_m: 6934582, data_n: 8388608, link_m: 288940, link_n: 524288, tu: 64
<7> [232.510876] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 1, infoframes enabled: 0x71
<7> [232.511124] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] GCP: 0x6
<7> [232.511364] i915 0000:00:02.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [232.511367] i915 0000:00:02.0: colorspace: RGB
<7> [232.511369] i915 0000:00:02.0: scan mode: Underscan
<7> [232.511371] i915 0000:00:02.0: colorimetry: No Data
<7> [232.511373] i915 0000:00:02.0: picture aspect: 16:9
<7> [232.511376] i915 0000:00:02.0: active aspect: Same as Picture
<7> [232.511378] i915 0000:00:02.0: itc: No Data
<7> [232.511380] i915 0000:00:02.0: extended colorimetry: xvYCC 601
<7> [232.511382] i915 0000:00:02.0: quantization range: Default
<7> [232.511384] i915 0000:00:02.0: nups: Unknown Non-uniform Scaling
<7> [232.511386] i915 0000:00:02.0: video code: 16
<7> [232.511389] i915 0000:00:02.0: ycc quantization range: Full
<7> [232.511391] i915 0000:00:02.0: hdmi content type: Graphics
<7> [232.511393] i915 0000:00:02.0: pixel repeat: 0
<7> [232.511395] i915 0000:00:02.0: bar top 0, bottom 0, left 0, right 0
<7> [232.511398] i915 0000:00:02.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [232.511400] i915 0000:00:02.0: vendor: Intel
<7> [232.511402] i915 0000:00:02.0: product: Integrated gfx
<7> [232.511405] i915 0000:00:02.0: source device information: PC General (0x9)
<7> [232.511407] i915 0000:00:02.0: HDMI infoframe: Vendor, version 1, length 4
<7> [232.511409] i915 0000:00:02.0: empty frame
<7> [232.511412] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 08 00 65 32 00 01 00 00 00 00 00 00 00 00
<7> [232.511679] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 4d 69 20 54 56 09 07 07 11 17 50 51
<7> [232.511931] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ELD: 07 00 00 00
<7> [232.512163] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1
<7> [232.512401] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [232.512663] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [232.512913] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [232.513145] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [232.513461] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [232.513739] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [232.513978] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148800 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [232.514239] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148800, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [232.514496] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] port clock: 223200, pipe src: 1920x1080+0+0, pixel rate 148800, min cdclk 165334
<7> [232.514741] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] linetime: 0, ips linetime: 0
<7> [232.514981] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [232.515220] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [232.515471] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0xc4010001, dpll_md: 0x0, fp0: 0x30f06, fp1: 0x30f06
<7> [232.515712] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x3 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [232.516042] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [232.516282] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [232.516538] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [232.516801] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [232.517047] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [232.517291] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [232.517569] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] [PLANE:33:primary A] fb: [FB:84] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000001, visible: yes
<7> [232.517854] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [232.518086] i915 0000:00:02.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [232.518465] i915 0000:00:02.0: [drm:intel_power_well_enable [i915]] enabling always-on
<7> [232.518804] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:68:CRT]
<7> [232.519053] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:69:HDMI D]
<7> [232.519278] i915 0000:00:02.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:77:DP D]
<7> [232.520216] i915 0000:00:02.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [232.521345] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x100
<7> [232.521581] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 1 done.
<7> [232.522475] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI_RX_IIR 0x200
<7> [232.522710] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train 2 done.
<7> [232.522943] i915 0000:00:02.0: [drm:gen6_fdi_link_train [i915]] FDI train done.
<7> [232.523211] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enable PCH DPLL A (active 0x1, on? 0) for [CRTC:49:pipe A]
<7> [232.523522] i915 0000:00:02.0: [drm:intel_dpll_enable [i915]] enabling PCH DPLL A
<7> [232.575238] i915 0000:00:02.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:70:HDMI-A-1][ENCODER:69:HDMI D] Enable audio codec on [CRTC:49:pipe A], 36 bytes ELD
<7> [232.591841] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] HDMI audio pixel clock setting for 148800 not found, falling back to defaults
<7> [232.592375] i915 0000:00:02.0: [drm:audio_config_hdmi_pixel_clock [i915]] Configuring HDMI audio for pixel clock 25200 (0x00010000)
<7> [232.592872] i915 0000:00:02.0: [drm:verify_connector_state [i915]] [CONNECTOR:70:HDMI-A-1]
<7> [232.593424] i915 0000:00:02.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:49:pipe A]
<6> [240.480067] [IGT] kms_flip: finished subtest A-HDMI-A1, FAIL
Created at 2025-11-12 21:01:48