Results for igt@kms_flip@plain-flip-ts-check@a-dp3

Machine description: shard-dg2-11

Result: Fail

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

DetailValue
Duration 11.23 seconds
Hostname 
shard-dg2-11
Igt-Version 
IGT-Version: 1.30-ga12df61e7 (x86_64) (Linux: 6.14.0-rc4-CI_DRM_16207-gf79125df2181+ x86_64)
Out 
Using IGT_SRANDOM=1740828404 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-DP3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Expected frametime: 16667us; measured 16554.4us +- 5.253us accuracy 0.10%
vblank interval differs from modeline! expected 16666.7us, measured 16554us +- 5.253us, difference 112.2us (21.4 sigma)
Stack trace:
  #0 ../lib/igt_core.c:2055 __igt_fail_assert()
  #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1845 run_test()
  #3 ../tests/kms_flip.c:2078 __igt_unique____real_main2001()
  #4 ../tests/kms_flip.c:2001 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-DP3: FAIL (11.233s)
Err 
Starting subtest: plain-flip-ts-check
Starting dynamic subtest: A-DP3
(kms_flip:1994) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:1994) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
Dynamic subtest A-DP3 failed.
**** DEBUG ****
(kms_flip:1994) DEBUG: flip ts/seq: last 66.071472/929, current 66.088089/930: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.088089
last_received_ts = 66.087723
last_seq = 930
current_ts = 66.104706
current_received_ts = 66.104424
current_seq = 931
count = 322
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.088089/930, current 66.104706/931: elapsed=16614.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.104706
last_received_ts = 66.104424
last_seq = 931
current_ts = 66.121323
current_received_ts = 66.120949
current_seq = 932
count = 323
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.104706/931, current 66.121323/932: elapsed=16621.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.121323
last_received_ts = 66.120949
last_seq = 932
current_ts = 66.137939
current_received_ts = 66.137566
current_seq = 933
count = 324
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.121323/932, current 66.137939/933: elapsed=16615.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.137939
last_received_ts = 66.137566
last_seq = 933
current_ts = 66.154556
current_received_ts = 66.154167
current_seq = 934
count = 325
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.137939/933, current 66.154556/934: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.154556
last_received_ts = 66.154167
last_seq = 934
current_ts = 66.171165
current_received_ts = 66.170769
current_seq = 935
count = 326
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.154556/934, current 66.171165/935: elapsed=16611.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.171165
last_received_ts = 66.170769
last_seq = 935
current_ts = 66.187782
current_received_ts = 66.187393
current_seq = 936
count = 327
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.171165/935, current 66.187782/936: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.187782
last_received_ts = 66.187393
last_seq = 936
current_ts = 66.204407
current_received_ts = 66.204071
current_seq = 937
count = 328
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.187782/936, current 66.204407/937: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.204407
last_received_ts = 66.204071
last_seq = 937
current_ts = 66.221024
current_received_ts = 66.220650
current_seq = 938
count = 329
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.204407/937, current 66.221024/938: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.221024
last_received_ts = 66.220650
last_seq = 938
current_ts = 66.237640
current_received_ts = 66.237297
current_seq = 939
count = 330
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.221024/938, current 66.237640/939: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.237640
last_received_ts = 66.237297
last_seq = 939
current_ts = 66.254257
current_received_ts = 66.253960
current_seq = 940
count = 331
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.237640/939, current 66.254257/940: elapsed=16619.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.254257
last_received_ts = 66.253960
last_seq = 940
current_ts = 66.270874
current_received_ts = 66.270454
current_seq = 941
count = 332
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.254257/940, current 66.270874/941: elapsed=16611.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.270874
last_received_ts = 66.270454
last_seq = 941
current_ts = 66.287491
current_received_ts = 66.287125
current_seq = 942
count = 333
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.270874/941, current 66.287491/942: elapsed=16620.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.287491
last_received_ts = 66.287125
last_seq = 942
current_ts = 66.304108
current_received_ts = 66.303810
current_seq = 943
count = 334
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.287491/942, current 66.304108/943: elapsed=16615.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.304108
last_received_ts = 66.303810
last_seq = 943
current_ts = 66.320724
current_received_ts = 66.320320
current_seq = 944
count = 335
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.304108/943, current 66.320724/944: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.320724
last_received_ts = 66.320320
last_seq = 944
current_ts = 66.337341
current_received_ts = 66.336975
current_seq = 945
count = 336
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.320724/944, current 66.337341/945: elapsed=16619.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.337341
last_received_ts = 66.336975
last_seq = 945
current_ts = 66.353951
current_received_ts = 66.353645
current_seq = 946
count = 337
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.337341/945, current 66.353951/946: elapsed=16613.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.353951
last_received_ts = 66.353645
last_seq = 946
current_ts = 66.370575
current_received_ts = 66.370308
current_seq = 947
count = 338
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.353951/946, current 66.370575/947: elapsed=16621.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.370575
last_received_ts = 66.370308
last_seq = 947
current_ts = 66.387192
current_received_ts = 66.386803
current_seq = 948
count = 339
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.370575/947, current 66.387192/948: elapsed=16617.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.387192
last_received_ts = 66.386803
last_seq = 948
current_ts = 66.403809
current_received_ts = 66.403389
current_seq = 949
count = 340
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.387192/948, current 66.403809/949: elapsed=16613.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.403809
last_received_ts = 66.403389
last_seq = 949
current_ts = 66.420425
current_received_ts = 66.420074
current_seq = 950
count = 341
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.403809/949, current 66.420425/950: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.420425
last_received_ts = 66.420074
last_seq = 950
current_ts = 66.437035
current_received_ts = 66.436745
current_seq = 951
count = 342
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.420425/950, current 66.437035/951: elapsed=16612.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.437035
last_received_ts = 66.436745
last_seq = 951
current_ts = 66.453659
current_received_ts = 66.453308
current_seq = 952
count = 343
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.437035/951, current 66.453659/952: elapsed=16624.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.453659
last_received_ts = 66.453308
last_seq = 952
current_ts = 66.470276
current_received_ts = 66.469894
current_seq = 953
count = 344
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.453659/952, current 66.470276/953: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.470276
last_received_ts = 66.469894
last_seq = 953
current_ts = 66.486893
current_received_ts = 66.486435
current_seq = 954
count = 345
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.470276/953, current 66.486893/954: elapsed=16620.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.486893
last_received_ts = 66.486435
last_seq = 954
current_ts = 66.503510
current_received_ts = 66.503189
current_seq = 955
count = 346
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.486893/954, current 66.503510/955: elapsed=16611.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.503510
last_received_ts = 66.503189
last_seq = 955
current_ts = 66.520126
current_received_ts = 66.519737
current_seq = 956
count = 347
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.503510/955, current 66.520126/956: elapsed=16620.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.520126
last_received_ts = 66.519737
last_seq = 956
current_ts = 66.536736
current_received_ts = 66.536385
current_seq = 957
count = 348
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.520126/956, current 66.536736/957: elapsed=16611.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.536736
last_received_ts = 66.536385
last_seq = 957
current_ts = 66.553360
current_received_ts = 66.552979
current_seq = 958
count = 349
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.536736/957, current 66.553360/958: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.553360
last_received_ts = 66.552979
last_seq = 958
current_ts = 66.569977
current_received_ts = 66.569656
current_seq = 959
count = 350
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.553360/958, current 66.569977/959: elapsed=16614.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.569977
last_received_ts = 66.569656
last_seq = 959
current_ts = 66.586594
current_received_ts = 66.586205
current_seq = 960
count = 351
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.569977/959, current 66.586594/960: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.586594
last_received_ts = 66.586205
last_seq = 960
current_ts = 66.603210
current_received_ts = 66.602913
current_seq = 961
count = 352
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.586594/960, current 66.603210/961: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.603210
last_received_ts = 66.602913
last_seq = 961
current_ts = 66.619820
current_received_ts = 66.619415
current_seq = 962
count = 353
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.603210/961, current 66.619820/962: elapsed=16608.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.619820
last_received_ts = 66.619415
last_seq = 962
current_ts = 66.636444
current_received_ts = 66.636169
current_seq = 963
count = 354
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.619820/962, current 66.636444/963: elapsed=16621.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.636444
last_received_ts = 66.636169
last_seq = 963
current_ts = 66.653053
current_received_ts = 66.652748
current_seq = 964
count = 355
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.636444/963, current 66.653053/964: elapsed=16612.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.653053
last_received_ts = 66.652748
last_seq = 964
current_ts = 66.669678
current_received_ts = 66.669273
current_seq = 965
count = 356
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.653053/964, current 66.669678/965: elapsed=16621.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.669678
last_received_ts = 66.669273
last_seq = 965
current_ts = 66.686295
current_received_ts = 66.685707
current_seq = 966
count = 357
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.669678/965, current 66.686295/966: elapsed=16621.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.686295
last_received_ts = 66.685707
last_seq = 966
current_ts = 66.702911
current_received_ts = 66.702339
current_seq = 967
count = 358
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.686295/966, current 66.702911/967: elapsed=16619.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.702911
last_received_ts = 66.702339
last_seq = 967
current_ts = 66.719528
current_received_ts = 66.718956
current_seq = 968
count = 359
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.702911/967, current 66.719528/968: elapsed=16617.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.719528
last_received_ts = 66.718956
last_seq = 968
current_ts = 66.736153
current_received_ts = 66.735596
current_seq = 969
count = 360
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.719528/968, current 66.736153/969: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.736153
last_received_ts = 66.735596
last_seq = 969
current_ts = 66.752762
current_received_ts = 66.752174
current_seq = 970
count = 361
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.736153/969, current 66.752762/970: elapsed=16613.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.752762
last_received_ts = 66.752174
last_seq = 970
current_ts = 66.769371
current_received_ts = 66.768845
current_seq = 971
count = 362
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.752762/970, current 66.769371/971: elapsed=16608.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.769371
last_received_ts = 66.768845
last_seq = 971
current_ts = 66.785995
current_received_ts = 66.785408
current_seq = 972
count = 363
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.769371/971, current 66.785995/972: elapsed=16625.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.785995
last_received_ts = 66.785408
last_seq = 972
current_ts = 66.802612
current_received_ts = 66.802025
current_seq = 973
count = 364
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.785995/972, current 66.802612/973: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.802612
last_received_ts = 66.802025
last_seq = 973
current_ts = 66.819229
current_received_ts = 66.818634
current_seq = 974
count = 365
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.802612/973, current 66.819229/974: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.819229
last_received_ts = 66.818634
last_seq = 974
current_ts = 66.835846
current_received_ts = 66.835258
current_seq = 975
count = 366
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.819229/974, current 66.835846/975: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.835846
last_received_ts = 66.835258
last_seq = 975
current_ts = 66.852463
current_received_ts = 66.851875
current_seq = 976
count = 367
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.835846/975, current 66.852463/976: elapsed=16617.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.852463
last_received_ts = 66.851875
last_seq = 976
current_ts = 66.869080
current_received_ts = 66.868523
current_seq = 977
count = 368
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.852463/976, current 66.869080/977: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.869080
last_received_ts = 66.868523
last_seq = 977
current_ts = 66.885696
current_received_ts = 66.885109
current_seq = 978
count = 369
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.869080/977, current 66.885696/978: elapsed=16617.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.885696
last_received_ts = 66.885109
last_seq = 978
current_ts = 66.902313
current_received_ts = 66.901733
current_seq = 979
count = 370
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.885696/978, current 66.902313/979: elapsed=16620.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.902313
last_received_ts = 66.901733
last_seq = 979
current_ts = 66.918922
current_received_ts = 66.918350
current_seq = 980
count = 371
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.902313/979, current 66.918922/980: elapsed=16604.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.918922
last_received_ts = 66.918350
last_seq = 980
current_ts = 66.935547
current_received_ts = 66.934967
current_seq = 981
count = 372
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.918922/980, current 66.935547/981: elapsed=16630.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.935547
last_received_ts = 66.934967
last_seq = 981
current_ts = 66.952164
current_received_ts = 66.951607
current_seq = 982
count = 373
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.935547/981, current 66.952164/982: elapsed=16611.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.952164
last_received_ts = 66.951607
last_seq = 982
current_ts = 66.968773
current_received_ts = 66.968216
current_seq = 983
count = 374
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.952164/982, current 66.968773/983: elapsed=16613.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.968773
last_received_ts = 66.968216
last_seq = 983
current_ts = 66.985390
current_received_ts = 66.984825
current_seq = 984
count = 375
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.968773/983, current 66.985390/984: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 66.985390
last_received_ts = 66.984825
last_seq = 984
current_ts = 67.002007
current_received_ts = 67.001442
current_seq = 985
count = 376
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 66.985390/984, current 67.002007/985: elapsed=16615.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.002007
last_received_ts = 67.001442
last_seq = 985
current_ts = 67.018631
current_received_ts = 67.018059
current_seq = 986
count = 377
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.002007/985, current 67.018631/986: elapsed=16626.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.018631
last_received_ts = 67.018059
last_seq = 986
current_ts = 67.035248
current_received_ts = 67.034668
current_seq = 987
count = 378
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.018631/986, current 67.035248/987: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.035248
last_received_ts = 67.034668
last_seq = 987
current_ts = 67.051872
current_received_ts = 67.051285
current_seq = 988
count = 379
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.035248/987, current 67.051872/988: elapsed=16621.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.051872
last_received_ts = 67.051285
last_seq = 988
current_ts = 67.068497
current_received_ts = 67.067909
current_seq = 989
count = 380
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.051872/988, current 67.068497/989: elapsed=16624.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.068497
last_received_ts = 67.067909
last_seq = 989
current_ts = 67.085114
current_received_ts = 67.084549
current_seq = 990
count = 381
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.068497/989, current 67.085114/990: elapsed=16619.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.085114
last_received_ts = 67.084549
last_seq = 990
current_ts = 67.101738
current_received_ts = 67.101151
current_seq = 991
count = 382
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.085114/990, current 67.101738/991: elapsed=16626.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.101738
last_received_ts = 67.101151
last_seq = 991
current_ts = 67.118370
current_received_ts = 67.117775
current_seq = 992
count = 383
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.101738/991, current 67.118370/992: elapsed=16628.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.118370
last_received_ts = 67.117775
last_seq = 992
current_ts = 67.134979
current_received_ts = 67.134415
current_seq = 993
count = 384
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.118370/992, current 67.134979/993: elapsed=16610.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.134979
last_received_ts = 67.134415
last_seq = 993
current_ts = 67.151611
current_received_ts = 67.151062
current_seq = 994
count = 385
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.134979/993, current 67.151611/994: elapsed=16630.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.151611
last_received_ts = 67.151062
last_seq = 994
current_ts = 67.168236
current_received_ts = 67.167656
current_seq = 995
count = 386
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.151611/994, current 67.168236/995: elapsed=16626.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.168236
last_received_ts = 67.167656
last_seq = 995
current_ts = 67.184860
current_received_ts = 67.184280
current_seq = 996
count = 387
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.168236/995, current 67.184860/996: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.184860
last_received_ts = 67.184280
last_seq = 996
current_ts = 67.201477
current_received_ts = 67.200897
current_seq = 997
count = 388
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.184860/996, current 67.201477/997: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.201477
last_received_ts = 67.200897
last_seq = 997
current_ts = 67.218109
current_received_ts = 67.217529
current_seq = 998
count = 389
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.201477/997, current 67.218109/998: elapsed=16626.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.218109
last_received_ts = 67.217529
last_seq = 998
current_ts = 67.234726
current_received_ts = 67.234146
current_seq = 999
count = 390
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.218109/998, current 67.234726/999: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.234726
last_received_ts = 67.234146
last_seq = 999
current_ts = 67.251350
current_received_ts = 67.250771
current_seq = 1000
count = 391
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.234726/999, current 67.251350/1000: elapsed=16621.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.251350
last_received_ts = 67.250771
last_seq = 1000
current_ts = 67.267975
current_received_ts = 67.267395
current_seq = 1001
count = 392
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.251350/1000, current 67.267975/1001: elapsed=16624.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.267975
last_received_ts = 67.267395
last_seq = 1001
current_ts = 67.284599
current_received_ts = 67.284019
current_seq = 1002
count = 393
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.267975/1001, current 67.284599/1002: elapsed=16626.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.284599
last_received_ts = 67.284019
last_seq = 1002
current_ts = 67.301224
current_received_ts = 67.300644
current_seq = 1003
count = 394
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.284599/1002, current 67.301224/1003: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.301224
last_received_ts = 67.300644
last_seq = 1003
current_ts = 67.317841
current_received_ts = 67.317261
current_seq = 1004
count = 395
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.301224/1003, current 67.317841/1004: elapsed=16620.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.317841
last_received_ts = 67.317261
last_seq = 1004
current_ts = 67.334465
current_received_ts = 67.333893
current_seq = 1005
count = 396
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.317841/1004, current 67.334465/1005: elapsed=16627.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.334465
last_received_ts = 67.333893
last_seq = 1005
current_ts = 67.351074
current_received_ts = 67.350517
current_seq = 1006
count = 397
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.334465/1005, current 67.351074/1006: elapsed=16610.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.351074
last_received_ts = 67.350517
last_seq = 1006
current_ts = 67.367714
current_received_ts = 67.367134
current_seq = 1007
count = 398
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.351074/1006, current 67.367714/1007: elapsed=16634.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.367714
last_received_ts = 67.367134
last_seq = 1007
current_ts = 67.384323
current_received_ts = 67.383766
current_seq = 1008
count = 399
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.367714/1007, current 67.384323/1008: elapsed=16612.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.384323
last_received_ts = 67.383766
last_seq = 1008
current_ts = 67.400948
current_received_ts = 67.400391
current_seq = 1009
count = 400
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.384323/1008, current 67.400948/1009: elapsed=16626.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.400948
last_received_ts = 67.400391
last_seq = 1009
current_ts = 67.417580
current_received_ts = 67.416992
current_seq = 1010
count = 401
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.400948/1009, current 67.417580/1010: elapsed=16632.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.417580
last_received_ts = 67.416992
last_seq = 1010
current_ts = 67.434204
current_received_ts = 67.433624
current_seq = 1011
count = 402
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.417580/1010, current 67.434204/1011: elapsed=16624.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.434204
last_received_ts = 67.433624
last_seq = 1011
current_ts = 67.450813
current_received_ts = 67.450249
current_seq = 1012
count = 403
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.434204/1011, current 67.450813/1012: elapsed=16610.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.450813
last_received_ts = 67.450249
last_seq = 1012
current_ts = 67.467445
current_received_ts = 67.466866
current_seq = 1013
count = 404
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.450813/1012, current 67.467445/1013: elapsed=16632.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.467445
last_received_ts = 67.466866
last_seq = 1013
current_ts = 67.484077
current_received_ts = 67.483498
current_seq = 1014
count = 405
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.467445/1013, current 67.484077/1014: elapsed=16626.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.484077
last_received_ts = 67.483498
last_seq = 1014
current_ts = 67.500687
current_received_ts = 67.500122
current_seq = 1015
count = 406
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.484077/1014, current 67.500687/1015: elapsed=16611.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.500687
last_received_ts = 67.500122
last_seq = 1015
current_ts = 67.517319
current_received_ts = 67.516747
current_seq = 1016
count = 407
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.500687/1015, current 67.517319/1016: elapsed=16635.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.517319
last_received_ts = 67.516747
last_seq = 1016
current_ts = 67.533943
current_received_ts = 67.533371
current_seq = 1017
count = 408
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.517319/1016, current 67.533943/1017: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.533943
last_received_ts = 67.533371
last_seq = 1017
current_ts = 67.550568
current_received_ts = 67.549988
current_seq = 1018
count = 409
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.533943/1017, current 67.550568/1018: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.550568
last_received_ts = 67.549988
last_seq = 1018
current_ts = 67.567192
current_received_ts = 67.566612
current_seq = 1019
count = 410
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.550568/1018, current 67.567192/1019: elapsed=16624.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.567192
last_received_ts = 67.566612
last_seq = 1019
current_ts = 67.583809
current_received_ts = 67.583237
current_seq = 1020
count = 411
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.567192/1019, current 67.583809/1020: elapsed=16620.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.583809
last_received_ts = 67.583237
last_seq = 1020
current_ts = 67.600433
current_received_ts = 67.599846
current_seq = 1021
count = 412
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.583809/1020, current 67.600433/1021: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.600433
last_received_ts = 67.599846
last_seq = 1021
current_ts = 67.617058
current_received_ts = 67.616486
current_seq = 1022
count = 413
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.600433/1021, current 67.617058/1022: elapsed=16625.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.617058
last_received_ts = 67.616486
last_seq = 1022
current_ts = 67.633682
current_received_ts = 67.633072
current_seq = 1023
count = 414
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.617058/1022, current 67.633682/1023: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.633682
last_received_ts = 67.633072
last_seq = 1023
current_ts = 67.650307
current_received_ts = 67.649727
current_seq = 1024
count = 415
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.633682/1023, current 67.650307/1024: elapsed=16624.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.650307
last_received_ts = 67.649727
last_seq = 1024
current_ts = 67.666924
current_received_ts = 67.666351
current_seq = 1025
count = 416
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.650307/1024, current 67.666924/1025: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.666924
last_received_ts = 67.666351
last_seq = 1025
current_ts = 67.683540
current_received_ts = 67.682983
current_seq = 1026
count = 417
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.666924/1025, current 67.683540/1026: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.683540
last_received_ts = 67.682983
last_seq = 1026
current_ts = 67.700172
current_received_ts = 67.699593
current_seq = 1027
count = 418
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.683540/1026, current 67.700172/1027: elapsed=16629.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.700172
last_received_ts = 67.699593
last_seq = 1027
current_ts = 67.716797
current_received_ts = 67.716217
current_seq = 1028
count = 419
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.700172/1027, current 67.716797/1028: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.716797
last_received_ts = 67.716217
last_seq = 1028
current_ts = 67.733414
current_received_ts = 67.732834
current_seq = 1029
count = 420
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.716797/1028, current 67.733414/1029: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.733414
last_received_ts = 67.732834
last_seq = 1029
current_ts = 67.750038
current_received_ts = 67.749451
current_seq = 1030
count = 421
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.733414/1029, current 67.750038/1030: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.750038
last_received_ts = 67.749451
last_seq = 1030
current_ts = 67.766663
current_received_ts = 67.766052
current_seq = 1031
count = 422
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.750038/1030, current 67.766663/1031: elapsed=16624.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.766663
last_received_ts = 67.766052
last_seq = 1031
current_ts = 67.783287
current_received_ts = 67.782707
current_seq = 1032
count = 423
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.766663/1031, current 67.783287/1032: elapsed=16625.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.783287
last_received_ts = 67.782707
last_seq = 1032
current_ts = 67.799911
current_received_ts = 67.799332
current_seq = 1033
count = 424
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.783287/1032, current 67.799911/1033: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.799911
last_received_ts = 67.799332
last_seq = 1033
current_ts = 67.816536
current_received_ts = 67.815964
current_seq = 1034
count = 425
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.799911/1033, current 67.816536/1034: elapsed=16623.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.816536
last_received_ts = 67.815964
last_seq = 1034
current_ts = 67.833153
current_received_ts = 67.832741
current_seq = 1035
count = 426
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.816536/1034, current 67.833153/1035: elapsed=16619.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.833153
last_received_ts = 67.832741
last_seq = 1035
current_ts = 67.849770
current_received_ts = 67.849258
current_seq = 1036
count = 427
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.833153/1035, current 67.849770/1036: elapsed=16615.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.849770
last_received_ts = 67.849258
last_seq = 1036
current_ts = 67.866402
current_received_ts = 67.865982
current_seq = 1037
count = 428
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.849770/1036, current 67.866402/1037: elapsed=16633.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.866402
last_received_ts = 67.865982
last_seq = 1037
current_ts = 67.883018
current_received_ts = 67.882591
current_seq = 1038
count = 429
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.866402/1037, current 67.883018/1038: elapsed=16619.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.883018
last_received_ts = 67.882591
last_seq = 1038
current_ts = 67.899651
current_received_ts = 67.899315
current_seq = 1039
count = 430
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.883018/1038, current 67.899651/1039: elapsed=16628.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.899651
last_received_ts = 67.899315
last_seq = 1039
current_ts = 67.916260
current_received_ts = 67.915848
current_seq = 1040
count = 431
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.899651/1039, current 67.916260/1040: elapsed=16616.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.916260
last_received_ts = 67.915848
last_seq = 1040
current_ts = 67.932899
current_received_ts = 67.932549
current_seq = 1041
count = 432
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.916260/1040, current 67.932899/1041: elapsed=16634.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.932899
last_received_ts = 67.932549
last_seq = 1041
current_ts = 67.949509
current_received_ts = 67.949142
current_seq = 1042
count = 433
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.932899/1041, current 67.949509/1042: elapsed=16609.0us expected=16554.4us +- 82.8us, error 0.3%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.949509
last_received_ts = 67.949142
last_seq = 1042
current_ts = 67.966141
current_received_ts = 67.965645
current_seq = 1043
count = 434
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.949509/1042, current 67.966141/1043: elapsed=16634.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.966141
last_received_ts = 67.965645
last_seq = 1043
current_ts = 67.982758
current_received_ts = 67.982300
current_seq = 1044
count = 435
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.966141/1043, current 67.982758/1044: elapsed=16618.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.982758
last_received_ts = 67.982300
last_seq = 1044
current_ts = 67.999382
current_received_ts = 67.999115
current_seq = 1045
count = 436
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.982758/1044, current 67.999382/1045: elapsed=16627.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 67.999382
last_received_ts = 67.999115
last_seq = 1045
current_ts = 68.015999
current_received_ts = 68.015625
current_seq = 1046
count = 437
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 67.999382/1045, current 68.015999/1046: elapsed=16614.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 68.015999
last_received_ts = 68.015625
last_seq = 1046
current_ts = 68.032631
current_received_ts = 68.032379
current_seq = 1047
count = 438
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 68.015999/1046, current 68.032631/1047: elapsed=16631.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: name = flip
last_ts = 68.032631
last_received_ts = 68.032379
last_seq = 1047
current_ts = 68.049255
current_received_ts = 68.048874
current_seq = 1048
count = 439
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 68.032631/1047, current 68.049255/1048: elapsed=16622.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 68.049255
last_received_ts = 68.048874
last_seq = 1048
current_ts = 68.065880
current_received_ts = 68.065445
current_seq = 1049
count = 440
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 68.049255/1048, current 68.065880/1049: elapsed=16628.0us expected=16554.4us +- 82.8us, error 0.4%
(kms_flip:1994) DEBUG: name = flip
last_ts = 68.065880
last_received_ts = 68.065445
last_seq = 1049
current_ts = 68.082520
current_received_ts = 68.082230
current_seq = 1050
count = 441
seq_step = 1
(kms_flip:1994) DEBUG: flip ts/seq: last 68.065880/1049, current 68.082520/1050: elapsed=16642.0us expected=16554.4us +- 82.8us, error 0.5%
(kms_flip:1994) DEBUG: inconsistent flip ts/seq: last 68.065880/1049, current 68.082520/1050: elapsed=16642.0us expected=16554.4us
(kms_flip:1994) DEBUG: expected 0, counted 441, encoder type 2
(kms_flip:1994) DEBUG: dropped frames, expected 0, counted 441, encoder type 2
(kms_flip:1994) CRITICAL: Test assertion failure function __run_test_on_crtc_set, file ../tests/kms_flip.c:1674:
(kms_flip:1994) CRITICAL: Failed assertion: !retried && needs_retry_after_link_reset(mon)
(kms_flip:1994) igt_core-INFO: Stack trace:
(kms_flip:1994) igt_core-INFO:   #0 ../lib/igt_core.c:2055 __igt_fail_assert()
(kms_flip:1994) igt_core-INFO:   #1 ../tests/kms_flip.c:791 run_test_on_crtc_set.constprop.0()
(kms_flip:1994) igt_core-INFO:   #2 ../tests/kms_flip.c:1845 run_test()
(kms_flip:1994) igt_core-INFO:   #3 ../tests/kms_flip.c:2078 __igt_unique____real_main2001()
(kms_flip:1994) igt_core-INFO:   #4 ../tests/kms_flip.c:2001 main()
(kms_flip:1994) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:1994) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:1994) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-DP3: FAIL (11.233s)
Dmesg
<6> [60.344560] Console: switching to colour dummy device 80x25
<6> [60.345021] [IGT] kms_flip: executing
<7> [60.356759] i915 0000:03:00.0: [drm:i915_gem_open [i915]]
<7> [60.358156] i915 0000:03:00.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x000001dc [0x000001dc]
<7> [60.370271] i915 0000:03:00.0: [drm:i915_gem_open [i915]]
<7> [60.377252] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:241:DP-1]
<7> [60.377270] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:241:DP-1]
<7> [60.381943] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:241:DP-1] disconnected
<7> [60.382300] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:254:DP-2]
<7> [60.382313] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:254:DP-2]
<7> [60.387004] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:254:DP-2] disconnected
<7> [60.387355] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:263:HDMI-A-1]
<7> [60.387368] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:263:HDMI-A-1]
<7> [60.392046] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:263:HDMI-A-1] disconnected
<7> [60.392582] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:277:HDMI-A-2]
<7> [60.392595] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:277:HDMI-A-2]
<7> [60.392954] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpc] NAK for addr: 0050 w(1)
<7> [60.393146] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpc] NAK on first message, retry
<7> [60.393470] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpc] NAK for addr: 0050 w(1)
<7> [60.393627] [drm:drm_do_probe_ddc_edid] drm: skipping non-existent adapter i915 gmbus dpc
<7> [60.393632] i915 0000:03:00.0: [drm:intel_hdmi_set_edid [i915]] HDMI GMBUS EDID read failed, retry using GPIO bit-banging
<7> [60.393783] i915 0000:03:00.0: [drm:intel_gmbus_force_bit [i915]] enabling bit-banging on i915 gmbus dpc. force bit now 1
<7> [60.395703] [drm:drm_do_probe_ddc_edid] drm: skipping non-existent adapter i915 gmbus dpc
<7> [60.395707] i915 0000:03:00.0: [drm:intel_gmbus_force_bit [i915]] disabling bit-banging on i915 gmbus dpc. force bit now 0
<7> [60.395871] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:277:HDMI-A-2] disconnected
<7> [60.396277] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:281:DP-4]
<7> [60.396290] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:281:DP-4]
<7> [60.401103] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:281:DP-4] disconnected
<7> [60.401456] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:289:HDMI-A-3]
<7> [60.401468] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:289:HDMI-A-3]
<7> [60.406110] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:289:HDMI-A-3] disconnected
<7> [60.406570] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:241:DP-1]
<7> [60.406582] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:241:DP-1]
<7> [60.411181] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:241:DP-1] disconnected
<7> [60.411204] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:254:DP-2]
<7> [60.411215] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:254:DP-2]
<7> [60.416214] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:254:DP-2] disconnected
<7> [60.416236] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:263:HDMI-A-1]
<7> [60.416248] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:263:HDMI-A-1]
<7> [60.421247] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:263:HDMI-A-1] disconnected
<7> [60.421270] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:269:DP-3]
<7> [60.421282] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:269:DP-3]
<7> [60.423149] i915 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX C/DDI C/PHY C: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [60.430413] i915 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00
<7> [60.431758] i915 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX C/DDI C/PHY C: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [60.432982] i915 0000:03:00.0: [drm:drm_dp_dump_desc [drm_display_helper]] AUX C/DDI C/PHY C: DP branch: OUI 00-1c-f8 dev-ID 176GB0 HW-rev 1.0 SW-rev 7.85 quirks 0x0000
<7> [60.435840] i915 0000:03:00.0: [drm:drm_dp_read_downstream_info [drm_display_helper]] AUX C/DDI C/PHY C: DPCD DFP: 0b f0 02 11
<7> [60.436702] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [ENCODER:268:DDI C/PHY C] MST support: port: yes, sink: SST, modparam: yes -> enable: SST
<7> [60.443795] i915 0000:03:00.0: [drm:intel_dp_print_rates [i915]] source rates: 162000, 216000, 270000, 324000, 432000, 540000, 648000, 810000, 1000000, 1350000
<7> [60.443966] i915 0000:03:00.0: [drm:intel_dp_print_rates [i915]] sink rates: 162000, 270000, 540000
<7> [60.444121] i915 0000:03:00.0: [drm:intel_dp_print_rates [i915]] common rates: 162000, 270000, 540000
<7> [60.450815] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.452881] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.454700] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.456591] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.458428] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.460224] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.462066] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.463938] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.467362] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.469208] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.471058] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.472853] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.474976] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.477033] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.478824] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.480575] i915 0000:03:00.0: [drm:drm_dp_i2c_do_msg [drm_display_helper]] AUX C/DDI C/PHY C: native defer
<7> [60.482200] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] HDMI: DVI dual 0, max TMDS clock 300000 kHz
<7> [60.482206] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] HDMI sink does deep color 30.
<7> [60.482209] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] HDMI sink does deep color 36.
<7> [60.482211] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] HDMI sink does deep color 48.
<7> [60.482214] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] Assigning HDMI sink color depth as 16 bpc.
<7> [60.482216] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] HDMI sink does YCRCB444 in deep color.
<7> [60.482220] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] ELD monitor DPF90435
<7> [60.482223] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] HDMI: latency present 0 0, video latency 0 0, audio latency 0 0
<7> [60.482226] i915 0000:03:00.0: [drm:update_display_info.part.0] [CONNECTOR:269:DP-3] ELD size 40, SAD count 3
<7> [60.482238] i915 0000:03:00.0: [drm:intel_dp_set_edid [i915]] [CONNECTOR:269:DP-3] VRR capable: no
<7> [60.482407] i915 0000:03:00.0: [drm:intel_dp_set_edid [i915]] [CONNECTOR:269:DP-3] DFP max bpc 12, max dotclock 0, TMDS clock 25000-600000, PCON Max FRL BW 0Gbps
<7> [60.483611] i915 0000:03:00.0: [drm:intel_dp_set_edid [i915]] PCON ENCODER DSC DPCD: 00 00 00 00 00 00 00 00 00 00 00 00 00
<7> [60.483773] i915 0000:03:00.0: [drm:intel_dp_set_edid [i915]] [CONNECTOR:269:DP-3] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? no, YCbCr 4:4:4->4:2:0 conversion? no
<7> [60.486527] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "2880x1800": 60 390000 2880 3056 3400 3440 1800 1808 1818 1890 0x40 0x5 (CLOCK_HIGH)
<7> [60.486535] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74250 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE)
<7> [60.486541] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 50 74250 1920 2448 2492 2640 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE)
<7> [60.486546] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "720x576i": 50 13500 720 732 795 864 576 580 586 625 0x40 0x101a (NO_INTERLACE)
<7> [60.486552] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x1c005 (NO_STEREO)
<7> [60.486557] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x4005 (NO_STEREO)
<7> [60.486562] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74250 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x20015 (NO_INTERLACE)
<7> [60.486567] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1280x720": 50 74250 1280 1720 1760 1980 720 725 730 750 0x40 0x1c005 (NO_STEREO)
<7> [60.486572] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1280x720": 50 74250 1280 1720 1760 1980 720 725 730 750 0x40 0x4005 (NO_STEREO)
<7> [60.486578] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 50 74250 1920 2448 2492 2640 1080 1084 1094 1125 0x40 0x20015 (NO_INTERLACE)
<7> [60.486592] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 24 74250 1920 2558 2602 2750 1080 1084 1089 1125 0x40 0x1c005 (NO_STEREO)
<7> [60.486597] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 24 74250 1920 2558 2602 2750 1080 1084 1089 1125 0x40 0x4005 (NO_STEREO)
<7> [60.486602] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "3840x2160": 50 594000 3840 4896 4984 5280 2160 2168 2178 2250 0x40 0x5 (NO_420)
<7> [60.486608] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "3840x2160": 60 594000 3840 4016 4104 4400 2160 2168 2178 2250 0x40 0x5 (NO_420)
<7> [60.486613] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "4096x2160": 50 594000 4096 5064 5152 5280 2160 2168 2178 2250 0x40 0x5 (NO_420)
<7> [60.486617] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "4096x2160": 60 594000 4096 4184 4272 4400 2160 2168 2178 2250 0x40 0x5 (NO_420)
<7> [60.486622] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74176 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x15 (NO_INTERLACE)
<7> [60.486627] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x1c005 (NO_STEREO)
<7> [60.486632] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x4005 (NO_STEREO)
<7> [60.486637] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080i": 60 74176 1920 2008 2052 2200 1080 1084 1094 1125 0x40 0x20015 (NO_INTERLACE)
<7> [60.486642] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 24 74176 1920 2558 2602 2750 1080 1084 1089 1125 0x40 0x1c005 (NO_STEREO)
<7> [60.486647] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "1920x1080": 24 74176 1920 2558 2602 2750 1080 1084 1089 1125 0x40 0x4005 (NO_STEREO)
<7> [60.486652] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "3840x2160": 60 593407 3840 4016 4104 4400 2160 2168 2178 2250 0x40 0x5 (NO_420)
<7> [60.486657] i915 0000:03:00.0: [drm:drm_mode_prune_invalid] Rejected mode: "4096x2160": 60 593407 4096 4184 4272 4400 2160 2168 2178 2250 0x40 0x5 (NO_420)
<7> [60.486665] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:269:DP-3] probed modes:
<7> [60.486678] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [60.486689] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "4096x2160": 30 297000 4096 4184 4272 4400 2160 2168 2178 2250 0x40 0x5
<7> [60.486700] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "4096x2160": 30 296703 4096 4184 4272 4400 2160 2168 2178 2250 0x40 0x5
<7> [60.486711] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "4096x2160": 24 297000 4096 5116 5204 5500 2160 2168 2178 2250 0x40 0x5
<7> [60.486722] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "4096x2160": 24 296703 4096 5116 5204 5500 2160 2168 2178 2250 0x40 0x5
<7> [60.486732] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "3840x2160": 30 297000 3840 4016 4104 4400 2160 2168 2178 2250 0x40 0x5
<7> [60.486743] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "3840x2160": 30 296703 3840 4016 4104 4400 2160 2168 2178 2250 0x40 0x5
<7> [60.486754] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "3840x2160": 25 297000 3840 4896 4984 5280 2160 2168 2178 2250 0x40 0x5
<7> [60.486764] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "3840x2160": 24 297000 3840 5116 5204 5500 2160 2168 2178 2250 0x40 0x5
<7> [60.486775] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "3840x2160": 24 296703 3840 5116 5204 5500 2160 2168 2178 2250 0x40 0x5
<7> [60.486785] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "2560x1600": 60 268500 2560 2608 2640 2720 1600 1603 1609 1646 0x40 0x5
<7> [60.486796] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "2224x1668": 60 245000 2224 2270 2302 2382 1668 1671 1677 1714 0x40 0x5
<7> [60.486806] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "2560x1440": 60 241500 2560 2608 2640 2720 1440 1443 1449 1481 0x40 0x5
<7> [60.486816] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1200": 60 154000 1920 1968 2000 2080 1200 1203 1209 1235 0x40 0x9
<7> [60.486827] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 120 297000 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [60.486837] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 120 296703 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [60.486848] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [60.486858] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 60 148352 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [60.486868] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 50 148500 1920 2448 2492 2640 1080 1084 1089 1125 0x40 0x5
<7> [60.486879] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 30 74250 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [60.486889] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 30 74176 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [60.486900] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 25 74250 1920 2448 2492 2640 1080 1084 1089 1125 0x40 0x5
<7> [60.486910] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 24 74250 1920 2558 2602 2750 1080 1084 1089 1125 0x40 0x5
<7> [60.486921] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1920x1080": 24 74176 1920 2558 2602 2750 1080 1084 1089 1125 0x40 0x5
<7> [60.486931] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1600x1200": 60 162000 1600 1664 1856 2160 1200 1201 1204 1250 0x40 0x5
<7> [60.486942] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1680x1050": 60 119000 1680 1728 1760 1840 1050 1053 1059 1080 0x40 0x9
<7> [60.486952] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1600x900": 60 108000 1600 1624 1704 1800 900 901 904 1000 0x40 0x5
<7> [60.486963] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1280x1024": 60 108000 1280 1328 1440 1688 1024 1025 1028 1066 0x40 0x5
<7> [60.486973] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1440x900": 60 88750 1440 1488 1520 1600 900 903 909 926 0x40 0x9
<7> [60.486984] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1366x768": 60 85500 1366 1436 1579 1792 768 771 774 798 0x40 0x5
<7> [60.486994] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1280x800": 60 71000 1280 1328 1360 1440 800 803 809 823 0x40 0x9
<7> [60.487005] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1280x720": 60 74250 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [60.487015] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1280x720": 60 74176 1280 1390 1430 1650 720 725 730 750 0x40 0x5
<7> [60.487026] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1280x720": 50 74250 1280 1720 1760 1980 720 725 730 750 0x40 0x5
<7> [60.487036] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "1024x768": 60 65000 1024 1048 1184 1344 768 771 777 806 0x40 0xa
<7> [60.487047] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "800x600": 60 40000 800 840 968 1056 600 601 605 628 0x40 0x5
<7> [60.487057] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "720x576": 50 27000 720 732 796 864 576 581 586 625 0x40 0xa
<7> [60.487068] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "720x480": 60 27027 720 736 798 858 480 489 495 525 0x40 0xa
<7> [60.487078] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "720x480": 60 27000 720 736 798 858 480 489 495 525 0x40 0xa
<7> [60.487089] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "640x480": 60 25200 640 656 752 800 480 490 492 525 0x40 0xa
<7> [60.487099] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] Probed mode: "640x480": 60 25175 640 656 752 800 480 490 492 525 0x40 0xa
<7> [60.487140] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:277:HDMI-A-2]
<7> [60.487152] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:277:HDMI-A-2]
<7> [60.487525] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpc] NAK for addr: 0050 w(1)
<7> [60.487699] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpc] NAK on first message, retry
<7> [60.488028] i915 0000:03:00.0: [drm:do_gmbus_xfer [i915]] GMBUS [i915 gmbus dpc] NAK for addr: 0050 w(1)
<7> [60.488190] [drm:drm_do_probe_ddc_edid] drm: skipping non-existent adapter i915 gmbus dpc
<7> [60.488194] i915 0000:03:00.0: [drm:intel_hdmi_set_edid [i915]] HDMI GMBUS EDID read failed, retry using GPIO bit-banging
<7> [60.488349] i915 0000:03:00.0: [drm:intel_gmbus_force_bit [i915]] enabling bit-banging on i915 gmbus dpc. force bit now 1
<7> [60.490169] [drm:drm_do_probe_ddc_edid] drm: skipping non-existent adapter i915 gmbus dpc
<7> [60.490173] i915 0000:03:00.0: [drm:intel_gmbus_force_bit [i915]] disabling bit-banging on i915 gmbus dpc. force bit now 0
<7> [60.490338] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:277:HDMI-A-2] disconnected
<7> [60.490363] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:281:DP-4]
<7> [60.490375] i915 0000:03:00.0: [drm:intel_dp_detect [i915]] [CONNECTOR:281:DP-4]
<7> [60.494709] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:281:DP-4] disconnected
<7> [60.494733] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:289:HDMI-A-3]
<7> [60.494744] i915 0000:03:00.0: [drm:intel_hdmi_detect [i915]] [CONNECTOR:289:HDMI-A-3]
<7> [60.499767] i915 0000:03:00.0: [drm:drm_helper_probe_single_connector_modes [drm_kms_helper]] [CONNECTOR:289:HDMI-A-3] disconnected
<6> [60.500141] [IGT] kms_flip: starting subtest plain-flip-ts-check
<6> [60.504340] [IGT] kms_flip: starting dynamic subtest A-DP3
<7> [60.504621] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:295]
<7> [60.504683] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:296]
<7> [60.505111] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.505478] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.573111] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.573435] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.579780] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.580073] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.598477] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.598772] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [60.624418] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:82:pipe A]
<7> [60.624747] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [60.624944] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [60.625109] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [60.625273] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [60.625436] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 5190451/8388608 link 288358/524288, found tu 0, data 0/0 link 0/0)
<7> [60.625608] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000)
<7> [60.625772] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [60.625934] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [60.626097] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [60.626263] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [60.626426] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [60.626594] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [60.626757] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [60.626920] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [60.627087] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [60.627249] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [60.627412] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [60.627614] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [60.627776] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [60.627939] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [60.628102] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [60.628264] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [60.628427] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [60.628635] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [60.628831] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [60.628994] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [60.629160] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [60.629322] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [60.629485] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [60.629685] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [60.629848] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [60.630010] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [60.630173] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [60.630336] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [60.630498] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no)
<7> [60.630728] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [60.630890] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [60.631053] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [60.631216] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in port_clock (expected 270000, found 0)
<7> [60.631379] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:82:pipe A] fastset requirement not met, forcing full modeset
<7> [60.631569] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [60.631791] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:82:pipe A] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [60.631985] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] ddb ( 0 - 1963) -> ( 0 - 0), size 1963 -> 0
<7> [60.632142] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:77:cursor A] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [60.632300] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [60.632457] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] lines 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [60.632654] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] blocks 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [60.632811] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] min_ddb 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [60.632970] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:82:pipe A] data rate 0 num active planes 0
<7> [60.633261] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 0
<7> [60.633447] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] Can change cdclk via squashing
<7> [60.633645] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [60.633807] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New voltage level calculated to be logical 0, actual 0
<7> [60.633971] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:82:pipe A] enable: no [modeset]
<7> [60.634134] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:32:plane 1A] fb: [NOFB], visible: no
<7> [60.634296] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:41:plane 2A] fb: [NOFB], visible: no
<7> [60.634458] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:50:plane 3A] fb: [NOFB], visible: no
<7> [60.634657] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:59:plane 4A] fb: [NOFB], visible: no
<7> [60.634818] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:68:plane 5A] fb: [NOFB], visible: no
<7> [60.634981] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:77:cursor A] fb: [NOFB], visible: no
<7> [60.635224] i915 0000:03:00.0: [drm:intel_audio_codec_disable [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C] Disable audio codec on [CRTC:82:pipe A]
<7> [60.669231] i915 0000:03:00.0: [drm:intel_audio_component_get_eld [i915]] Not valid for port C
<7> [60.686589] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe A
<7> [60.704567] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_C
<7> [60.705446] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling AUX_C
<7> [60.705913] i915 0000:03:00.0: [drm:__intel_fbc_disable [i915]] Disabling FBC on [PLANE:32:plane 1A]
<7> [60.706389] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:240:DDI A/PHY A]
<7> [60.706803] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:242:DP-MST A]
<7> [60.707233] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:243:DP-MST B]
<7> [60.707645] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:244:DP-MST C]
<7> [60.708056] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:245:DP-MST D]
<7> [60.708478] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:253:DDI B/PHY B]
<7> [60.708889] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:255:DP-MST A]
<7> [60.709312] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:256:DP-MST B]
<7> [60.709724] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:257:DP-MST C]
<7> [60.710147] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:258:DP-MST D]
<7> [60.710560] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:268:DDI C/PHY C]
<7> [60.711004] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:270:DP-MST A]
<7> [60.711436] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:271:DP-MST B]
<7> [60.711846] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:272:DP-MST C]
<7> [60.712276] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:273:DP-MST D]
<7> [60.712688] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:280:DDI D/PHY D]
<7> [60.713100] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:282:DP-MST A]
<7> [60.713522] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:283:DP-MST B]
<7> [60.713933] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:284:DP-MST C]
<7> [60.714355] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:285:DP-MST D]
<7> [60.714766] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:269:DP-3]
<7> [60.715364] i915 0000:03:00.0: [drm:intel_set_cdclk [i915]] Post changing CDCLK to 163200 kHz, VCO 1305600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [60.716001] i915 0000:03:00.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=408
<7> [60.716441] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [60.716985] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_A
<7> [60.718364] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [60.719846] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:82:pipe A]
<7> [60.721573] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:134:pipe B]
<7> [60.722555] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:186:pipe C]
<7> [60.722903] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:238:pipe D]
<7> [60.723273] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:82:pipe A]
<7> [60.723348] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:269:DP-3]
<7> [60.723540] i915 0000:03:00.0: [drm:intel_dp_compute_config_limits [i915]] [ENCODER:268:DDI C/PHY C][CRTC:82:pipe A] DP link limits: pixel clock 148500 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 36 max link_bpp 36.0000
<7> [60.723957] i915 0000:03:00.0: [drm:intel_dp_compute_link_config [i915]] DP lane count 4 clock 270000 bpp input 36 compressed 0.0000 link rate required 668250 available 1080000
<7> [60.724405] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:82:pipe A] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [60.724830] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:268:DDI C/PHY C] [CRTC:82:pipe A]
<7> [60.725255] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [60.725680] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [60.726102] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [60.726555] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [60.726978] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 5190451/8388608 link 288358/524288)
<7> [60.727415] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000080)
<7> [60.727837] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [60.728271] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [60.728694] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [60.729115] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [60.729626] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [60.730049] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [60.730439] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [60.730781] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [60.731122] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [60.731473] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [60.731813] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [60.732154] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [60.732504] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [60.732845] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [60.733186] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [60.733539] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [60.733879] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [60.734219] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [60.734571] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [60.734912] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [60.735256] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [60.735552] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [60.735838] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [60.736124] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [60.736418] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [60.736704] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [60.736991] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [60.737287] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [60.737573] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in enhanced_framing (expected no, found yes)
<7> [60.737860] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [60.738146] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [60.738443] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [60.738730] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:82:pipe A] fastset requirement not met in port_clock (expected 0, found 270000)
<7> [60.739017] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:82:pipe A] fastset requirement not met, forcing full modeset
<7> [60.739345] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [60.739624] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:82:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x1
<7> [60.739958] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [60.740242] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:77:cursor A] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [60.740496] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [60.740557] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [60.740734] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [60.740976] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0
<7> [60.741085] i915 0000:03:00.0: [drm:gen9_enable_dc5 [i915]] Enabling DC5
<7> [60.741217] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [PLANE:32:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0
<7> [60.741362] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 01
<7> [60.741466] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:82:pipe A] data rate 594000 num active planes 1
<7> [60.741715] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [60.741960] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [60.742226] i915 0000:03:00.0: [drm:intel_plane_calc_min_cdclk [i915]] [PLANE:32:plane 1A] min cdclk (74250 kHz) > [CRTC:82:pipe A] min cdclk (0 kHz)
<7> [60.742482] i915 0000:03:00.0: [drm:intel_bw_calc_min_cdclk [i915]] new bandwidth min cdclk (11602 kHz) > old min cdclk (0 kHz)
<7> [60.742731] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] Can change cdclk via squashing
<7> [60.742976] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New cdclk calculated to be logical 204000 kHz, actual 204000 kHz
<7> [60.743221] i915 0000:03:00.0: [drm:intel_modeset_calc_cdclk [i915]] New voltage level calculated to be logical 0, actual 0
<7> [60.743476] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:82:pipe A] enable: yes [modeset]
<7> [60.743723] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB
<7> [60.743970] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 36, dithering: 0
<7> [60.744216] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [60.744471] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [60.744716] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [60.744961] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [60.745215] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dp m_n: lanes: 4; data_m: 5190451, data_n: 8388608, link_m: 288358, link_n: 524288, tu: 64
<7> [60.745437] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [60.745654] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] fec: disabled, enhanced framing: enabled
<7> [60.745870] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sdp split: disabled
<7> [60.746085] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [60.746301] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] minimum HBlank: 0
<7> [60.746523] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 1, infoframes: 0, infoframes enabled: 0x0
<7> [60.746739] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00
<7> [60.746955] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11
<7> [60.747171] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ELD: 17 50 51 07 00 00 00 00
<7> [60.747393] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 1
<7> [60.747608] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vblank delay: 0, framestart delay: 1, MSA timing delay: 0
<7> [60.747824] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, vmin: 0, vmax: 0, flipline: 0, pipeline full: 0, guardband: 0 vsync start: 0, vsync end: 0
<7> [60.748039] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 0, vmax vblank: 0, vmin vtotal: 0, vmax vtotal: 0
<7> [60.748254] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [60.748478] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [60.748695] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [60.748912] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [60.749130] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [60.749346] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 270000, pipe src: 1920x1080+0+0, pixel rate 148500
<7> [60.749573] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [60.749789] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [60.750006] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [60.750232] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [60.750432] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x41eb0, dpll_md: 0x18000000, fp0: 0x88228fe, fp1: 0x2b000020
<7> [60.750624] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x40000000 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [60.750817] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [60.751009] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [60.751203] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0db0 0x0000 0x0000
<7> [60.751402] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0db0 0x0000
<7> [60.751594] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0db0
<7> [60.751786] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0100 0x0100 0x0100
<7> [60.751979] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [60.752171] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [60.752364] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [60.752563] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [60.752755] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [60.752948] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:32:plane 1A] fb: [FB:295] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [60.753142] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [60.753335] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [60.753535] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:41:plane 2A] fb: [NOFB], visible: no
<7> [60.753729] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:50:plane 3A] fb: [NOFB], visible: no
<7> [60.753922] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:59:plane 4A] fb: [NOFB], visible: no
<7> [60.754114] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:68:plane 5A] fb: [NOFB], visible: no
<7> [60.754306] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:77:cursor A] fb: [NOFB], visible: no
<7> [60.755548] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [60.755855] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 01 to 00
<7> [60.756218] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [60.756437] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [60.756742] i915 0000:03:00.0: [drm:intel_set_cdclk [i915]] Pre changing CDCLK to 204000 kHz, VCO 1305600 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0
<7> [60.756957] i915 0000:03:00.0: [drm:intel_audio_cdclk_change_post.part.0 [i915]] aud_ts_cdclk set to M=60, N=510
<7> [60.757130] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:240:DDI A/PHY A]
<7> [60.757300] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:242:DP-MST A]
<7> [60.757477] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:243:DP-MST B]
<7> [60.757646] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:244:DP-MST C]
<7> [60.757817] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:245:DP-MST D]
<7> [60.757987] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:253:DDI B/PHY B]
<7> [60.758156] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:255:DP-MST A]
<7> [60.758326] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:256:DP-MST B]
<7> [60.758503] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:257:DP-MST C]
<7> [60.758672] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:258:DP-MST D]
<7> [60.758841] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:268:DDI C/PHY C]
<7> [60.759011] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:270:DP-MST A]
<7> [60.759181] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:271:DP-MST B]
<7> [60.759351] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:272:DP-MST C]
<7> [60.759527] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:273:DP-MST D]
<7> [60.759697] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:280:DDI D/PHY D]
<7> [60.759867] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:282:DP-MST A]
<7> [60.760037] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:283:DP-MST B]
<7> [60.760218] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:284:DP-MST C]
<7> [60.760376] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:285:DP-MST D]
<7> [60.760571] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [60.760861] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling AUX_C
<7> [60.762370] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_C
<7> [60.764721] i915 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX C/DDI C/PHY C: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [60.772287] i915 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00
<7> [60.773601] i915 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX C/DDI C/PHY C: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [60.775163] i915 0000:03:00.0: [drm:intel_dp_start_link_train [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] Using LINK_BW_SET value 0a
<7> [60.776217] i915 0000:03:00.0: [drm:intel_dp_set_signal_levels [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [60.776410] i915 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] Using DP training pattern TPS1
<7> [60.782953] i915 0000:03:00.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] Clock recovery OK
<7> [60.783114] i915 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] Using DP training pattern TPS3
<7> [60.789999] i915 0000:03:00.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] Channel EQ done. DP Training successful
<7> [60.790159] i915 0000:03:00.0: [drm:intel_dp_link_train_phy [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C][DPRX] Link Training passed at link rate = 270000, lane count = 4
<7> [60.791044] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [60.791500] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [60.791682] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:32:plane 1A]
<7> [60.808167] i915 0000:03:00.0: [drm:intel_audio_codec_enable [i915]] [CONNECTOR:269:DP-3][ENCODER:268:DDI C/PHY C] Enable audio codec on [CRTC:82:pipe A], 40 bytes ELD
<7> [60.825308] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:269:DP-3]
<7> [60.825615] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:82:pipe A]
<6> [71.737664] [IGT] kms_flip: finished subtest A-DP3, FAIL
Created at 2025-03-01 12:52:14