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

Result: Fail

i915_display_info22 igt_runner22 results22.json results22-xe-load.json guc_logs22.tar i915_display_info_post_exec22 boot22 dmesg22

DetailValue
Duration 1.86 seconds
Hostname 
shard-bmg-9
Igt-Version 
IGT-Version: 2.3-gb5051dc2e (x86_64) (Linux: 7.0.0-rc2-lgci-xe-xe-4675-fce8d7fb2107068c2-debug+ x86_64)
Out 
Starting dynamic subtest: C-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1887 run_test()
  #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
  #4 ../tests/kms_flip.c:2043 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest C-HDMI-A3: FAIL (1.862s)
Err 
Starting dynamic subtest: C-HDMI-A3
(kms_flip:13993) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:13993) CRITICAL: Failed assertion: end - start < 500
(kms_flip:13993) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest C-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:13993) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 0: 0x0000000c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 1: 0x0000000e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 2: 0x0000000f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 3: 0x0000003c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 4: 0x00000032
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 5: 0x0000003e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 6: 0x0000041c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 7: 0x00000033
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 8: 0x00000030
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 9: 0x0000020c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 10: 0x00000230
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 11: 0x0000061c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 12: 0x0000023c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 13: 0x00000000
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 14: 0x00000200
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 15: 0x00000614
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 16: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 17: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 18: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 19: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 20: 0x0000004c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 21: 0x0000024c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 22: 0x0000004e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 23: 0x0000004f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 24: 0x0000008c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 25: 0x0000028c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 26: 0x0000008e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 27: 0x0000008f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 0: 0x0000000c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 1: 0x0000000e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 2: 0x0000000f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 3: 0x0000003c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 4: 0x00000032
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 5: 0x0000003e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 6: 0x0000041c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 7: 0x00000033
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 8: 0x00000030
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 9: 0x0000020c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 10: 0x00000230
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 11: 0x0000061c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 12: 0x0000023c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 13: 0x00000000
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 14: 0x00000200
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 15: 0x00000614
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 16: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 17: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 18: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 19: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 20: 0x0000004c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 21: 0x0000024c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 22: 0x0000004e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 23: 0x0000004f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 24: 0x0000008c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 25: 0x0000028c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 26: 0x0000008e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 27: 0x0000008f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 0: 0x0000000c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 1: 0x0000000e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 2: 0x0000000f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 3: 0x0000003c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 4: 0x00000032
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 5: 0x0000003e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 6: 0x0000041c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 7: 0x00000033
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 8: 0x00000030
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 9: 0x0000020c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 10: 0x00000230
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 11: 0x0000061c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 12: 0x0000023c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 13: 0x00000000
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 14: 0x00000200
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 15: 0x00000614
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 16: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 17: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 18: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 19: 0x00000000 (reserved)
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 20: 0x0000004c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 21: 0x0000024c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 22: 0x0000004e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 23: 0x0000004f
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 24: 0x0000008c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 25: 0x0000028c
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 26: 0x0000008e
(kms_flip:13993) intel_pat-DEBUG: Parsed PAT entry 27: 0x0000008f
(kms_flip:13993) intel_allocator_simple-DEBUG: <ial: 0x635a4b920700, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:13993) intel_allocator_simple-DEBUG: <ial: 0x635a4b920700, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:13993) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9 
(kms_flip:13993) DEBUG: No stale events found
(kms_flip:13993) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:13993) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:13993) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 596.501892
current_received_ts = 596.501526
current_seq = 280
count = 0
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 40us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.501892
last_received_ts = 596.501526
last_seq = 280
current_ts = 596.518616
current_received_ts = 596.518250
current_seq = 281
count = 1
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 28us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.518616
last_received_ts = 596.518250
last_seq = 281
current_ts = 596.535278
current_received_ts = 596.534912
current_seq = 282
count = 2
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.535278
last_received_ts = 596.534912
last_seq = 282
current_ts = 596.551941
current_received_ts = 596.551575
current_seq = 283
count = 3
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.551941
last_received_ts = 596.551575
last_seq = 283
current_ts = 596.568604
current_received_ts = 596.568237
current_seq = 284
count = 4
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.568604
last_received_ts = 596.568237
last_seq = 284
current_ts = 596.585266
current_received_ts = 596.584778
current_seq = 285
count = 5
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.585266
last_received_ts = 596.584778
last_seq = 285
current_ts = 596.601929
current_received_ts = 596.601562
current_seq = 286
count = 6
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.601929
last_received_ts = 596.601562
last_seq = 286
current_ts = 596.618591
current_received_ts = 596.618164
current_seq = 287
count = 7
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.618591
last_received_ts = 596.618164
last_seq = 287
current_ts = 596.635254
current_received_ts = 596.634766
current_seq = 288
count = 8
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.635254
last_received_ts = 596.634766
last_seq = 288
current_ts = 596.651978
current_received_ts = 596.651550
current_seq = 289
count = 9
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.651978
last_received_ts = 596.651550
last_seq = 289
current_ts = 596.668640
current_received_ts = 596.668152
current_seq = 290
count = 10
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.668640
last_received_ts = 596.668152
last_seq = 290
current_ts = 596.685303
current_received_ts = 596.684937
current_seq = 291
count = 11
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.685303
last_received_ts = 596.684937
last_seq = 291
current_ts = 596.701965
current_received_ts = 596.701538
current_seq = 292
count = 12
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.701965
last_received_ts = 596.701538
last_seq = 292
current_ts = 596.718628
current_received_ts = 596.718201
current_seq = 293
count = 13
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.718628
last_received_ts = 596.718201
last_seq = 293
current_ts = 596.735291
current_received_ts = 596.734924
current_seq = 294
count = 14
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.735291
last_received_ts = 596.734924
last_seq = 294
current_ts = 596.751953
current_received_ts = 596.751526
current_seq = 295
count = 15
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.751953
last_received_ts = 596.751526
last_seq = 295
current_ts = 596.768677
current_received_ts = 596.768188
current_seq = 296
count = 16
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.768677
last_received_ts = 596.768188
last_seq = 296
current_ts = 596.785339
current_received_ts = 596.784851
current_seq = 297
count = 17
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.785339
last_received_ts = 596.784851
last_seq = 297
current_ts = 596.802002
current_received_ts = 596.801636
current_seq = 298
count = 18
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.802002
last_received_ts = 596.801636
last_seq = 298
current_ts = 596.818665
current_received_ts = 596.818298
current_seq = 299
count = 19
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.818665
last_received_ts = 596.818298
last_seq = 299
current_ts = 596.835327
current_received_ts = 596.834961
current_seq = 300
count = 20
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.835327
last_received_ts = 596.834961
last_seq = 300
current_ts = 596.851990
current_received_ts = 596.851562
current_seq = 301
count = 21
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.851990
last_received_ts = 596.851562
last_seq = 301
current_ts = 596.868652
current_received_ts = 596.868225
current_seq = 302
count = 22
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 24us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.868652
last_received_ts = 596.868225
last_seq = 302
current_ts = 596.885315
current_received_ts = 596.884949
current_seq = 303
count = 23
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 43us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.885315
last_received_ts = 596.884949
last_seq = 303
current_ts = 596.902039
current_received_ts = 596.901550
current_seq = 304
count = 24
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.902039
last_received_ts = 596.901550
last_seq = 304
current_ts = 596.918701
current_received_ts = 596.918213
current_seq = 305
count = 25
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.918701
last_received_ts = 596.918213
last_seq = 305
current_ts = 596.935364
current_received_ts = 596.934998
current_seq = 306
count = 26
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 44us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.935364
last_received_ts = 596.934998
last_seq = 306
current_ts = 596.952026
current_received_ts = 596.951599
current_seq = 307
count = 27
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.952026
last_received_ts = 596.951599
last_seq = 307
current_ts = 596.968689
current_received_ts = 596.968323
current_seq = 308
count = 28
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.968689
last_received_ts = 596.968323
last_seq = 308
current_ts = 596.985352
current_received_ts = 596.984985
current_seq = 309
count = 29
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 596.985352
last_received_ts = 596.984985
last_seq = 309
current_ts = 597.002014
current_received_ts = 597.001587
current_seq = 310
count = 30
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.002014
last_received_ts = 597.001587
last_seq = 310
current_ts = 597.018677
current_received_ts = 597.018311
current_seq = 311
count = 31
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.018677
last_received_ts = 597.018311
last_seq = 311
current_ts = 597.035400
current_received_ts = 597.034912
current_seq = 312
count = 32
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.035400
last_received_ts = 597.034912
last_seq = 312
current_ts = 597.052063
current_received_ts = 597.051697
current_seq = 313
count = 33
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.052063
last_received_ts = 597.051697
last_seq = 313
current_ts = 597.068726
current_received_ts = 597.068237
current_seq = 314
count = 34
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.068726
last_received_ts = 597.068237
last_seq = 314
current_ts = 597.085388
current_received_ts = 597.085022
current_seq = 315
count = 35
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.085388
last_received_ts = 597.085022
last_seq = 315
current_ts = 597.102051
current_received_ts = 597.101685
current_seq = 316
count = 36
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.102051
last_received_ts = 597.101685
last_seq = 316
current_ts = 597.118713
current_received_ts = 597.118408
current_seq = 317
count = 37
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 35us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.118713
last_received_ts = 597.118408
last_seq = 317
current_ts = 597.135376
current_received_ts = 597.135071
current_seq = 318
count = 38
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 28us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.135376
last_received_ts = 597.135071
last_seq = 318
current_ts = 597.152039
current_received_ts = 597.151611
current_seq = 319
count = 39
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.152039
last_received_ts = 597.151611
last_seq = 319
current_ts = 597.168762
current_received_ts = 597.168396
current_seq = 320
count = 40
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.168762
last_received_ts = 597.168396
last_seq = 320
current_ts = 597.185425
current_received_ts = 597.184937
current_seq = 321
count = 41
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.185425
last_received_ts = 597.184937
last_seq = 321
current_ts = 597.202087
current_received_ts = 597.201721
current_seq = 322
count = 42
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.202087
last_received_ts = 597.201721
last_seq = 322
current_ts = 597.218750
current_received_ts = 597.218384
current_seq = 323
count = 43
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.218750
last_received_ts = 597.218384
last_seq = 323
current_ts = 597.235413
current_received_ts = 597.235291
current_seq = 324
count = 44
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.235413
last_received_ts = 597.235291
last_seq = 324
current_ts = 597.252075
current_received_ts = 597.251709
current_seq = 325
count = 45
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 28us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.252075
last_received_ts = 597.251709
last_seq = 325
current_ts = 597.268738
current_received_ts = 597.268372
current_seq = 326
count = 46
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.268738
last_received_ts = 597.268372
last_seq = 326
current_ts = 597.285461
current_received_ts = 597.285034
current_seq = 327
count = 47
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.285461
last_received_ts = 597.285034
last_seq = 327
current_ts = 597.302124
current_received_ts = 597.301758
current_seq = 328
count = 48
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.302124
last_received_ts = 597.301758
last_seq = 328
current_ts = 597.318787
current_received_ts = 597.318420
current_seq = 329
count = 49
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.318787
last_received_ts = 597.318420
last_seq = 329
current_ts = 597.335449
current_received_ts = 597.335327
current_seq = 330
count = 50
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.335449
last_received_ts = 597.335327
last_seq = 330
current_ts = 597.352112
current_received_ts = 597.351746
current_seq = 331
count = 51
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.352112
last_received_ts = 597.351746
last_seq = 331
current_ts = 597.368774
current_received_ts = 597.368408
current_seq = 332
count = 52
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.368774
last_received_ts = 597.368408
last_seq = 332
current_ts = 597.385437
current_received_ts = 597.385071
current_seq = 333
count = 53
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.385437
last_received_ts = 597.385071
last_seq = 333
current_ts = 597.402161
current_received_ts = 597.401733
current_seq = 334
count = 54
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.402161
last_received_ts = 597.401733
last_seq = 334
current_ts = 597.418823
current_received_ts = 597.418457
current_seq = 335
count = 55
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.418823
last_received_ts = 597.418457
last_seq = 335
current_ts = 597.435486
current_received_ts = 597.434998
current_seq = 336
count = 56
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 43us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.435486
last_received_ts = 597.434998
last_seq = 336
current_ts = 597.452148
current_received_ts = 597.451782
current_seq = 337
count = 57
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.452148
last_received_ts = 597.451782
last_seq = 337
current_ts = 597.468811
current_received_ts = 597.468445
current_seq = 338
count = 58
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.468811
last_received_ts = 597.468445
last_seq = 338
current_ts = 597.485474
current_received_ts = 597.485107
current_seq = 339
count = 59
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.485474
last_received_ts = 597.485107
last_seq = 339
current_ts = 597.502136
current_received_ts = 597.501770
current_seq = 340
count = 60
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.502136
last_received_ts = 597.501770
last_seq = 340
current_ts = 597.518799
current_received_ts = 597.518433
current_seq = 341
count = 61
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.518799
last_received_ts = 597.518433
last_seq = 341
current_ts = 597.535522
current_received_ts = 597.535156
current_seq = 342
count = 62
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 38us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.535522
last_received_ts = 597.535156
last_seq = 342
current_ts = 597.552185
current_received_ts = 597.551819
current_seq = 343
count = 63
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 39us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.552185
last_received_ts = 597.551819
last_seq = 343
current_ts = 597.568848
current_received_ts = 597.568481
current_seq = 344
count = 64
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.568848
last_received_ts = 597.568481
last_seq = 344
current_ts = 597.585510
current_received_ts = 597.585144
current_seq = 345
count = 65
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.585510
last_received_ts = 597.585144
last_seq = 345
current_ts = 597.602173
current_received_ts = 597.601807
current_seq = 346
count = 66
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.602173
last_received_ts = 597.601807
last_seq = 346
current_ts = 597.618835
current_received_ts = 597.618469
current_seq = 347
count = 67
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 25us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.618835
last_received_ts = 597.618469
last_seq = 347
current_ts = 597.635498
current_received_ts = 597.635071
current_seq = 348
count = 68
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 26us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.635498
last_received_ts = 597.635071
last_seq = 348
current_ts = 597.652161
current_received_ts = 597.651672
current_seq = 349
count = 69
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.652161
last_received_ts = 597.651672
last_seq = 349
current_ts = 597.668884
current_received_ts = 597.668457
current_seq = 350
count = 70
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.668884
last_received_ts = 597.668457
last_seq = 350
current_ts = 597.685547
current_received_ts = 597.685059
current_seq = 351
count = 71
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.685547
last_received_ts = 597.685059
last_seq = 351
current_ts = 597.702209
current_received_ts = 597.701843
current_seq = 352
count = 72
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.702209
last_received_ts = 597.701843
last_seq = 352
current_ts = 597.718872
current_received_ts = 597.718445
current_seq = 353
count = 73
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 27us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.718872
last_received_ts = 597.718445
last_seq = 353
current_ts = 597.735535
current_received_ts = 597.735168
current_seq = 354
count = 74
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 241us
(kms_flip:13993) DEBUG: name = flip
last_ts = 597.735535
last_received_ts = 597.735168
last_seq = 354
current_ts = 597.752197
current_received_ts = 597.751892
current_seq = 355
count = 75
seq_step = 1
(kms_flip:13993) DEBUG: Vblank took 525us
(kms_flip:13993) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:926:
(kms_flip:13993) CRITICAL: Failed assertion: end - start < 500
(kms_flip:13993) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:13993) igt_core-INFO: Stack trace:
(kms_flip:13993) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:13993) igt_core-INFO:   #1 ../tests/kms_flip.c:921 run_test_on_crtc_set.constprop.0()
(kms_flip:13993) igt_core-INFO:   #2 ../tests/kms_flip.c:1887 run_test()
(kms_flip:13993) igt_core-INFO:   #3 ../tests/kms_flip.c:2156 __igt_unique____real_main2043()
(kms_flip:13993) igt_core-INFO:   #4 ../tests/kms_flip.c:2043 main()
(kms_flip:13993) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:13993) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:13993) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest C-HDMI-A3: FAIL (1.862s)
Dmesg
<6> [611.036031] [IGT] kms_flip: starting dynamic subtest C-HDMI-A3
<7> [611.037654] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:555]
<7> [611.038590] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:556]
<7> [611.080752] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:150:pipe A]
<7> [611.080866] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]
<7> [611.080927] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [611.081050] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [611.081150] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [611.081249] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [611.081343] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [611.081441] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [611.081610] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [611.081761] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [611.081904] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [611.082043] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [611.082181] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [611.082320] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [611.082458] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [611.082617] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [611.082762] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1083, found 0)
<7> [611.082917] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1088, found 0)
<7> [611.083059] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [611.083197] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [611.083335] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [611.083476] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [611.083641] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [611.083783] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [611.083924] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [611.084064] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [611.084201] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [611.084337] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [611.084475] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1083, found 0)
<7> [611.084685] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1088, found 0)
<7> [611.084822] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [611.084959] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [611.085100] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [611.085241] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [611.085382] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)
<7> [611.085526] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in has_hdmi_sink (expected yes, found no)
<7> [611.085665] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in has_infoframe (expected yes, found no)
<7> [611.085800] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [611.085938] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [611.086080] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [611.086223] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [611.086363] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in infoframes.enable (expected 0x00000071, found 0x00000000)
<7> [611.086508] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in avi infoframe
<7> [611.086646] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [611.086789] xe 0000:03:00.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [611.086792] xe 0000:03:00.0: colorspace: RGB
<7> [611.086794] xe 0000:03:00.0: scan mode: Underscan
<7> [611.086796] xe 0000:03:00.0: colorimetry: No Data
<7> [611.086798] xe 0000:03:00.0: picture aspect: No Data
<7> [611.086801] xe 0000:03:00.0: active aspect: Same as Picture
<7> [611.086803] xe 0000:03:00.0: itc: No Data
<7> [611.086805] xe 0000:03:00.0: extended colorimetry: xvYCC 601
<7> [611.086807] xe 0000:03:00.0: quantization range: Full
<7> [611.086809] xe 0000:03:00.0: nups: Unknown Non-uniform Scaling
<7> [611.086811] xe 0000:03:00.0: video code: 0
<7> [611.086814] xe 0000:03:00.0: ycc quantization range: Full
<7> [611.086816] xe 0000:03:00.0: hdmi content type: Graphics
<7> [611.086818] xe 0000:03:00.0: pixel repeat: 0
<7> [611.086820] xe 0000:03:00.0: bar top 0, bottom 0, left 0, right 0
<7> [611.086823] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [611.086966] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in spd infoframe
<7> [611.087107] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [611.087244] xe 0000:03:00.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [611.087247] xe 0000:03:00.0: vendor: Intel
<7> [611.087249] xe 0000:03:00.0: product: Discrete gfx
<7> [611.087251] xe 0000:03:00.0: source device information: PC General (0x9)
<7> [611.087254] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [611.087391] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:268:pipe B] fastset requirement not met in hdmi infoframe
<7> [611.087534] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [611.087673] xe 0000:03:00.0: HDMI infoframe: Vendor, version 1, length 4
<7> [611.087675] xe 0000:03:00.0: empty frame
<7> [611.087678] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [611.087815] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:268:pipe B] fastset requirement not met, forcing full modeset
<7> [611.087952] xe 0000:03:00.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:268:pipe B] releasing TC PLL 3
<7> [611.088134] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [611.088258] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:268:pipe B] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [611.088413] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:262:cursor B] ddb (4037 - 4096) -> ( 0 - 0), size 59 -> 0
<7> [611.088567] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:268:pipe B] min cdclk: 192000 kHz -> 0 kHz
<7> [611.088738] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:268:pipe B] enable: no [modeset]
<7> [611.088881] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:152:plane 1B] fb: [NOFB], visible: no
<7> [611.089020] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:182:plane 2B] fb: [NOFB], visible: no
<7> [611.089158] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:212:plane 3B] fb: [NOFB], visible: no
<7> [611.089295] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:242:plane 4B] fb: [NOFB], visible: no
<7> [611.089434] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:252:plane 5B] fb: [NOFB], visible: no
<7> [611.089596] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:262:cursor B] fb: [NOFB], visible: no
<7> [611.090330] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:538:HDMI-A-3][ENCODER:537:DDI TC3/PHY H] Disable audio codec on [CRTC:268:pipe B]
<7> [611.114944] xe 0000:03:00.0: [drm:intel_hdmi_handle_sink_scrambling [xe]] [CONNECTOR:538:HDMI-A-3] scrambling=no, TMDS bit clock ratio=1/10
<7> [611.115332] xe 0000:03:00.0: [drm:do_gmbus_xfer [xe]] GMBUS [i915 gmbus tc3] NAK for addr: 0054 w(1)
<7> [611.115449] xe 0000:03:00.0: [drm:do_gmbus_xfer [xe]] GMBUS [i915 gmbus tc3] NAK on first message, retry
<7> [611.115838] xe 0000:03:00.0: [drm:do_gmbus_xfer [xe]] GMBUS [i915 gmbus tc3] NAK for addr: 0054 w(1)
<7> [611.115981] xe 0000:03:00.0: [drm:drm_scdc_set_high_tmds_clock_ratio [drm_display_helper]] [CONNECTOR:538:HDMI-A-3] Failed to read TMDS config: -6
<7> [611.116000] xe 0000:03:00.0: [drm:intel_ddi_disable [xe]] [CONNECTOR:538:HDMI-A-3] Failed to reset sink scrambling/TMDS bit clock ratio
<7> [611.116277] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe B
<7> [611.137651] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disable TC PLL 3 (active 0x2, on? 1) for [CRTC:268:pipe B]
<7> [611.139960] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disabling TC PLL 3
<7> [611.140573] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:506:DDI TC1/PHY F]
<7> [611.140945] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:508:DP-MST A]
<7> [611.141285] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST B]
<7> [611.141650] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST C]
<7> [611.141962] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST D]
<7> [611.142260] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:525:DDI TC2/PHY G]
<7> [611.142579] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:527:DP-MST A]
<7> [611.142867] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST B]
<7> [611.143151] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST C]
<7> [611.143421] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST D]
<7> [611.143725] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:537:DDI TC3/PHY H]
<7> [611.144185] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:541:DDI TC4/PHY I]
<7> [611.144426] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:543:DP-MST A]
<7> [611.144698] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST B]
<7> [611.144923] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST C]
<7> [611.145158] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST D]
<7> [611.145373] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:538:HDMI-A-3]
<7> [611.145856] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)
<7> [611.146064] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [611.146464] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [611.147010] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_B
<7> [611.147425] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xaa000000)
<7> [611.147677] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [611.148101] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:268:pipe B]
<7> [611.148478] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C]
<7> [611.149230] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:504:pipe D]
<7> [611.149412] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:386:pipe C]
<7> [611.149445] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:538:HDMI-A-3]
<7> [611.149555] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CONNECTOR:538:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 36, max requested bpp 24, max platform bpp 36)
<7> [611.149722] xe 0000:03:00.0: [drm:intel_hdmi_compute_clock [xe]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [611.149879] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:386:pipe C] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [611.150030] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:537:DDI TC3/PHY H] [CRTC:386:pipe C]
<7> [611.150180] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.enable (expected no, found yes)
<7> [611.150330] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.active (expected no, found yes)
<7> [611.150474] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)
<7> [611.150641] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in lane_count (expected 0, found 4)
<7> [611.150777] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [611.150911] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [611.151039] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [611.151166] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [611.151293] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [611.151424] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [611.151574] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [611.151706] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [611.151831] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [611.151956] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [611.152082] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1083)
<7> [611.152210] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1088)
<7> [611.152340] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [611.152469] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [611.152624] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [611.152749] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [611.152875] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [611.153004] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [611.153127] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [611.153249] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [611.153372] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [611.153500] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [611.153633] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1083)
<7> [611.153757] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1088)
<7> [611.153881] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [611.154004] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [611.154129] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [611.154260] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [611.154390] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [611.154525] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in has_hdmi_sink (expected no, found yes)
<7> [611.154656] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in has_infoframe (expected no, found yes)
<7> [611.154783] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in dpll_hw_state
<7> [611.154907] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [611.155036] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no
<7> [611.155165] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:
<7> [611.155292] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000
<7> [611.155419] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000
<7> [611.155565] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x50a8
<7> [611.155697] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x2120
<7> [611.155825] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0xcd9a
<7> [611.155950] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0xbfc1
<7> [611.156077] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x5ab8
<7> [611.156200] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x4c34
<7> [611.156324] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2000
<7> [611.156446] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0x0001
<7> [611.156592] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x6000
<7> [611.156716] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000
<7> [611.156838] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000
<7> [611.156961] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x40, hdmi rate: 0x00
<7> [611.157088] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [611.157215] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no
<7> [611.157338] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:
<7> [611.157462] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x9800, tx[2] = 0x0000
<7> [611.157614] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000
<7> [611.157739] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x409a
<7> [611.157862] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x7d20
<7> [611.157987] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0xca06
<7> [611.158110] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0xbe40
<7> [611.158232] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x0000
<7> [611.158355] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x0000
<7> [611.158478] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2200
<7> [611.158677] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0x0001
<7> [611.158801] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x5800
<7> [611.158924] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000
<7> [611.159045] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0001
<7> [611.159171] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00
<7> [611.159303] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [611.159432] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [611.159632] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [611.159803] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [611.159958] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000071)
<7> [611.160110] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in avi infoframe
<7> [611.160261] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [611.160410] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [611.160570] xe 0000:03:00.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [611.160573] xe 0000:03:00.0: colorspace: RGB
<7> [611.160575] xe 0000:03:00.0: scan mode: Underscan
<7> [611.160576] xe 0000:03:00.0: colorimetry: No Data
<7> [611.160578] xe 0000:03:00.0: picture aspect: No Data
<7> [611.160580] xe 0000:03:00.0: active aspect: Same as Picture
<7> [611.160582] xe 0000:03:00.0: itc: No Data
<7> [611.160584] xe 0000:03:00.0: extended colorimetry: xvYCC 601
<7> [611.160585] xe 0000:03:00.0: quantization range: Full
<7> [611.160587] xe 0000:03:00.0: nups: Unknown Non-uniform Scaling
<7> [611.160589] xe 0000:03:00.0: video code: 0
<7> [611.160591] xe 0000:03:00.0: ycc quantization range: Full
<7> [611.160592] xe 0000:03:00.0: hdmi content type: Graphics
<7> [611.160594] xe 0000:03:00.0: pixel repeat: 0
<7> [611.160596] xe 0000:03:00.0: bar top 0, bottom 0, left 0, right 0
<7> [611.160598] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in spd infoframe
<7> [611.160747] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [611.160896] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [611.161044] xe 0000:03:00.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [611.161046] xe 0000:03:00.0: vendor: Intel
<7> [611.161047] xe 0000:03:00.0: product: Discrete gfx
<7> [611.161049] xe 0000:03:00.0: source device information: PC General (0x9)
<7> [611.161051] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:386:pipe C] fastset requirement not met in hdmi infoframe
<7> [611.161200] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [611.161349] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [611.161505] xe 0000:03:00.0: HDMI infoframe: Vendor, version 1, length 4
<7> [611.161507] xe 0000:03:00.0: empty frame
<7> [611.161509] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:386:pipe C] fastset requirement not met, forcing full modeset
<7> [611.161690] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [611.161810] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:386:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4
<7> [611.161961] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:270:plane 1C] ddb ( 0 - 0) -> ( 0 - 1989), size 0 -> 1989
<7> [611.162076] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:380:cursor C] ddb ( 0 - 0) -> (1989 - 2048), size 0 -> 59
<7> [611.162191] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:270:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [611.162306] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:270:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 9, 9, 17, 17, 17, 17, 0, 15, 0
<7> [611.162422] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:270:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 139, 139, 261, 261, 261, 261, 137, 230, 244
<7> [611.162563] xe 0000:03:00.0: [drm:skl_print_plane_changes [xe]] [PLANE:270:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 245, 245, 367, 367, 0, 0, 138, 306, 306
<7> [611.162670] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:386:pipe C] data rate 594000 num active planes 1
<7> [611.162775] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 624 qgv_peak_bw: 48000
<7> [611.162874] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 624 qgv_peak_bw: 48000
<7> [611.162964] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 624
<7> [611.163062] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:386:pipe C] min cdclk: 0 kHz -> 192000 kHz
<7> [611.163174] xe 0000:03:00.0: [drm:intel_find_dpll [xe]] [CRTC:386:pipe C] allocated TC PLL 3
<7> [611.163263] xe 0000:03:00.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:386:pipe C] reserving TC PLL 3
<7> [611.163351] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:386:pipe C] enable: yes [modeset]
<7> [611.163441] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [611.163549] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 24, dithering: 0
<7> [611.163664] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [611.163761] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [611.163856] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [611.163950] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [611.164042] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 1, infoframes enabled: 0x71
<7> [611.164134] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] GCP: 0x0
<7> [611.164226] xe 0000:03:00.0: HDMI infoframe: Auxiliary Video Information (AVI), version 2, length 13
<7> [611.164228] xe 0000:03:00.0: colorspace: RGB
<7> [611.164229] xe 0000:03:00.0: scan mode: Underscan
<7> [611.164230] xe 0000:03:00.0: colorimetry: No Data
<7> [611.164231] xe 0000:03:00.0: picture aspect: No Data
<7> [611.164232] xe 0000:03:00.0: active aspect: Same as Picture
<7> [611.164233] xe 0000:03:00.0: itc: No Data
<7> [611.164234] xe 0000:03:00.0: extended colorimetry: xvYCC 601
<7> [611.164235] xe 0000:03:00.0: quantization range: Full
<7> [611.164236] xe 0000:03:00.0: nups: Unknown Non-uniform Scaling
<7> [611.164237] xe 0000:03:00.0: video code: 0
<7> [611.164238] xe 0000:03:00.0: ycc quantization range: Full
<7> [611.164239] xe 0000:03:00.0: hdmi content type: Graphics
<7> [611.164241] xe 0000:03:00.0: pixel repeat: 0
<7> [611.164242] xe 0000:03:00.0: bar top 0, bottom 0, left 0, right 0
<7> [611.164243] xe 0000:03:00.0: HDMI infoframe: Source Product Description (SPD), version 1, length 25
<7> [611.164244] xe 0000:03:00.0: vendor: Intel
<7> [611.164246] xe 0000:03:00.0: product: Discrete gfx
<7> [611.164247] xe 0000:03:00.0: source device information: PC General (0x9)
<7> [611.164248] xe 0000:03:00.0: HDMI infoframe: Vendor, version 1, length 4
<7> [611.164249] xe 0000:03:00.0: empty frame
<7> [611.164250] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 08 00 6d 10 00 01 00 00 00 00 00 00 00 00
<7> [611.164342] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 24 96 11 ed 41 4f 43 32 38 45 38 35 30 2e 48 44
<7> [611.164432] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 52 09 07 07
<7> [611.164537] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [611.164648] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [611.164739] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 42, vsync end: 37
<7> [611.164831] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125
<7> [611.164921] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [611.165013] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9
<7> [611.165107] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x48 0x9
<7> [611.165201] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9
<7> [611.165296] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1083 1088 1125 0x40 0x9
<7> [611.165389] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1083-1088 vt=1125, flags=0x9
<7> [611.165481] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 148500, pipe src: 1920x1080+0+0, pixel rate 148500, min cdclk 192000
<7> [611.165593] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0
<7> [611.165700] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [611.165800] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [611.165899] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [611.165995] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no
<7> [611.166090] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] c20pll_hw_state:
<7> [611.166183] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] tx[0] = 0xbe88, tx[1] = 0x9800, tx[2] = 0x0000
<7> [611.166274] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000
<7> [611.166366] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[0] = 0x409a
<7> [611.166456] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[1] = 0x7d20
<7> [611.166495] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [611.166562] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[2] = 0xca06
<7> [611.166665] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[3] = 0xbe40
<7> [611.166757] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[4] = 0x0000
<7> [611.166829] xe 0000:03:00.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [611.166847] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[5] = 0x0000
<7> [611.166932] xe 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [611.166938] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[6] = 0x2200
<7> [611.167027] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[7] = 0x0001
<7> [611.167048] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling always-on
<7> [611.167118] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[8] = 0x5800
<7> [611.167214] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[9] = 0x0000
<7> [611.167306] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[10] = 0x0001
<7> [611.167399] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00
<7> [611.167502] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [611.167604] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [611.167695] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [611.167789] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [611.167880] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [611.167971] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [611.168063] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [611.168154] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [611.168245] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [611.168335] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [611.168426] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [611.168526] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [611.168628] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [611.168719] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:270:plane 1C] fb: [FB:555] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [611.168811] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [611.168902] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [611.168997] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:300:plane 2C] fb: [NOFB], visible: no
<7> [611.169091] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:330:plane 3C] fb: [NOFB], visible: no
<7> [611.169183] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:360:plane 4C] fb: [NOFB], visible: no
<7> [611.169275] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:370:plane 5C] fb: [NOFB], visible: no
<7> [611.169365] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:380:cursor C] fb: [NOFB], visible: no
<7> [611.170038] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling always-on
<7> [611.170162] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [611.170408] xe 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [611.170553] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [611.170704] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_C
<7> [611.170850] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000)
<7> [611.170965] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:506:DDI TC1/PHY F]
<7> [611.171065] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:508:DP-MST A]
<7> [611.171161] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST B]
<7> [611.171259] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST C]
<7> [611.171354] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST D]
<7> [611.171445] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:525:DDI TC2/PHY G]
<7> [611.171543] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:527:DP-MST A]
<7> [611.171633] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST B]
<7> [611.171726] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST C]
<7> [611.171820] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST D]
<7> [611.171910] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:537:DDI TC3/PHY H]
<7> [611.172000] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:541:DDI TC4/PHY I]
<7> [611.172089] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:543:DP-MST A]
<7> [611.172182] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST B]
<7> [611.172275] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST C]
<7> [611.172367] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST D]
<7> [611.172466] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd
<7> [611.172646] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)
<7> [611.172749] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enable TC PLL 3 (active 0x4, on? 0) for [CRTC:386:pipe C]
<7> [611.172854] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enabling TC PLL 3
<7> [611.175352] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe C
<7> [611.176550] xe 0000:03:00.0: [drm:intel_hdmi_handle_sink_scrambling [xe]] [CONNECTOR:538:HDMI-A-3] scrambling=no, TMDS bit clock ratio=1/10
<7> [611.176888] xe 0000:03:00.0: [drm:do_gmbus_xfer [xe]] GMBUS [i915 gmbus tc3] NAK for addr: 0054 w(1)
<7> [611.176985] xe 0000:03:00.0: [drm:do_gmbus_xfer [xe]] GMBUS [i915 gmbus tc3] NAK on first message, retry
<7> [611.177322] xe 0000:03:00.0: [drm:do_gmbus_xfer [xe]] GMBUS [i915 gmbus tc3] NAK for addr: 0054 w(1)
<7> [611.177417] xe 0000:03:00.0: [drm:drm_scdc_set_high_tmds_clock_ratio [drm_display_helper]] [CONNECTOR:538:HDMI-A-3] Failed to read TMDS config: -6
<7> [611.177430] xe 0000:03:00.0: [drm:intel_ddi_enable [xe]] [CONNECTOR:538:HDMI-A-3] Failed to configure sink scrambling/TMDS bit clock ratio
<7> [611.195050] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:538:HDMI-A-3][ENCODER:537:DDI TC3/PHY H] Enable audio codec on [CRTC:386:pipe C], 36 bytes ELD
<7> [611.211668] xe 0000:03:00.0: [drm:audio_config_hdmi_pixel_clock [xe]] Configuring HDMI audio for pixel clock 148500 (0x00090000)
<7> [611.211813] xe 0000:03:00.0: [drm:hsw_audio_config_update [xe]] using automatic N
<7> [611.212315] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:538:HDMI-A-3]
<7> [611.212713] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:386:pipe C]
<6> [612.906047] [IGT] kms_flip: finished subtest C-HDMI-A3, FAIL
Created at 2026-03-08 04:06:25