igt@kms_flip@flip-vs-expired-vblank-interruptible@b-dp2 on shard-bmg@IGTPW

Detail	Value
Duration	1.22 seconds
Hostname	shard-bmg-6
Igt-Version	IGT-Version: 2.4-gabf1b4463 (x86_64) (Linux: 7.1.0-rc3-lgci-xe-xe-5060-e54a14bbf920aa5ee-debug+ x86_64)
Out	Starting dynamic subtest: B-DP2 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 Stack trace: #0 ../lib/igt_core.c:2074 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1920 run_test() #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() #4 ../tests/kms_flip.c:2105 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest B-DP2: FAIL (1.216s)
Err	Starting dynamic subtest: B-DP2 [64.553860] (kms_flip:2872) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: [64.553940] (kms_flip:2872) CRITICAL: Failed assertion: end - start < 500 [64.554002] (kms_flip:2872) CRITICAL: Last errno: 4, Interrupted system call Dynamic subtest B-DP2 failed. ** DEBUG [63.375455] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000009, size=0) [63.375544] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) [63.375703] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) [63.377261] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=7680) [63.377271] (kms_flip:2872) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) [63.377421] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000009, size=0) [63.377464] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) [63.377550] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) [63.379068] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680) [63.379075] (kms_flip:2872) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) [63.385976] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator [63.388477] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912ef2910, fd: 5> objects: 3, reserved_areas: 0 [63.388481] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912ef2910, fd: 5> objects: 3, reserved_areas: 0 [63.404083] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator [63.405277] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0 [63.405279] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0 [63.408118] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator [63.409282] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0 [63.409283] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0 [63.421863] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator [63.423196] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0 [63.423198] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0 [63.423742] (kms_flip:2872) igt_kms-INFO: 1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 [63.425212] (kms_flip:2872) DEBUG: No stale events found [63.593615] (kms_flip:2872) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0 [63.593932] (kms_flip:2872) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0 [63.619777] (kms_flip:2872) DEBUG: name = flip last_ts = 0.000000 last_received_ts = 0.000000 last_seq = 0 current_ts = 64.980980 current_received_ts = 64.980629 current_seq = 1268 count = 0 seq_step = 1 [63.619824] (kms_flip:2872) DEBUG: Vblank took 34us [63.636422] (kms_flip:2872) DEBUG: name = flip last_ts = 64.980980 last_received_ts = 64.980629 last_seq = 1268 current_ts = 64.997650 current_received_ts = 64.997284 current_seq = 1269 count = 1 seq_step = 1 [63.636454] (kms_flip:2872) DEBUG: Vblank took 26us [63.653095] (kms_flip:2872) DEBUG: name = flip last_ts = 64.997650 last_received_ts = 64.997284 last_seq = 1269 current_ts = 65.014320 current_received_ts = 65.013954 current_seq = 1270 count = 2 seq_step = 1 [63.653147] (kms_flip:2872) DEBUG: Vblank took 44us [63.669753] (kms_flip:2872) DEBUG: name = flip last_ts = 65.014320 last_received_ts = 65.013954 last_seq = 1270 current_ts = 65.030983 current_received_ts = 65.030617 current_seq = 1271 count = 3 seq_step = 1 [63.669784] (kms_flip:2872) DEBUG: Vblank took 25us [63.686414] (kms_flip:2872) DEBUG: name = flip last_ts = 65.030983 last_received_ts = 65.030617 last_seq = 1271 current_ts = 65.047661 current_received_ts = 65.047279 current_seq = 1272 count = 4 seq_step = 1 [63.686444] (kms_flip:2872) DEBUG: Vblank took 25us [63.703079] (kms_flip:2872) DEBUG: name = flip last_ts = 65.047661 last_received_ts = 65.047279 last_seq = 1272 current_ts = 65.064331 current_received_ts = 65.063942 current_seq = 1273 count = 5 seq_step = 1 [63.703108] (kms_flip:2872) DEBUG: Vblank took 24us [63.719748] (kms_flip:2872) DEBUG: name = flip last_ts = 65.064331 last_received_ts = 65.063942 last_seq = 1273 current_ts = 65.081001 current_received_ts = 65.080612 current_seq = 1274 count = 6 seq_step = 1 [63.719778] (kms_flip:2872) DEBUG: Vblank took 25us [63.736343] (kms_flip:2872) DEBUG: name = flip last_ts = 65.081001 last_received_ts = 65.080612 last_seq = 1274 current_ts = 65.097656 current_received_ts = 65.097206 current_seq = 1275 count = 7 seq_step = 1 [63.736374] (kms_flip:2872) DEBUG: Vblank took 25us [63.753083] (kms_flip:2872) DEBUG: name = flip last_ts = 65.097656 last_received_ts = 65.097206 last_seq = 1275 current_ts = 65.114319 current_received_ts = 65.113953 current_seq = 1276 count = 8 seq_step = 1 [63.753112] (kms_flip:2872) DEBUG: Vblank took 26us [63.769678] (kms_flip:2872) DEBUG: name = flip last_ts = 65.114319 last_received_ts = 65.113953 last_seq = 1276 current_ts = 65.130989 current_received_ts = 65.130547 current_seq = 1277 count = 9 seq_step = 1 [63.769708] (kms_flip:2872) DEBUG: Vblank took 25us [63.786345] (kms_flip:2872) DEBUG: name = flip last_ts = 65.130989 last_received_ts = 65.130547 last_seq = 1277 current_ts = 65.147659 current_received_ts = 65.147209 current_seq = 1278 count = 10 seq_step = 1 [63.786375] (kms_flip:2872) DEBUG: Vblank took 25us [63.803012] (kms_flip:2872) DEBUG: name = flip last_ts = 65.147659 last_received_ts = 65.147209 last_seq = 1278 current_ts = 65.164330 current_received_ts = 65.163879 current_seq = 1279 count = 11 seq_step = 1 [63.803042] (kms_flip:2872) DEBUG: Vblank took 25us [63.819756] (kms_flip:2872) DEBUG: name = flip last_ts = 65.164330 last_received_ts = 65.163879 last_seq = 1279 current_ts = 65.180992 current_received_ts = 65.180618 current_seq = 1280 count = 12 seq_step = 1 [63.819785] (kms_flip:2872) DEBUG: Vblank took 26us [63.836347] (kms_flip:2872) DEBUG: name = flip last_ts = 65.180992 last_received_ts = 65.180618 last_seq = 1280 current_ts = 65.197662 current_received_ts = 65.197212 current_seq = 1281 count = 13 seq_step = 1 [63.836376] (kms_flip:2872) DEBUG: Vblank took 26us [63.853088] (kms_flip:2872) DEBUG: name = flip last_ts = 65.197662 last_received_ts = 65.197212 last_seq = 1281 current_ts = 65.214325 current_received_ts = 65.213951 current_seq = 1282 count = 14 seq_step = 1 [63.853117] (kms_flip:2872) DEBUG: Vblank took 24us [63.869762] (kms_flip:2872) DEBUG: name = flip last_ts = 65.214325 last_received_ts = 65.213951 last_seq = 1282 current_ts = 65.230995 current_received_ts = 65.230629 current_seq = 1283 count = 15 seq_step = 1 [63.869794] (kms_flip:2872) DEBUG: Vblank took 25us [63.886350] (kms_flip:2872) DEBUG: name = flip last_ts = 65.230995 last_received_ts = 65.230629 last_seq = 1283 current_ts = 65.247665 current_received_ts = 65.247215 current_seq = 1284 count = 16 seq_step = 1 [63.886379] (kms_flip:2872) DEBUG: Vblank took 24us [63.903088] (kms_flip:2872) DEBUG: name = flip last_ts = 65.247665 last_received_ts = 65.247215 last_seq = 1284 current_ts = 65.264328 current_received_ts = 65.263954 current_seq = 1285 count = 17 seq_step = 1 [63.903117] (kms_flip:2872) DEBUG: Vblank took 24us [63.919684] (kms_flip:2872) DEBUG: name = flip last_ts = 65.264328 last_received_ts = 65.263954 last_seq = 1285 current_ts = 65.280998 current_received_ts = 65.280548 current_seq = 1286 count = 18 seq_step = 1 [63.919714] (kms_flip:2872) DEBUG: Vblank took 25us [63.936351] (kms_flip:2872) DEBUG: name = flip last_ts = 65.280998 last_received_ts = 65.280548 last_seq = 1286 current_ts = 65.297668 current_received_ts = 65.297218 current_seq = 1287 count = 19 seq_step = 1 [63.936380] (kms_flip:2872) DEBUG: Vblank took 25us [63.953018] (kms_flip:2872) DEBUG: name = flip last_ts = 65.297668 last_received_ts = 65.297218 last_seq = 1287 current_ts = 65.314331 current_received_ts = 65.313889 current_seq = 1288 count = 20 seq_step = 1 [63.953047] (kms_flip:2872) DEBUG: Vblank took 25us [63.969778] (kms_flip:2872) DEBUG: name = flip last_ts = 65.314331 last_received_ts = 65.313889 last_seq = 1288 current_ts = 65.331001 current_received_ts = 65.330643 current_seq = 1289 count = 21 seq_step = 1 [63.969808] (kms_flip:2872) DEBUG: Vblank took 25us [63.986319] (kms_flip:2872) DEBUG: name = flip last_ts = 65.331001 last_received_ts = 65.330643 last_seq = 1289 current_ts = 65.347672 current_received_ts = 65.347183 current_seq = 1290 count = 22 seq_step = 1 [63.986349] (kms_flip:2872) DEBUG: Vblank took 25us [64.003099] (kms_flip:2872) DEBUG: name = flip last_ts = 65.347672 last_received_ts = 65.347183 last_seq = 1290 current_ts = 65.364334 current_received_ts = 65.363968 current_seq = 1291 count = 23 seq_step = 1 [64.003154] (kms_flip:2872) DEBUG: Vblank took 47us [64.019688] (kms_flip:2872) DEBUG: name = flip last_ts = 65.364334 last_received_ts = 65.363968 last_seq = 1291 current_ts = 65.381004 current_received_ts = 65.380554 current_seq = 1292 count = 24 seq_step = 1 [64.019718] (kms_flip:2872) DEBUG: Vblank took 25us [64.036429] (kms_flip:2872) DEBUG: name = flip last_ts = 65.381004 last_received_ts = 65.380554 last_seq = 1292 current_ts = 65.397667 current_received_ts = 65.397293 current_seq = 1293 count = 25 seq_step = 1 [64.036458] (kms_flip:2872) DEBUG: Vblank took 25us [64.053095] (kms_flip:2872) DEBUG: name = flip last_ts = 65.397667 last_received_ts = 65.397293 last_seq = 1293 current_ts = 65.414337 current_received_ts = 65.413963 current_seq = 1294 count = 26 seq_step = 1 [64.053125] (kms_flip:2872) DEBUG: Vblank took 25us [64.069766] (kms_flip:2872) DEBUG: name = flip last_ts = 65.414337 last_received_ts = 65.413963 last_seq = 1294 current_ts = 65.431007 current_received_ts = 65.430634 current_seq = 1295 count = 27 seq_step = 1 [64.069795] (kms_flip:2872) DEBUG: Vblank took 25us [64.086430] (kms_flip:2872) DEBUG: name = flip last_ts = 65.431007 last_received_ts = 65.430634 last_seq = 1295 current_ts = 65.447685 current_received_ts = 65.447296 current_seq = 1296 count = 28 seq_step = 1 [64.086459] (kms_flip:2872) DEBUG: Vblank took 25us [64.103097] (kms_flip:2872) DEBUG: name = flip last_ts = 65.447685 last_received_ts = 65.447296 last_seq = 1296 current_ts = 65.464333 current_received_ts = 65.463966 current_seq = 1297 count = 29 seq_step = 1 [64.103125] (kms_flip:2872) DEBUG: Vblank took 25us [64.119766] (kms_flip:2872) DEBUG: name = flip last_ts = 65.464333 last_received_ts = 65.463966 last_seq = 1297 current_ts = 65.481003 current_received_ts = 65.480629 current_seq = 1298 count = 30 seq_step = 1 [64.119794] (kms_flip:2872) DEBUG: Vblank took 25us [64.136433] (kms_flip:2872) DEBUG: name = flip last_ts = 65.481003 last_received_ts = 65.480629 last_seq = 1298 current_ts = 65.497673 current_received_ts = 65.497299 current_seq = 1299 count = 31 seq_step = 1 [64.136464] (kms_flip:2872) DEBUG: Vblank took 25us [64.153099] (kms_flip:2872) DEBUG: name = flip last_ts = 65.497673 last_received_ts = 65.497299 last_seq = 1299 current_ts = 65.514336 current_received_ts = 65.513962 current_seq = 1300 count = 32 seq_step = 1 [64.153146] (kms_flip:2872) DEBUG: Vblank took 43us [64.169765] (kms_flip:2872) DEBUG: name = flip last_ts = 65.514336 last_received_ts = 65.513962 last_seq = 1300 current_ts = 65.531021 current_received_ts = 65.530632 current_seq = 1301 count = 33 seq_step = 1 [64.169794] (kms_flip:2872) DEBUG: Vblank took 24us [64.186363] (kms_flip:2872) DEBUG: name = flip last_ts = 65.531021 last_received_ts = 65.530632 last_seq = 1301 current_ts = 65.547676 current_received_ts = 65.547226 current_seq = 1302 count = 34 seq_step = 1 [64.186391] (kms_flip:2872) DEBUG: Vblank took 25us [64.203030] (kms_flip:2872) DEBUG: name = flip last_ts = 65.547676 last_received_ts = 65.547226 last_seq = 1302 current_ts = 65.564346 current_received_ts = 65.563896 current_seq = 1303 count = 35 seq_step = 1 [64.203059] (kms_flip:2872) DEBUG: Vblank took 24us [64.219772] (kms_flip:2872) DEBUG: name = flip last_ts = 65.564346 last_received_ts = 65.563896 last_seq = 1303 current_ts = 65.581009 current_received_ts = 65.580635 current_seq = 1304 count = 36 seq_step = 1 [64.219801] (kms_flip:2872) DEBUG: Vblank took 25us [64.236365] (kms_flip:2872) DEBUG: name = flip last_ts = 65.581009 last_received_ts = 65.580635 last_seq = 1304 current_ts = 65.597679 current_received_ts = 65.597229 current_seq = 1305 count = 37 seq_step = 1 [64.236393] (kms_flip:2872) DEBUG: Vblank took 25us [64.253104] (kms_flip:2872) DEBUG: name = flip last_ts = 65.597679 last_received_ts = 65.597229 last_seq = 1305 current_ts = 65.614342 current_received_ts = 65.613968 current_seq = 1306 count = 38 seq_step = 1 [64.253148] (kms_flip:2872) DEBUG: Vblank took 41us [64.269699] (kms_flip:2872) DEBUG: name = flip last_ts = 65.614342 last_received_ts = 65.613968 last_seq = 1306 current_ts = 65.631012 current_received_ts = 65.630562 current_seq = 1307 count = 39 seq_step = 1 [64.269729] (kms_flip:2872) DEBUG: Vblank took 25us [64.286439] (kms_flip:2872) DEBUG: name = flip last_ts = 65.631012 last_received_ts = 65.630562 last_seq = 1307 current_ts = 65.647682 current_received_ts = 65.647308 current_seq = 1308 count = 40 seq_step = 1 [64.286468] (kms_flip:2872) DEBUG: Vblank took 25us [64.303104] (kms_flip:2872) DEBUG: name = flip last_ts = 65.647682 last_received_ts = 65.647308 last_seq = 1308 current_ts = 65.664345 current_received_ts = 65.663971 current_seq = 1309 count = 41 seq_step = 1 [64.303147] (kms_flip:2872) DEBUG: Vblank took 39us [64.319772] (kms_flip:2872) DEBUG: name = flip last_ts = 65.664345 last_received_ts = 65.663971 last_seq = 1309 current_ts = 65.681030 current_received_ts = 65.680641 current_seq = 1310 count = 42 seq_step = 1 [64.319801] (kms_flip:2872) DEBUG: Vblank took 25us [64.336441] (kms_flip:2872) DEBUG: name = flip last_ts = 65.681030 last_received_ts = 65.680641 last_seq = 1310 current_ts = 65.697678 current_received_ts = 65.697304 current_seq = 1311 count = 43 seq_step = 1 [64.336470] (kms_flip:2872) DEBUG: Vblank took 24us [64.353108] (kms_flip:2872) DEBUG: name = flip last_ts = 65.697678 last_received_ts = 65.697304 last_seq = 1311 current_ts = 65.714348 current_received_ts = 65.713974 current_seq = 1312 count = 44 seq_step = 1 [64.353150] (kms_flip:2872) DEBUG: Vblank took 38us [64.369704] (kms_flip:2872) DEBUG: name = flip last_ts = 65.714348 last_received_ts = 65.713974 last_seq = 1312 current_ts = 65.731018 current_received_ts = 65.730568 current_seq = 1313 count = 45 seq_step = 1 [64.369732] (kms_flip:2872) DEBUG: Vblank took 24us [64.386372] (kms_flip:2872) DEBUG: name = flip last_ts = 65.731018 last_received_ts = 65.730568 last_seq = 1313 current_ts = 65.747688 current_received_ts = 65.747238 current_seq = 1314 count = 46 seq_step = 1 [64.386400] (kms_flip:2872) DEBUG: Vblank took 25us [64.403111] (kms_flip:2872) DEBUG: name = flip last_ts = 65.747688 last_received_ts = 65.747238 last_seq = 1314 current_ts = 65.764351 current_received_ts = 65.763977 current_seq = 1315 count = 47 seq_step = 1 [64.403155] (kms_flip:2872) DEBUG: Vblank took 39us [64.419706] (kms_flip:2872) DEBUG: name = flip last_ts = 65.764351 last_received_ts = 65.763977 last_seq = 1315 current_ts = 65.781021 current_received_ts = 65.780571 current_seq = 1316 count = 48 seq_step = 1 [64.419735] (kms_flip:2872) DEBUG: Vblank took 24us [64.436445] (kms_flip:2872) DEBUG: name = flip last_ts = 65.781021 last_received_ts = 65.780571 last_seq = 1316 current_ts = 65.797684 current_received_ts = 65.797310 current_seq = 1317 count = 49 seq_step = 1 [64.436477] (kms_flip:2872) DEBUG: Vblank took 25us [64.453040] (kms_flip:2872) DEBUG: name = flip last_ts = 65.797684 last_received_ts = 65.797310 last_seq = 1317 current_ts = 65.814354 current_received_ts = 65.813904 current_seq = 1318 count = 50 seq_step = 1 [64.453069] (kms_flip:2872) DEBUG: Vblank took 25us [64.469778] (kms_flip:2872) DEBUG: name = flip last_ts = 65.814354 last_received_ts = 65.813904 last_seq = 1318 current_ts = 65.831032 current_received_ts = 65.830643 current_seq = 1319 count = 51 seq_step = 1 [64.469806] (kms_flip:2872) DEBUG: Vblank took 24us [64.486450] (kms_flip:2872) DEBUG: name = flip last_ts = 65.831032 last_received_ts = 65.830643 last_seq = 1319 current_ts = 65.847687 current_received_ts = 65.847313 current_seq = 1320 count = 52 seq_step = 1 [64.486480] (kms_flip:2872) DEBUG: Vblank took 26us [64.503002] (kms_flip:2872) DEBUG: name = flip last_ts = 65.847687 last_received_ts = 65.847313 last_seq = 1320 current_ts = 65.864365 current_received_ts = 65.863869 current_seq = 1321 count = 53 seq_step = 1 [64.503031] (kms_flip:2872) DEBUG: Vblank took 25us [64.519669] (kms_flip:2872) DEBUG: name = flip last_ts = 65.864365 last_received_ts = 65.863869 last_seq = 1321 current_ts = 65.881027 current_received_ts = 65.880531 current_seq = 1322 count = 54 seq_step = 1 [64.519698] (kms_flip:2872) DEBUG: Vblank took 25us [64.536453] (kms_flip:2872) DEBUG: name = flip last_ts = 65.881027 last_received_ts = 65.880531 last_seq = 1322 current_ts = 65.897690 current_received_ts = 65.897316 current_seq = 1323 count = 55 seq_step = 1 [64.536482] (kms_flip:2872) DEBUG: Vblank took 25us [64.553119] (kms_flip:2872) DEBUG: name = flip last_ts = 65.897690 last_received_ts = 65.897316 last_seq = 1323 current_ts = 65.914360 current_received_ts = 65.913986 current_seq = 1324 count = 56 seq_step = 1 [64.553853] (kms_flip:2872) DEBUG: Vblank took 727us [64.553860] (kms_flip:2872) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: [64.553940] (kms_flip:2872) CRITICAL: Failed assertion: end - start < 500 [64.554002] (kms_flip:2872) CRITICAL: Last errno: 4, Interrupted system call [64.567452] (kms_flip:2872) igt_core-INFO: Stack trace: [64.583280] (kms_flip:2872) igt_core-INFO: #0 ../lib/igt_core.c:2074 __igt_fail_assert() [64.584669] (kms_flip:2872) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() [64.584743] (kms_flip:2872) igt_core-INFO: #2 ../tests/kms_flip.c:1920 run_test() [64.584783] (kms_flip:2872) igt_core-INFO: #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105() [64.584832] (kms_flip:2872) igt_core-INFO: #4 ../tests/kms_flip.c:2105 main() [64.588044] (kms_flip:2872) igt_core-INFO: #5 [__libc_init_first+0x8a] [64.589025] (kms_flip:2872) igt_core-INFO: #6 [__libc_start_main+0x8b] [64.589238] (kms_flip:2872) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest B-DP2: FAIL (1.216s)
Dmesg	<6> [64.903822] [IGT] kms_flip: starting dynamic subtest B-DP2 <7> [64.906605] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:556] <7> [64.908393] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:559] <7> [64.954454] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [64.954542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [64.954693] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [64.954825] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [64.954952] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [64.955083] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 7208960/8388608 link 480597/524288, found tu 0, data 0/0 link 0/0) <7> [64.955213] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000) <7> [64.955331] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [64.955465] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0) <7> [64.955617] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0) <7> [64.955737] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0) <7> [64.955852] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0) <7> [64.955961] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0) <7> [64.956065] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0) <7> [64.956168] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0) <7> [64.956268] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0) <7> [64.956375] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0) <7> [64.956473] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0) <7> [64.956569] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0) <7> [64.956663] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0) <7> [64.956758] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0) <7> [64.956853] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0) <7> [64.956947] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0) <7> [64.957042] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0) <7> [64.957136] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0) <7> [64.957230] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0) <7> [64.957324] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0) <7> [64.957432] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0) <7> [64.957533] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0) <7> [64.957628] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0) <7> [64.957723] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0) <7> [64.957819] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0) <7> [64.957914] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [64.958008] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0) <7> [64.958104] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0) <7> [64.958199] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no) <7> [64.958296] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [64.958442] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0) <7> [64.958542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0) <7> [64.958637] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 162000, found 0) <7> [64.958733] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000002, found 0x00000000) <7> [64.958829] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [64.958926] xe 0000:03:00.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing TC PLL 2 <7> [64.959054] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [64.959136] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [64.959234] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4037 - 4096) -> ( 0 - 0), size 59 -> 0 <7> [64.959312] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 192000 kHz -> 0 kHz <7> [64.959472] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset] <7> [64.959581] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [64.959686] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [64.959790] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [64.959893] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [64.960059] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [64.960167] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [64.960583] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Disable audio codec on [CRTC:151:pipe A] <7> [64.982591] xe 0000:03:00.0: [drm:intel_audio_component_get_eld [xe]] Not valid for port E <7> [64.983347] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [65.000643] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2 <7> [65.003539] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disable TC PLL 2 (active 0x1, on? 1) for [CRTC:151:pipe A] <7> [65.006093] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disabling TC PLL 2 <7> [65.006966] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:507:DDI TC1/PHY F] <7> [65.007427] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST A] <7> [65.007834] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST B] <7> [65.007761] xe 0000:03:00.0: [drm:intel_audio_component_get_power [xe]] restored AUD_FREQ_CNTRL to 0x8010 <7> [65.008226] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST C] <7> [65.008620] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:512:DP-MST D] <7> [65.008966] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:526:DDI TC2/PHY G] <7> [65.009510] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST A] <7> [65.009847] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST B] <7> [65.010144] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST C] <7> [65.010461] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:531:DP-MST D] <7> [65.010739] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:538:DDI TC3/PHY H] <7> [65.011000] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:542:DDI TC4/PHY I] <7> [65.011252] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST A] <7> [65.011534] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST B] <7> [65.011790] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST C] <7> [65.012034] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:547:DP-MST D] <7> [65.012275] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:527:DP-2] <7> [65.012763] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no) <7> [65.012978] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [65.013325] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [65.013898] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [65.014347] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [65.014837] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [65.015227] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C] <7> [65.015968] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe B] <7> [65.016132] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D] <7> [65.016289] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C] <7> [65.016318] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:527:DP-2] <7> [65.016655] xe 0000:03:00.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:527:DP-2] Limiting target display pipe bpp to 30 (EDID bpp 48, max requested bpp 30, max platform bpp 36) <7> [65.016854] xe 0000:03:00.0: [drm:intel_dp_compute_config_limits [xe]] [CONNECTOR:527:DP-2] Can't force 30 bpp for HDR (pipe bpp: 18-36 DSC-support: no) <7> [65.017027] xe 0000:03:00.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:526:DDI TC2/PHY G][CRTC:269:pipe C] DP link limits: pixel clock 148500 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000 <7> [65.017184] xe 0000:03:00.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 162000 bpp input 30 compressed 0.0000 HDR yes link rate required 556875 available 648000 <7> [65.017342] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [65.017520] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:526:DDI TC2/PHY G] [CRTC:269:pipe C] <7> [65.017678] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.enable (expected no, found yes) <7> [65.017831] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.active (expected no, found yes) <7> [65.017976] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2) <7> [65.018115] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in lane_count (expected 0, found 4) <7> [65.018249] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 7208960/8388608 link 480597/524288) <7> [65.018396] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000080) <7> [65.018524] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [65.018650] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920) <7> [65.018775] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200) <7> [65.018898] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920) <7> [65.019020] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200) <7> [65.019147] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008) <7> [65.019259] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052) <7> [65.019380] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080) <7> [65.019485] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080) <7> [65.019588] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084) <7> [65.019691] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089) <7> [65.019793] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125) <7> [65.019896] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125) <7> [65.019992] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920) <7> [65.020087] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200) <7> [65.020181] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920) <7> [65.020275] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200) <7> [65.020375] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008) <7> [65.020478] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052) <7> [65.020577] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080) <7> [65.020673] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080) <7> [65.020769] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084) <7> [65.020864] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089) <7> [65.020958] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125) <7> [65.021052] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125) <7> [65.021146] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [65.021240] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1) <7> [65.021335] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4) <7> [65.021440] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in enhanced_framing (expected no, found yes) <7> [65.021534] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in dpll_hw_state <7> [65.021592] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2 <7> [65.021628] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected: <7> [65.021722] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [65.021815] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state: <7> [65.021909] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000 <7> [65.022003] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [65.022098] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x40e8 <7> [65.022190] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x7d20 <7> [65.022283] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0x0a06 <7> [65.022381] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0x8f1c <7> [65.022474] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x0000 <7> [65.022567] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x0000 <7> [65.022660] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2200 <7> [65.022753] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0xffff <7> [65.022846] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x0400 <7> [65.022939] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000 <7> [65.023033] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0001 <7> [65.023126] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00 <7> [65.023222] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found: <7> [65.023316] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [65.023434] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state: <7> [65.023537] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000 <7> [65.023637] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [65.023733] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x50a8 <7> [65.023829] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x2120 <7> [65.023924] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0xcd9a <7> [65.024018] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0xbfc1 <7> [65.024111] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x5ab8 <7> [65.024206] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x4c34 <7> [65.024299] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2000 <7> [65.024415] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0x0001 <7> [65.024508] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x6000 <7> [65.024601] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000 <7> [65.024694] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000 <7> [65.024786] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x40, hdmi rate: 0x00 <7> [65.024879] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [65.024972] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500) <7> [65.025066] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500) <7> [65.025159] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in port_clock (expected 0, found 162000) <7> [65.025252] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000002) <7> [65.025345] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] fastset requirement not met, forcing full modeset <7> [65.025468] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no <7> [65.025551] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:269:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4 <7> [65.025649] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:153:plane 1C] ddb ( 0 - 0) -> ( 0 - 1989), size 0 -> 1989 <7> [65.025727] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:263:cursor C] ddb ( 0 - 0) -> (1989 - 2048), size 0 -> 59 <7> [65.025802] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [65.025873] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 9, 9, 17, 17, 17, 17, 0, 15, 0 <7> [65.025946] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 139, 139, 261, 261, 261, 261, 137, 230, 244 <7> [65.026017] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 245, 245, 367, 367, 0, 0, 138, 306, 306 <7> [65.026097] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:269:pipe C] data rate 594000 num active planes 1 <7> [65.026206] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 624 qgv_peak_bw: 48000 <7> [65.026313] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 624 qgv_peak_bw: 48000 <7> [65.026425] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 624 <7> [65.026546] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:269:pipe C] min cdclk: 0 kHz -> 192000 kHz <7> [65.026675] xe 0000:03:00.0: [drm:intel_find_dpll [xe]] [CRTC:269:pipe C] allocated TC PLL 2 <7> [65.026772] xe 0000:03:00.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:269:pipe C] reserving TC PLL 2 <7> [65.026868] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:269:pipe C] enable: yes [modeset] <7> [65.026976] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB <7> [65.027081] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 30, dithering: 0 <7> [65.027182] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [65.027284] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [65.027409] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [65.027513] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [65.027613] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 7208960, data_n: 8388608, link_m: 480597, link_n: 524288, tu: 64 <7> [65.027713] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0 <7> [65.027811] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled <7> [65.027910] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [65.028008] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled <7> [65.028106] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0 <7> [65.028202] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 0, infoframes enabled: 0x2 <7> [65.028300] xe 0000:03:00.0: HDMI infoframe: Dynamic Range and Mastering, version 1, length 26 <7> [65.028302] xe 0000:03:00.0: length: 26 <7> [65.028303] xe 0000:03:00.0: metadata type: 0 <7> [65.028305] xe 0000:03:00.0: eotf: 2 <7> [65.028306] xe 0000:03:00.0: x[0]: 35400 <7> [65.028307] xe 0000:03:00.0: y[0]: 14599 <7> [65.028308] xe 0000:03:00.0: x[1]: 8500 <7> [65.028310] xe 0000:03:00.0: y[1]: 39850 <7> [65.028311] xe 0000:03:00.0: x[2]: 6550 <7> [65.028312] xe 0000:03:00.0: y[2]: 2300 <7> [65.028313] xe 0000:03:00.0: white point x: 15634 <7> [65.028314] xe 0000:03:00.0: white point y: 16450 <7> [65.028315] xe 0000:03:00.0: max_display_mastering_luminance: 1000 <7> [65.028317] xe 0000:03:00.0: min_display_mastering_luminance: 500 <7> [65.028318] xe 0000:03:00.0: max_cll: 500 <7> [65.028319] xe 0000:03:00.0: max_fall: 1000 <7> [65.028320] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00 <7> [65.028459] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11 <7> [65.028558] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 17 50 51 07 00 00 00 00 <7> [65.028657] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [65.028755] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [65.028853] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 42 vsync start: 41, vsync end: 36 <7> [65.028955] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1083, vmax vblank: 1083, vmin vtotal: 1125, vmax vtotal: 1125 <7> [65.029056] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [65.029155] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [65.029254] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 <7> [65.029353] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [65.029463] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5 <7> [65.029561] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5 <7> [65.029659] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 162000, pixel rate 148500, min cdclk 192000, min voltage level 0 <7> [65.029756] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0 <7> [65.029853] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0 <7> [65.029948] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe src: 1920x1080+0+0 <7> [65.030043] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [65.030139] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [65.030235] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [65.030331] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no <7> [65.030434] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] c20pll_hw_state: <7> [65.030530] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000 <7> [65.030625] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000 <7> [65.030720] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[0] = 0x50a8 <7> [65.030815] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[1] = 0x2120 <7> [65.030910] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[2] = 0xcd9a <7> [65.031006] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[3] = 0xbfc1 <7> [65.031101] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[4] = 0x5ab8 <7> [65.031196] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[5] = 0x4c34 <7> [65.031291] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[6] = 0x2000 <7> [65.031414] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[7] = 0x0001 <7> [65.031509] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[8] = 0x6000 <7> [65.031605] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[9] = 0x0000 <7> [65.031700] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[10] = 0x0000 <7> [65.031795] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vdr: custom width: 0x00, serdes rate: 0x40, hdmi rate: 0x00 <7> [65.031891] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [65.031987] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [65.032082] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [65.032177] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [65.032272] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [65.032372] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [65.032469] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [65.032563] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [65.032659] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [65.032754] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [65.032849] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [65.032944] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [65.033039] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:153:plane 1C] fb: [FB:556] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [65.033136] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [65.033232] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0 <7> [65.033328] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:183:plane 2C] fb: [NOFB], visible: no <7> [65.033433] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:213:plane 3C] fb: [NOFB], visible: no <7> [65.033534] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:243:plane 4C] fb: [NOFB], visible: no <7> [65.033654] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:253:plane 5C] fb: [NOFB], visible: no <7> [65.033779] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:263:cursor C] fb: [NOFB], visible: no <7> [65.034476] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2 <7> [65.034593] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_C <7> [65.034716] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000) <7> [65.034827] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:507:DDI TC1/PHY F] <7> [65.034919] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST A] <7> [65.035008] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST B] <7> [65.035094] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST C] <7> [65.035180] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:512:DP-MST D] <7> [65.035266] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:526:DDI TC2/PHY G] <7> [65.035350] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST A] <7> [65.035452] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST B] <7> [65.035539] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST C] <7> [65.035623] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:531:DP-MST D] <7> [65.035708] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:538:DDI TC3/PHY H] <7> [65.035792] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:542:DDI TC4/PHY I] <7> [65.035875] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST A] <7> [65.035958] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST B] <7> [65.036040] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST C] <7> [65.036122] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:547:DP-MST D] <7> [65.036213] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd <7> [65.036388] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no) <7> [65.036486] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enable TC PLL 2 (active 0x4, on? 0) for [CRTC:269:pipe C] <7> [65.036581] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enabling TC PLL 2 <7> [65.040533] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01 <7> [65.045268] xe 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00 <7> [65.046280] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01 <7> [65.046736] xe 0000:03:00.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using LINK_BW_SET value 06 <7> [65.048296] xe 0000:03:00.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [65.048869] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS1 <7> [65.056339] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Clock recovery OK <7> [65.056490] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS3 <7> [65.063349] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Channel EQ done. DP Training successful <7> [65.063594] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Link Training passed at link rate = 162000, lane count = 4 <7> [65.064902] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe C <7> [65.099050] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Enable audio codec on [CRTC:269:pipe C], 40 bytes ELD <7> [65.113154] xe 0000:03:00.0: [drm:intel_audio_component_get_power [xe]] restored AUD_FREQ_CNTRL to 0x8010 <7> [65.116149] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:527:DP-2] <7> [65.117082] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:269:pipe C] <7> [65.168411] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2 <6> [66.120310] [IGT] kms_flip: finished subtest B-DP2, FAIL

Detail

Value

Duration

1.22 seconds

Hostname

shard-bmg-6

Igt-Version

IGT-Version: 2.4-gabf1b4463 (x86_64) (Linux: 7.1.0-rc3-lgci-xe-xe-5060-e54a14bbf920aa5ee-debug+ x86_64)

Out

Starting dynamic subtest: B-DP2
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2074 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-DP2: FAIL (1.216s)

Err

Starting dynamic subtest: B-DP2
[64.553860] (kms_flip:2872) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[64.553940] (kms_flip:2872) CRITICAL: Failed assertion: end - start < 500
[64.554002] (kms_flip:2872) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-DP2 failed.
**** DEBUG ****
[63.375455] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000009, size=0)
[63.375544] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
[63.375703] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
[63.377261] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=7680)
[63.377271] (kms_flip:2872) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
[63.377421] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=1920, height=1080, format=XR24(0x34325258), modifier=0x100000000000009, size=0)
[63.377464] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
[63.377550] (kms_flip:2872) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
[63.379068] (kms_flip:2872) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=7680)
[63.379075] (kms_flip:2872) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
[63.385976] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator
[63.388477] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912ef2910, fd: 5> objects: 3, reserved_areas: 0
[63.388481] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912ef2910, fd: 5> objects: 3, reserved_areas: 0
[63.404083] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator
[63.405277] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0
[63.405279] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0
[63.408118] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator
[63.409282] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0
[63.409283] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0
[63.421863] (kms_flip:2872) intel_allocator_simple-DEBUG: Using simple allocator
[63.423196] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0
[63.423198] (kms_flip:2872) intel_allocator_simple-DEBUG: <ial: 0x608912e5ae00, fd: 5> objects: 3, reserved_areas: 0
[63.423742] (kms_flip:2872) igt_kms-INFO:   1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
[63.425212] (kms_flip:2872) DEBUG: No stale events found
[63.593615] (kms_flip:2872) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
[63.593932] (kms_flip:2872) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
[63.619777] (kms_flip:2872) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 64.980980
current_received_ts = 64.980629
current_seq = 1268
count = 0
seq_step = 1
[63.619824] (kms_flip:2872) DEBUG: Vblank took 34us
[63.636422] (kms_flip:2872) DEBUG: name = flip
last_ts = 64.980980
last_received_ts = 64.980629
last_seq = 1268
current_ts = 64.997650
current_received_ts = 64.997284
current_seq = 1269
count = 1
seq_step = 1
[63.636454] (kms_flip:2872) DEBUG: Vblank took 26us
[63.653095] (kms_flip:2872) DEBUG: name = flip
last_ts = 64.997650
last_received_ts = 64.997284
last_seq = 1269
current_ts = 65.014320
current_received_ts = 65.013954
current_seq = 1270
count = 2
seq_step = 1
[63.653147] (kms_flip:2872) DEBUG: Vblank took 44us
[63.669753] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.014320
last_received_ts = 65.013954
last_seq = 1270
current_ts = 65.030983
current_received_ts = 65.030617
current_seq = 1271
count = 3
seq_step = 1
[63.669784] (kms_flip:2872) DEBUG: Vblank took 25us
[63.686414] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.030983
last_received_ts = 65.030617
last_seq = 1271
current_ts = 65.047661
current_received_ts = 65.047279
current_seq = 1272
count = 4
seq_step = 1
[63.686444] (kms_flip:2872) DEBUG: Vblank took 25us
[63.703079] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.047661
last_received_ts = 65.047279
last_seq = 1272
current_ts = 65.064331
current_received_ts = 65.063942
current_seq = 1273
count = 5
seq_step = 1
[63.703108] (kms_flip:2872) DEBUG: Vblank took 24us
[63.719748] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.064331
last_received_ts = 65.063942
last_seq = 1273
current_ts = 65.081001
current_received_ts = 65.080612
current_seq = 1274
count = 6
seq_step = 1
[63.719778] (kms_flip:2872) DEBUG: Vblank took 25us
[63.736343] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.081001
last_received_ts = 65.080612
last_seq = 1274
current_ts = 65.097656
current_received_ts = 65.097206
current_seq = 1275
count = 7
seq_step = 1
[63.736374] (kms_flip:2872) DEBUG: Vblank took 25us
[63.753083] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.097656
last_received_ts = 65.097206
last_seq = 1275
current_ts = 65.114319
current_received_ts = 65.113953
current_seq = 1276
count = 8
seq_step = 1
[63.753112] (kms_flip:2872) DEBUG: Vblank took 26us
[63.769678] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.114319
last_received_ts = 65.113953
last_seq = 1276
current_ts = 65.130989
current_received_ts = 65.130547
current_seq = 1277
count = 9
seq_step = 1
[63.769708] (kms_flip:2872) DEBUG: Vblank took 25us
[63.786345] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.130989
last_received_ts = 65.130547
last_seq = 1277
current_ts = 65.147659
current_received_ts = 65.147209
current_seq = 1278
count = 10
seq_step = 1
[63.786375] (kms_flip:2872) DEBUG: Vblank took 25us
[63.803012] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.147659
last_received_ts = 65.147209
last_seq = 1278
current_ts = 65.164330
current_received_ts = 65.163879
current_seq = 1279
count = 11
seq_step = 1
[63.803042] (kms_flip:2872) DEBUG: Vblank took 25us
[63.819756] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.164330
last_received_ts = 65.163879
last_seq = 1279
current_ts = 65.180992
current_received_ts = 65.180618
current_seq = 1280
count = 12
seq_step = 1
[63.819785] (kms_flip:2872) DEBUG: Vblank took 26us
[63.836347] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.180992
last_received_ts = 65.180618
last_seq = 1280
current_ts = 65.197662
current_received_ts = 65.197212
current_seq = 1281
count = 13
seq_step = 1
[63.836376] (kms_flip:2872) DEBUG: Vblank took 26us
[63.853088] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.197662
last_received_ts = 65.197212
last_seq = 1281
current_ts = 65.214325
current_received_ts = 65.213951
current_seq = 1282
count = 14
seq_step = 1
[63.853117] (kms_flip:2872) DEBUG: Vblank took 24us
[63.869762] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.214325
last_received_ts = 65.213951
last_seq = 1282
current_ts = 65.230995
current_received_ts = 65.230629
current_seq = 1283
count = 15
seq_step = 1
[63.869794] (kms_flip:2872) DEBUG: Vblank took 25us
[63.886350] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.230995
last_received_ts = 65.230629
last_seq = 1283
current_ts = 65.247665
current_received_ts = 65.247215
current_seq = 1284
count = 16
seq_step = 1
[63.886379] (kms_flip:2872) DEBUG: Vblank took 24us
[63.903088] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.247665
last_received_ts = 65.247215
last_seq = 1284
current_ts = 65.264328
current_received_ts = 65.263954
current_seq = 1285
count = 17
seq_step = 1
[63.903117] (kms_flip:2872) DEBUG: Vblank took 24us
[63.919684] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.264328
last_received_ts = 65.263954
last_seq = 1285
current_ts = 65.280998
current_received_ts = 65.280548
current_seq = 1286
count = 18
seq_step = 1
[63.919714] (kms_flip:2872) DEBUG: Vblank took 25us
[63.936351] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.280998
last_received_ts = 65.280548
last_seq = 1286
current_ts = 65.297668
current_received_ts = 65.297218
current_seq = 1287
count = 19
seq_step = 1
[63.936380] (kms_flip:2872) DEBUG: Vblank took 25us
[63.953018] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.297668
last_received_ts = 65.297218
last_seq = 1287
current_ts = 65.314331
current_received_ts = 65.313889
current_seq = 1288
count = 20
seq_step = 1
[63.953047] (kms_flip:2872) DEBUG: Vblank took 25us
[63.969778] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.314331
last_received_ts = 65.313889
last_seq = 1288
current_ts = 65.331001
current_received_ts = 65.330643
current_seq = 1289
count = 21
seq_step = 1
[63.969808] (kms_flip:2872) DEBUG: Vblank took 25us
[63.986319] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.331001
last_received_ts = 65.330643
last_seq = 1289
current_ts = 65.347672
current_received_ts = 65.347183
current_seq = 1290
count = 22
seq_step = 1
[63.986349] (kms_flip:2872) DEBUG: Vblank took 25us
[64.003099] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.347672
last_received_ts = 65.347183
last_seq = 1290
current_ts = 65.364334
current_received_ts = 65.363968
current_seq = 1291
count = 23
seq_step = 1
[64.003154] (kms_flip:2872) DEBUG: Vblank took 47us
[64.019688] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.364334
last_received_ts = 65.363968
last_seq = 1291
current_ts = 65.381004
current_received_ts = 65.380554
current_seq = 1292
count = 24
seq_step = 1
[64.019718] (kms_flip:2872) DEBUG: Vblank took 25us
[64.036429] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.381004
last_received_ts = 65.380554
last_seq = 1292
current_ts = 65.397667
current_received_ts = 65.397293
current_seq = 1293
count = 25
seq_step = 1
[64.036458] (kms_flip:2872) DEBUG: Vblank took 25us
[64.053095] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.397667
last_received_ts = 65.397293
last_seq = 1293
current_ts = 65.414337
current_received_ts = 65.413963
current_seq = 1294
count = 26
seq_step = 1
[64.053125] (kms_flip:2872) DEBUG: Vblank took 25us
[64.069766] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.414337
last_received_ts = 65.413963
last_seq = 1294
current_ts = 65.431007
current_received_ts = 65.430634
current_seq = 1295
count = 27
seq_step = 1
[64.069795] (kms_flip:2872) DEBUG: Vblank took 25us
[64.086430] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.431007
last_received_ts = 65.430634
last_seq = 1295
current_ts = 65.447685
current_received_ts = 65.447296
current_seq = 1296
count = 28
seq_step = 1
[64.086459] (kms_flip:2872) DEBUG: Vblank took 25us
[64.103097] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.447685
last_received_ts = 65.447296
last_seq = 1296
current_ts = 65.464333
current_received_ts = 65.463966
current_seq = 1297
count = 29
seq_step = 1
[64.103125] (kms_flip:2872) DEBUG: Vblank took 25us
[64.119766] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.464333
last_received_ts = 65.463966
last_seq = 1297
current_ts = 65.481003
current_received_ts = 65.480629
current_seq = 1298
count = 30
seq_step = 1
[64.119794] (kms_flip:2872) DEBUG: Vblank took 25us
[64.136433] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.481003
last_received_ts = 65.480629
last_seq = 1298
current_ts = 65.497673
current_received_ts = 65.497299
current_seq = 1299
count = 31
seq_step = 1
[64.136464] (kms_flip:2872) DEBUG: Vblank took 25us
[64.153099] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.497673
last_received_ts = 65.497299
last_seq = 1299
current_ts = 65.514336
current_received_ts = 65.513962
current_seq = 1300
count = 32
seq_step = 1
[64.153146] (kms_flip:2872) DEBUG: Vblank took 43us
[64.169765] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.514336
last_received_ts = 65.513962
last_seq = 1300
current_ts = 65.531021
current_received_ts = 65.530632
current_seq = 1301
count = 33
seq_step = 1
[64.169794] (kms_flip:2872) DEBUG: Vblank took 24us
[64.186363] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.531021
last_received_ts = 65.530632
last_seq = 1301
current_ts = 65.547676
current_received_ts = 65.547226
current_seq = 1302
count = 34
seq_step = 1
[64.186391] (kms_flip:2872) DEBUG: Vblank took 25us
[64.203030] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.547676
last_received_ts = 65.547226
last_seq = 1302
current_ts = 65.564346
current_received_ts = 65.563896
current_seq = 1303
count = 35
seq_step = 1
[64.203059] (kms_flip:2872) DEBUG: Vblank took 24us
[64.219772] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.564346
last_received_ts = 65.563896
last_seq = 1303
current_ts = 65.581009
current_received_ts = 65.580635
current_seq = 1304
count = 36
seq_step = 1
[64.219801] (kms_flip:2872) DEBUG: Vblank took 25us
[64.236365] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.581009
last_received_ts = 65.580635
last_seq = 1304
current_ts = 65.597679
current_received_ts = 65.597229
current_seq = 1305
count = 37
seq_step = 1
[64.236393] (kms_flip:2872) DEBUG: Vblank took 25us
[64.253104] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.597679
last_received_ts = 65.597229
last_seq = 1305
current_ts = 65.614342
current_received_ts = 65.613968
current_seq = 1306
count = 38
seq_step = 1
[64.253148] (kms_flip:2872) DEBUG: Vblank took 41us
[64.269699] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.614342
last_received_ts = 65.613968
last_seq = 1306
current_ts = 65.631012
current_received_ts = 65.630562
current_seq = 1307
count = 39
seq_step = 1
[64.269729] (kms_flip:2872) DEBUG: Vblank took 25us
[64.286439] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.631012
last_received_ts = 65.630562
last_seq = 1307
current_ts = 65.647682
current_received_ts = 65.647308
current_seq = 1308
count = 40
seq_step = 1
[64.286468] (kms_flip:2872) DEBUG: Vblank took 25us
[64.303104] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.647682
last_received_ts = 65.647308
last_seq = 1308
current_ts = 65.664345
current_received_ts = 65.663971
current_seq = 1309
count = 41
seq_step = 1
[64.303147] (kms_flip:2872) DEBUG: Vblank took 39us
[64.319772] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.664345
last_received_ts = 65.663971
last_seq = 1309
current_ts = 65.681030
current_received_ts = 65.680641
current_seq = 1310
count = 42
seq_step = 1
[64.319801] (kms_flip:2872) DEBUG: Vblank took 25us
[64.336441] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.681030
last_received_ts = 65.680641
last_seq = 1310
current_ts = 65.697678
current_received_ts = 65.697304
current_seq = 1311
count = 43
seq_step = 1
[64.336470] (kms_flip:2872) DEBUG: Vblank took 24us
[64.353108] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.697678
last_received_ts = 65.697304
last_seq = 1311
current_ts = 65.714348
current_received_ts = 65.713974
current_seq = 1312
count = 44
seq_step = 1
[64.353150] (kms_flip:2872) DEBUG: Vblank took 38us
[64.369704] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.714348
last_received_ts = 65.713974
last_seq = 1312
current_ts = 65.731018
current_received_ts = 65.730568
current_seq = 1313
count = 45
seq_step = 1
[64.369732] (kms_flip:2872) DEBUG: Vblank took 24us
[64.386372] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.731018
last_received_ts = 65.730568
last_seq = 1313
current_ts = 65.747688
current_received_ts = 65.747238
current_seq = 1314
count = 46
seq_step = 1
[64.386400] (kms_flip:2872) DEBUG: Vblank took 25us
[64.403111] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.747688
last_received_ts = 65.747238
last_seq = 1314
current_ts = 65.764351
current_received_ts = 65.763977
current_seq = 1315
count = 47
seq_step = 1
[64.403155] (kms_flip:2872) DEBUG: Vblank took 39us
[64.419706] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.764351
last_received_ts = 65.763977
last_seq = 1315
current_ts = 65.781021
current_received_ts = 65.780571
current_seq = 1316
count = 48
seq_step = 1
[64.419735] (kms_flip:2872) DEBUG: Vblank took 24us
[64.436445] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.781021
last_received_ts = 65.780571
last_seq = 1316
current_ts = 65.797684
current_received_ts = 65.797310
current_seq = 1317
count = 49
seq_step = 1
[64.436477] (kms_flip:2872) DEBUG: Vblank took 25us
[64.453040] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.797684
last_received_ts = 65.797310
last_seq = 1317
current_ts = 65.814354
current_received_ts = 65.813904
current_seq = 1318
count = 50
seq_step = 1
[64.453069] (kms_flip:2872) DEBUG: Vblank took 25us
[64.469778] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.814354
last_received_ts = 65.813904
last_seq = 1318
current_ts = 65.831032
current_received_ts = 65.830643
current_seq = 1319
count = 51
seq_step = 1
[64.469806] (kms_flip:2872) DEBUG: Vblank took 24us
[64.486450] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.831032
last_received_ts = 65.830643
last_seq = 1319
current_ts = 65.847687
current_received_ts = 65.847313
current_seq = 1320
count = 52
seq_step = 1
[64.486480] (kms_flip:2872) DEBUG: Vblank took 26us
[64.503002] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.847687
last_received_ts = 65.847313
last_seq = 1320
current_ts = 65.864365
current_received_ts = 65.863869
current_seq = 1321
count = 53
seq_step = 1
[64.503031] (kms_flip:2872) DEBUG: Vblank took 25us
[64.519669] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.864365
last_received_ts = 65.863869
last_seq = 1321
current_ts = 65.881027
current_received_ts = 65.880531
current_seq = 1322
count = 54
seq_step = 1
[64.519698] (kms_flip:2872) DEBUG: Vblank took 25us
[64.536453] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.881027
last_received_ts = 65.880531
last_seq = 1322
current_ts = 65.897690
current_received_ts = 65.897316
current_seq = 1323
count = 55
seq_step = 1
[64.536482] (kms_flip:2872) DEBUG: Vblank took 25us
[64.553119] (kms_flip:2872) DEBUG: name = flip
last_ts = 65.897690
last_received_ts = 65.897316
last_seq = 1323
current_ts = 65.914360
current_received_ts = 65.913986
current_seq = 1324
count = 56
seq_step = 1
[64.553853] (kms_flip:2872) DEBUG: Vblank took 727us
[64.553860] (kms_flip:2872) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[64.553940] (kms_flip:2872) CRITICAL: Failed assertion: end - start < 500
[64.554002] (kms_flip:2872) CRITICAL: Last errno: 4, Interrupted system call
[64.567452] (kms_flip:2872) igt_core-INFO: Stack trace:
[64.583280] (kms_flip:2872) igt_core-INFO:   #0 ../lib/igt_core.c:2074 __igt_fail_assert()
[64.584669] (kms_flip:2872) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
[64.584743] (kms_flip:2872) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
[64.584783] (kms_flip:2872) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
[64.584832] (kms_flip:2872) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
[64.588044] (kms_flip:2872) igt_core-INFO:   #5 [__libc_init_first+0x8a]
[64.589025] (kms_flip:2872) igt_core-INFO:   #6 [__libc_start_main+0x8b]
[64.589238] (kms_flip:2872) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-DP2: FAIL (1.216s)

Dmesg

<6> [64.903822] [IGT] kms_flip: starting dynamic subtest B-DP2

<7> [64.906605] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:556]

<7> [64.908393] xe 0000:03:00.0: [drm:drm_mode_addfb2] [FB:559]

<7> [64.954454] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

<7> [64.954542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no)

<7> [64.954693] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no)

<7> [64.954825] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)

<7> [64.954952] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0)

<7> [64.955083] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 7208960/8388608 link 480597/524288, found tu 0, data 0/0 link 0/0)

<7> [64.955213] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000)

<7> [64.955331] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)

<7> [64.955465] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)

<7> [64.955617] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)

<7> [64.955737] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)

<7> [64.955852] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)

<7> [64.955961] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)

<7> [64.956065] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)

<7> [64.956168] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)

<7> [64.956268] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)

<7> [64.956375] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)

<7> [64.956473] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)

<7> [64.956569] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)

<7> [64.956663] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)

<7> [64.956758] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)

<7> [64.956853] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)

<7> [64.956947] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)

<7> [64.957042] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)

<7> [64.957136] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)

<7> [64.957230] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)

<7> [64.957324] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)

<7> [64.957432] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)

<7> [64.957533] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)

<7> [64.957628] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)

<7> [64.957723] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)

<7> [64.957819] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)

<7> [64.957914] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)

<7> [64.958008] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)

<7> [64.958104] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)

<7> [64.958199] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no)

<7> [64.958296] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)

<7> [64.958442] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)

<7> [64.958542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)

<7> [64.958637] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 162000, found 0)

<7> [64.958733] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in infoframes.enable (expected 0x00000002, found 0x00000000)

<7> [64.958829] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset

<7> [64.958926] xe 0000:03:00.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing TC PLL 2

<7> [64.959054] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no

<7> [64.959136] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0

<7> [64.959234] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4037 - 4096) -> ( 0 - 0), size 59 -> 0

<7> [64.959312] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 192000 kHz -> 0 kHz

<7> [64.959472] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]

<7> [64.959581] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no

<7> [64.959686] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no

<7> [64.959790] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no

<7> [64.959893] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no

<7> [64.960059] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no

<7> [64.960167] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no

<7> [64.960583] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Disable audio codec on [CRTC:151:pipe A]

<7> [64.982591] xe 0000:03:00.0: [drm:intel_audio_component_get_eld [xe]] Not valid for port E

<7> [64.983347] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe A

<7> [65.000643] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2

<7> [65.003539] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disable TC PLL 2 (active 0x1, on? 1) for [CRTC:151:pipe A]

<7> [65.006093] xe 0000:03:00.0: [drm:intel_dpll_disable [xe]] disabling TC PLL 2

<7> [65.006966] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:507:DDI TC1/PHY F]

<7> [65.007427] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST A]

<7> [65.007834] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST B]

<7> [65.007761] xe 0000:03:00.0: [drm:intel_audio_component_get_power [xe]] restored AUD_FREQ_CNTRL to 0x8010

<7> [65.008226] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST C]

<7> [65.008620] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:512:DP-MST D]

<7> [65.008966] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:526:DDI TC2/PHY G]

<7> [65.009510] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST A]

<7> [65.009847] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST B]

<7> [65.010144] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST C]

<7> [65.010461] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:531:DP-MST D]

<7> [65.010739] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:538:DDI TC3/PHY H]

<7> [65.011000] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:542:DDI TC4/PHY I]

<7> [65.011252] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST A]

<7> [65.011534] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST B]

<7> [65.011790] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST C]

<7> [65.012034] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:547:DP-MST D]

<7> [65.012275] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:527:DP-2]

<7> [65.012763] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)

<7> [65.012978] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)

<7> [65.013325] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1

<7> [65.013898] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_A

<7> [65.014347] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)

<7> [65.014837] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

<7> [65.015227] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C]

<7> [65.015968] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe B]

<7> [65.016132] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]

<7> [65.016289] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C]

<7> [65.016318] xe 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:527:DP-2]

<7> [65.016655] xe 0000:03:00.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:527:DP-2] Limiting target display pipe bpp to 30 (EDID bpp 48, max requested bpp 30, max platform bpp 36)

<7> [65.016854] xe 0000:03:00.0: [drm:intel_dp_compute_config_limits [xe]] [CONNECTOR:527:DP-2] Can't force 30 bpp for HDR (pipe bpp: 18-36 DSC-support: no)

<7> [65.017027] xe 0000:03:00.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:526:DDI TC2/PHY G][CRTC:269:pipe C] DP link limits: pixel clock 148500 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000

<7> [65.017184] xe 0000:03:00.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 162000 bpp input 30 compressed 0.0000 HDR yes link rate required 556875 available 648000

<7> [65.017342] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] hw max bpp: 30, pipe bpp: 30, dithering: 0

<7> [65.017520] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:526:DDI TC2/PHY G] [CRTC:269:pipe C]

<7> [65.017678] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.enable (expected no, found yes)

<7> [65.017831] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.active (expected no, found yes)

<7> [65.017976] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in cpu_transcoder (expected -1, found 2)

<7> [65.018115] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in lane_count (expected 0, found 4)

<7> [65.018249] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 7208960/8388608 link 480597/524288)

<7> [65.018396] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in output_types (expected 0x00000000, found 0x00000080)

<7> [65.018524] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in framestart_delay (expected 0, found 1)

<7> [65.018650] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)

<7> [65.018775] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)

<7> [65.018898] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)

<7> [65.019020] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)

<7> [65.019147] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)

<7> [65.019259] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)

<7> [65.019380] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)

<7> [65.019485] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)

<7> [65.019588] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)

<7> [65.019691] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)

<7> [65.019793] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)

<7> [65.019896] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)

<7> [65.019992] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)

<7> [65.020087] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)

<7> [65.020181] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)

<7> [65.020275] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)

<7> [65.020375] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)

<7> [65.020478] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)

<7> [65.020577] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)

<7> [65.020673] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)

<7> [65.020769] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)

<7> [65.020864] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)

<7> [65.020958] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)

<7> [65.021052] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)

<7> [65.021146] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in pixel_multiplier (expected 0, found 1)

<7> [65.021240] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)

<7> [65.021335] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)

<7> [65.021440] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in enhanced_framing (expected no, found yes)

<7> [65.021534] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in dpll_hw_state

<7> [65.021592] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2

<7> [65.021628] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:

<7> [65.021722] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no

<7> [65.021815] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:

<7> [65.021909] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000

<7> [65.022003] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000

<7> [65.022098] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x40e8

<7> [65.022190] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x7d20

<7> [65.022283] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0x0a06

<7> [65.022381] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0x8f1c

<7> [65.022474] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x0000

<7> [65.022567] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x0000

<7> [65.022660] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2200

<7> [65.022753] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0xffff

<7> [65.022846] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x0400

<7> [65.022939] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000

<7> [65.023033] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0001

<7> [65.023126] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00

<7> [65.023222] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:

<7> [65.023316] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no

<7> [65.023434] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:

<7> [65.023537] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000

<7> [65.023637] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000

<7> [65.023733] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[0] = 0x50a8

<7> [65.023829] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[1] = 0x2120

<7> [65.023924] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[2] = 0xcd9a

<7> [65.024018] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[3] = 0xbfc1

<7> [65.024111] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[4] = 0x5ab8

<7> [65.024206] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[5] = 0x4c34

<7> [65.024299] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[6] = 0x2000

<7> [65.024415] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[7] = 0x0001

<7> [65.024508] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[8] = 0x6000

<7> [65.024601] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[9] = 0x0000

<7> [65.024694] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000

<7> [65.024786] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x40, hdmi rate: 0x00

<7> [65.024879] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in pipe_bpp (expected 0, found 30)

<7> [65.024972] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)

<7> [65.025066] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)

<7> [65.025159] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in port_clock (expected 0, found 162000)

<7> [65.025252] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:269:pipe C] fastset requirement not met in infoframes.enable (expected 0x00000000, found 0x00000002)

<7> [65.025345] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:269:pipe C] fastset requirement not met, forcing full modeset

<7> [65.025468] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no

<7> [65.025551] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:269:pipe C] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x4

<7> [65.025649] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:153:plane 1C] ddb ( 0 - 0) -> ( 0 - 1989), size 0 -> 1989

<7> [65.025727] xe 0000:03:00.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:263:cursor C] ddb ( 0 - 0) -> (1989 - 2048), size 0 -> 59

<7> [65.025802] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm

<7> [65.025873] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 9, 9, 17, 17, 17, 17, 0, 15, 0

<7> [65.025946] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 139, 139, 261, 261, 261, 261, 137, 230, 244

<7> [65.026017] xe 0000:03:00.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:153:plane 1C] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 245, 245, 367, 367, 0, 0, 138, 306, 306

<7> [65.026097] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:269:pipe C] data rate 594000 num active planes 1

<7> [65.026206] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 624 qgv_peak_bw: 48000

<7> [65.026313] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 624 qgv_peak_bw: 48000

<7> [65.026425] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 624

<7> [65.026546] xe 0000:03:00.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:269:pipe C] min cdclk: 0 kHz -> 192000 kHz

<7> [65.026675] xe 0000:03:00.0: [drm:intel_find_dpll [xe]] [CRTC:269:pipe C] allocated TC PLL 2

<7> [65.026772] xe 0000:03:00.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:269:pipe C] reserving TC PLL 2

<7> [65.026868] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:269:pipe C] enable: yes [modeset]

<7> [65.026976] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB

<7> [65.027081] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: C, pipe bpp: 30, dithering: 0

<7> [65.027182] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>

<7> [65.027284] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0

<7> [65.027409] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0

<7> [65.027513] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0

<7> [65.027613] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 7208960, data_n: 8388608, link_m: 480597, link_n: 524288, tu: 64

<7> [65.027713] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0

<7> [65.027811] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled

<7> [65.027910] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled

<7> [65.028008] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled

<7> [65.028106] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0

<7> [65.028202] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 0, infoframes enabled: 0x2

<7> [65.028300] xe 0000:03:00.0: HDMI infoframe: Dynamic Range and Mastering, version 1, length 26

<7> [65.028302] xe 0000:03:00.0: length: 26

<7> [65.028303] xe 0000:03:00.0: metadata type: 0

<7> [65.028305] xe 0000:03:00.0: eotf: 2

<7> [65.028306] xe 0000:03:00.0: x[0]: 35400

<7> [65.028307] xe 0000:03:00.0: y[0]: 14599

<7> [65.028308] xe 0000:03:00.0: x[1]: 8500

<7> [65.028310] xe 0000:03:00.0: y[1]: 39850

<7> [65.028311] xe 0000:03:00.0: x[2]: 6550

<7> [65.028312] xe 0000:03:00.0: y[2]: 2300

<7> [65.028313] xe 0000:03:00.0: white point x: 15634

<7> [65.028314] xe 0000:03:00.0: white point y: 16450

<7> [65.028315] xe 0000:03:00.0: max_display_mastering_luminance: 1000

<7> [65.028317] xe 0000:03:00.0: min_display_mastering_luminance: 500

<7> [65.028318] xe 0000:03:00.0: max_cll: 500

<7> [65.028319] xe 0000:03:00.0: max_fall: 1000

<7> [65.028320] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00

<7> [65.028459] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11

<7> [65.028558] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ELD: 17 50 51 07 00 00 00 00

<7> [65.028657] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1

<7> [65.028755] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0

<7> [65.028853] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 42 vsync start: 41, vsync end: 36

<7> [65.028955] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1083, vmax vblank: 1083, vmin vtotal: 1125, vmax vtotal: 1125

<7> [65.029056] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0

<7> [65.029155] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [65.029254] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5

<7> [65.029353] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [65.029463] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5

<7> [65.029561] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5

<7> [65.029659] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 162000, pixel rate 148500, min cdclk 192000, min voltage level 0

<7> [65.029756] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0

<7> [65.029853] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0

<7> [65.029948] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe src: 1920x1080+0+0

<7> [65.030043] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no

<7> [65.030139] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0

<7> [65.030235] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0

<7> [65.030331] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: no, tbt_mode: no

<7> [65.030434] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] c20pll_hw_state:

<7> [65.030530] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] tx[0] = 0xbe88, tx[1] = 0x5800, tx[2] = 0x0000

<7> [65.030625] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000

<7> [65.030720] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[0] = 0x50a8

<7> [65.030815] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[1] = 0x2120

<7> [65.030910] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[2] = 0xcd9a

<7> [65.031006] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[3] = 0xbfc1

<7> [65.031101] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[4] = 0x5ab8

<7> [65.031196] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[5] = 0x4c34

<7> [65.031291] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[6] = 0x2000

<7> [65.031414] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[7] = 0x0001

<7> [65.031509] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[8] = 0x6000

<7> [65.031605] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[9] = 0x0000

<7> [65.031700] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] mpllb[10] = 0x0000

<7> [65.031795] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vdr: custom width: 0x00, serdes rate: 0x40, hdmi rate: 0x00

<7> [65.031891] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

<7> [65.031987] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries

<7> [65.032082] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000

<7> [65.032177] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [65.032272] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [65.032372] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [65.032469] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000

<7> [65.032563] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000

<7> [65.032659] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [65.032754] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [65.032849] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [65.032944] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000

<7> [65.033039] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:153:plane 1C] fb: [FB:556] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

<7> [65.033136] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0

<7> [65.033232] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0

<7> [65.033328] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:183:plane 2C] fb: [NOFB], visible: no

<7> [65.033433] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:213:plane 3C] fb: [NOFB], visible: no

<7> [65.033534] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:243:plane 4C] fb: [NOFB], visible: no

<7> [65.033654] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:253:plane 5C] fb: [NOFB], visible: no

<7> [65.033779] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:263:cursor C] fb: [NOFB], visible: no

<7> [65.034476] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2

<7> [65.034593] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_C

<7> [65.034716] xe 0000:03:00.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x4 (CLKGATE_DIS_DSSDSC=0x8a000000)

<7> [65.034827] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:507:DDI TC1/PHY F]

<7> [65.034919] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:509:DP-MST A]

<7> [65.035008] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:510:DP-MST B]

<7> [65.035094] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:511:DP-MST C]

<7> [65.035180] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:512:DP-MST D]

<7> [65.035266] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:526:DDI TC2/PHY G]

<7> [65.035350] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:528:DP-MST A]

<7> [65.035452] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:529:DP-MST B]

<7> [65.035539] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:530:DP-MST C]

<7> [65.035623] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:531:DP-MST D]

<7> [65.035708] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:538:DDI TC3/PHY H]

<7> [65.035792] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:542:DDI TC4/PHY I]

<7> [65.035875] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:544:DP-MST A]

<7> [65.035958] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:545:DP-MST B]

<7> [65.036040] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:546:DP-MST C]

<7> [65.036122] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:547:DP-MST D]

<7> [65.036213] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xd

<7> [65.036388] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)

<7> [65.036486] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enable TC PLL 2 (active 0x4, on? 0) for [CRTC:269:pipe C]

<7> [65.036581] xe 0000:03:00.0: [drm:intel_dpll_enable [xe]] enabling TC PLL 2

<7> [65.040533] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01

<7> [65.045268] xe 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00

<7> [65.046280] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01

<7> [65.046736] xe 0000:03:00.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using LINK_BW_SET value 06

<7> [65.048296] xe 0000:03:00.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0

<7> [65.048869] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS1

<7> [65.056339] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Clock recovery OK

<7> [65.056490] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Using DP training pattern TPS3

<7> [65.063349] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Channel EQ done. DP Training successful

<7> [65.063594] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G][DPRX] Link Training passed at link rate = 162000, lane count = 4

<7> [65.064902] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe C

<7> [65.099050] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:527:DP-2][ENCODER:526:DDI TC2/PHY G] Enable audio codec on [CRTC:269:pipe C], 40 bytes ELD

<7> [65.113154] xe 0000:03:00.0: [drm:intel_audio_component_get_power [xe]] restored AUD_FREQ_CNTRL to 0x8010

<7> [65.116149] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:527:DP-2]

<7> [65.117082] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:269:pipe C]

<7> [65.168411] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2

<6> [66.120310] [IGT] kms_flip: finished subtest B-DP2, FAIL

Results for igt@kms_flip@flip-vs-expired-vblank-interruptible@b-dp2