igt@kms_flip@flip-vs-expired-vblank@a-edp1 on shard-lnl@xe-4858-9e217a8df7b2f298a2fd850e29f970b7360dc77b Test details

Detail	Value
Duration	10.15 seconds
Hostname	shard-lnl-2
Igt-Version	IGT-Version: 2.4-g2a9f1c1ae (x86_64) (Linux: 7.0.0-rc7-lgci-xe-xe-4858-9e217a8df7b2f298a-debug+ x86_64)
Out	Using IGT_SRANDOM=1775592189 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() #2 ../tests/kms_flip.c:1919 run_test() #3 ../tests/kms_flip.c:2183 __igt_unique____real_main2104() #4 ../tests/kms_flip.c:2104 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (10.153s)
Err	Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 (kms_flip:5481) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:5481) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:5481) DEBUG: name = flip last_ts = 259.430511 last_received_ts = 259.429932 last_seq = 4176 current_ts = 259.447174 current_received_ts = 259.446594 current_seq = 4177 count = 397 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 259.447174 last_received_ts = 259.446594 last_seq = 4177 current_ts = 259.463837 current_received_ts = 259.463257 current_seq = 4178 count = 398 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 259.463837 last_received_ts = 259.463257 last_seq = 4178 current_ts = 259.480499 current_received_ts = 259.479767 current_seq = 4179 count = 399 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 259.480499 last_received_ts = 259.479767 last_seq = 4179 current_ts = 259.497162 current_received_ts = 259.496582 current_seq = 4180 count = 400 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 68us (kms_flip:5481) DEBUG: name = flip last_ts = 259.497162 last_received_ts = 259.496582 last_seq = 4180 current_ts = 259.513824 current_received_ts = 259.513245 current_seq = 4181 count = 401 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 68us (kms_flip:5481) DEBUG: name = flip last_ts = 259.513824 last_received_ts = 259.513245 last_seq = 4181 current_ts = 259.530487 current_received_ts = 259.529877 current_seq = 4182 count = 402 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.530487 last_received_ts = 259.529877 last_seq = 4182 current_ts = 259.547150 current_received_ts = 259.546600 current_seq = 4183 count = 403 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 64us (kms_flip:5481) DEBUG: name = flip last_ts = 259.547150 last_received_ts = 259.546600 last_seq = 4183 current_ts = 259.563812 current_received_ts = 259.563232 current_seq = 4184 count = 404 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 64us (kms_flip:5481) DEBUG: name = flip last_ts = 259.563812 last_received_ts = 259.563232 last_seq = 4184 current_ts = 259.580475 current_received_ts = 259.579865 current_seq = 4185 count = 405 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.580475 last_received_ts = 259.579865 last_seq = 4185 current_ts = 259.597168 current_received_ts = 259.596405 current_seq = 4186 count = 406 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 58us (kms_flip:5481) DEBUG: name = flip last_ts = 259.597168 last_received_ts = 259.596405 last_seq = 4186 current_ts = 259.613831 current_received_ts = 259.613251 current_seq = 4187 count = 407 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 259.613831 last_received_ts = 259.613251 last_seq = 4187 current_ts = 259.630493 current_received_ts = 259.629852 current_seq = 4188 count = 408 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.630493 last_received_ts = 259.629852 last_seq = 4188 current_ts = 259.647156 current_received_ts = 259.646576 current_seq = 4189 count = 409 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.647156 last_received_ts = 259.646576 last_seq = 4189 current_ts = 259.663818 current_received_ts = 259.663239 current_seq = 4190 count = 410 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 259.663818 last_received_ts = 259.663239 last_seq = 4190 current_ts = 259.680481 current_received_ts = 259.679840 current_seq = 4191 count = 411 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.680481 last_received_ts = 259.679840 last_seq = 4191 current_ts = 259.697144 current_received_ts = 259.696411 current_seq = 4192 count = 412 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 68us (kms_flip:5481) DEBUG: name = flip last_ts = 259.697144 last_received_ts = 259.696411 last_seq = 4192 current_ts = 259.713806 current_received_ts = 259.713257 current_seq = 4193 count = 413 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 64us (kms_flip:5481) DEBUG: name = flip last_ts = 259.713806 last_received_ts = 259.713257 last_seq = 4193 current_ts = 259.730469 current_received_ts = 259.729858 current_seq = 4194 count = 414 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 259.730469 last_received_ts = 259.729858 last_seq = 4194 current_ts = 259.747131 current_received_ts = 259.746460 current_seq = 4195 count = 415 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 57us (kms_flip:5481) DEBUG: name = flip last_ts = 259.747131 last_received_ts = 259.746460 last_seq = 4195 current_ts = 259.763794 current_received_ts = 259.763214 current_seq = 4196 count = 416 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.763794 last_received_ts = 259.763214 last_seq = 4196 current_ts = 259.780457 current_received_ts = 259.779907 current_seq = 4197 count = 417 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.780457 last_received_ts = 259.779907 last_seq = 4197 current_ts = 259.797119 current_received_ts = 259.796600 current_seq = 4198 count = 418 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 259.797119 last_received_ts = 259.796600 last_seq = 4198 current_ts = 259.813812 current_received_ts = 259.813232 current_seq = 4199 count = 419 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 64us (kms_flip:5481) DEBUG: name = flip last_ts = 259.813812 last_received_ts = 259.813232 last_seq = 4199 current_ts = 259.830475 current_received_ts = 259.829834 current_seq = 4200 count = 420 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 60us (kms_flip:5481) DEBUG: name = flip last_ts = 259.830475 last_received_ts = 259.829834 last_seq = 4200 current_ts = 259.847137 current_received_ts = 259.846558 current_seq = 4201 count = 421 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 259.847137 last_received_ts = 259.846558 last_seq = 4201 current_ts = 259.863800 current_received_ts = 259.863220 current_seq = 4202 count = 422 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.863800 last_received_ts = 259.863220 last_seq = 4202 current_ts = 259.880463 current_received_ts = 259.879852 current_seq = 4203 count = 423 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.880463 last_received_ts = 259.879852 last_seq = 4203 current_ts = 259.897125 current_received_ts = 259.896545 current_seq = 4204 count = 424 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.897125 last_received_ts = 259.896545 last_seq = 4204 current_ts = 259.913788 current_received_ts = 259.913208 current_seq = 4205 count = 425 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 259.913788 last_received_ts = 259.913208 last_seq = 4205 current_ts = 259.930450 current_received_ts = 259.929840 current_seq = 4206 count = 426 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.930450 last_received_ts = 259.929840 last_seq = 4206 current_ts = 259.947113 current_received_ts = 259.946564 current_seq = 4207 count = 427 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 259.947113 last_received_ts = 259.946564 last_seq = 4207 current_ts = 259.963776 current_received_ts = 259.963226 current_seq = 4208 count = 428 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 259.963776 last_received_ts = 259.963226 last_seq = 4208 current_ts = 259.980438 current_received_ts = 259.979828 current_seq = 4209 count = 429 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 259.980438 last_received_ts = 259.979828 last_seq = 4209 current_ts = 259.997101 current_received_ts = 259.996521 current_seq = 4210 count = 430 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 259.997101 last_received_ts = 259.996521 last_seq = 4210 current_ts = 260.013794 current_received_ts = 260.013214 current_seq = 4211 count = 431 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.013794 last_received_ts = 260.013214 last_seq = 4211 current_ts = 260.030457 current_received_ts = 260.029877 current_seq = 4212 count = 432 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 260.030457 last_received_ts = 260.029877 last_seq = 4212 current_ts = 260.047119 current_received_ts = 260.046570 current_seq = 4213 count = 433 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.047119 last_received_ts = 260.046570 last_seq = 4213 current_ts = 260.063782 current_received_ts = 260.063202 current_seq = 4214 count = 434 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 260.063782 last_received_ts = 260.063202 last_seq = 4214 current_ts = 260.080444 current_received_ts = 260.079865 current_seq = 4215 count = 435 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.080444 last_received_ts = 260.079865 last_seq = 4215 current_ts = 260.097107 current_received_ts = 260.096405 current_seq = 4216 count = 436 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.097107 last_received_ts = 260.096405 last_seq = 4216 current_ts = 260.113770 current_received_ts = 260.113220 current_seq = 4217 count = 437 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.113770 last_received_ts = 260.113220 last_seq = 4217 current_ts = 260.130432 current_received_ts = 260.129822 current_seq = 4218 count = 438 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 260.130432 last_received_ts = 260.129822 last_seq = 4218 current_ts = 260.147095 current_received_ts = 260.146545 current_seq = 4219 count = 439 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 260.147095 last_received_ts = 260.146545 last_seq = 4219 current_ts = 260.163757 current_received_ts = 260.163208 current_seq = 4220 count = 440 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.163757 last_received_ts = 260.163208 last_seq = 4220 current_ts = 260.180420 current_received_ts = 260.179871 current_seq = 4221 count = 441 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 260.180420 last_received_ts = 260.179871 last_seq = 4221 current_ts = 260.197083 current_received_ts = 260.196472 current_seq = 4222 count = 442 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.197083 last_received_ts = 260.196472 last_seq = 4222 current_ts = 260.213745 current_received_ts = 260.213165 current_seq = 4223 count = 443 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 64us (kms_flip:5481) DEBUG: name = flip last_ts = 260.213745 last_received_ts = 260.213165 last_seq = 4223 current_ts = 260.230408 current_received_ts = 260.229889 current_seq = 4224 count = 444 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.230408 last_received_ts = 260.229889 last_seq = 4224 current_ts = 260.247101 current_received_ts = 260.246521 current_seq = 4225 count = 445 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.247101 last_received_ts = 260.246521 last_seq = 4225 current_ts = 260.263763 current_received_ts = 260.263214 current_seq = 4226 count = 446 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.263763 last_received_ts = 260.263214 last_seq = 4226 current_ts = 260.280426 current_received_ts = 260.279755 current_seq = 4227 count = 447 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 260.280426 last_received_ts = 260.279755 last_seq = 4227 current_ts = 260.297089 current_received_ts = 260.296539 current_seq = 4228 count = 448 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.297089 last_received_ts = 260.296539 last_seq = 4228 current_ts = 260.313751 current_received_ts = 260.313171 current_seq = 4229 count = 449 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 260.313751 last_received_ts = 260.313171 last_seq = 4229 current_ts = 260.330414 current_received_ts = 260.329834 current_seq = 4230 count = 450 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 260.330414 last_received_ts = 260.329834 last_seq = 4230 current_ts = 260.347076 current_received_ts = 260.346527 current_seq = 4231 count = 451 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.347076 last_received_ts = 260.346527 last_seq = 4231 current_ts = 260.363739 current_received_ts = 260.363190 current_seq = 4232 count = 452 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 68us (kms_flip:5481) DEBUG: name = flip last_ts = 260.363739 last_received_ts = 260.363190 last_seq = 4232 current_ts = 260.380402 current_received_ts = 260.379852 current_seq = 4233 count = 453 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 260.380402 last_received_ts = 260.379852 last_seq = 4233 current_ts = 260.397064 current_received_ts = 260.396484 current_seq = 4234 count = 454 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.397064 last_received_ts = 260.396484 last_seq = 4234 current_ts = 260.413727 current_received_ts = 260.413177 current_seq = 4235 count = 455 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 260.413727 last_received_ts = 260.413177 last_seq = 4235 current_ts = 260.430389 current_received_ts = 260.429840 current_seq = 4236 count = 456 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.430389 last_received_ts = 260.429840 last_seq = 4236 current_ts = 260.447083 current_received_ts = 260.446503 current_seq = 4237 count = 457 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 69us (kms_flip:5481) DEBUG: name = flip last_ts = 260.447083 last_received_ts = 260.446503 last_seq = 4237 current_ts = 260.463745 current_received_ts = 260.463135 current_seq = 4238 count = 458 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.463745 last_received_ts = 260.463135 last_seq = 4238 current_ts = 260.480408 current_received_ts = 260.479828 current_seq = 4239 count = 459 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.480408 last_received_ts = 260.479828 last_seq = 4239 current_ts = 260.497070 current_received_ts = 260.496521 current_seq = 4240 count = 460 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.497070 last_received_ts = 260.496521 last_seq = 4240 current_ts = 260.513733 current_received_ts = 260.513123 current_seq = 4241 count = 461 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 260.513733 last_received_ts = 260.513123 last_seq = 4241 current_ts = 260.530396 current_received_ts = 260.529816 current_seq = 4242 count = 462 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.530396 last_received_ts = 260.529816 last_seq = 4242 current_ts = 260.547058 current_received_ts = 260.546509 current_seq = 4243 count = 463 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.547058 last_received_ts = 260.546509 last_seq = 4243 current_ts = 260.563721 current_received_ts = 260.563141 current_seq = 4244 count = 464 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 260.563721 last_received_ts = 260.563141 last_seq = 4244 current_ts = 260.580383 current_received_ts = 260.579803 current_seq = 4245 count = 465 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 260.580383 last_received_ts = 260.579803 last_seq = 4245 current_ts = 260.597046 current_received_ts = 260.596466 current_seq = 4246 count = 466 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 260.597046 last_received_ts = 260.596466 last_seq = 4246 current_ts = 260.613708 current_received_ts = 260.613129 current_seq = 4247 count = 467 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.613708 last_received_ts = 260.613129 last_seq = 4247 current_ts = 260.630371 current_received_ts = 260.629822 current_seq = 4248 count = 468 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.630371 last_received_ts = 260.629822 last_seq = 4248 current_ts = 260.647034 current_received_ts = 260.646484 current_seq = 4249 count = 469 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 68us (kms_flip:5481) DEBUG: name = flip last_ts = 260.647034 last_received_ts = 260.646484 last_seq = 4249 current_ts = 260.663727 current_received_ts = 260.663177 current_seq = 4250 count = 470 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.663727 last_received_ts = 260.663177 last_seq = 4250 current_ts = 260.680389 current_received_ts = 260.679810 current_seq = 4251 count = 471 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 65us (kms_flip:5481) DEBUG: name = flip last_ts = 260.680389 last_received_ts = 260.679810 last_seq = 4251 current_ts = 260.697052 current_received_ts = 260.696472 current_seq = 4252 count = 472 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.697052 last_received_ts = 260.696472 last_seq = 4252 current_ts = 260.713715 current_received_ts = 260.713135 current_seq = 4253 count = 473 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 260.713715 last_received_ts = 260.713135 last_seq = 4253 current_ts = 260.730377 current_received_ts = 260.729797 current_seq = 4254 count = 474 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.730377 last_received_ts = 260.729797 last_seq = 4254 current_ts = 260.747040 current_received_ts = 260.746490 current_seq = 4255 count = 475 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 260.747040 last_received_ts = 260.746490 last_seq = 4255 current_ts = 260.763702 current_received_ts = 260.763123 current_seq = 4256 count = 476 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 133us (kms_flip:5481) DEBUG: name = flip last_ts = 260.763702 last_received_ts = 260.763123 last_seq = 4256 current_ts = 260.780365 current_received_ts = 260.779755 current_seq = 4257 count = 477 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 260.780365 last_received_ts = 260.779755 last_seq = 4257 current_ts = 260.797028 current_received_ts = 260.796478 current_seq = 4258 count = 478 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 68us (kms_flip:5481) DEBUG: name = flip last_ts = 260.797028 last_received_ts = 260.796478 last_seq = 4258 current_ts = 260.813690 current_received_ts = 260.813141 current_seq = 4259 count = 479 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.813690 last_received_ts = 260.813141 last_seq = 4259 current_ts = 260.830353 current_received_ts = 260.829803 current_seq = 4260 count = 480 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 45us (kms_flip:5481) DEBUG: name = flip last_ts = 260.830353 last_received_ts = 260.829803 last_seq = 4260 current_ts = 260.847015 current_received_ts = 260.846497 current_seq = 4261 count = 481 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.847015 last_received_ts = 260.846497 last_seq = 4261 current_ts = 260.863678 current_received_ts = 260.863129 current_seq = 4262 count = 482 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.863678 last_received_ts = 260.863129 last_seq = 4262 current_ts = 260.880341 current_received_ts = 260.879791 current_seq = 4263 count = 483 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 260.880341 last_received_ts = 260.879791 last_seq = 4263 current_ts = 260.897034 current_received_ts = 260.896454 current_seq = 4264 count = 484 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 260.897034 last_received_ts = 260.896454 last_seq = 4264 current_ts = 260.913696 current_received_ts = 260.913116 current_seq = 4265 count = 485 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.913696 last_received_ts = 260.913116 last_seq = 4265 current_ts = 260.930359 current_received_ts = 260.929779 current_seq = 4266 count = 486 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 260.930359 last_received_ts = 260.929779 last_seq = 4266 current_ts = 260.947021 current_received_ts = 260.946411 current_seq = 4267 count = 487 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 57us (kms_flip:5481) DEBUG: name = flip last_ts = 260.947021 last_received_ts = 260.946411 last_seq = 4267 current_ts = 260.963684 current_received_ts = 260.963104 current_seq = 4268 count = 488 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 57us (kms_flip:5481) DEBUG: name = flip last_ts = 260.963684 last_received_ts = 260.963104 last_seq = 4268 current_ts = 260.980347 current_received_ts = 260.979767 current_seq = 4269 count = 489 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 60us (kms_flip:5481) DEBUG: name = flip last_ts = 260.980347 last_received_ts = 260.979767 last_seq = 4269 current_ts = 260.997009 current_received_ts = 260.996429 current_seq = 4270 count = 490 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 260.997009 last_received_ts = 260.996429 last_seq = 4270 current_ts = 261.013672 current_received_ts = 261.013092 current_seq = 4271 count = 491 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.013672 last_received_ts = 261.013092 last_seq = 4271 current_ts = 261.030334 current_received_ts = 261.029724 current_seq = 4272 count = 492 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.030334 last_received_ts = 261.029724 last_seq = 4272 current_ts = 261.046997 current_received_ts = 261.046448 current_seq = 4273 count = 493 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 261.046997 last_received_ts = 261.046448 last_seq = 4273 current_ts = 261.063660 current_received_ts = 261.063110 current_seq = 4274 count = 494 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 261.063660 last_received_ts = 261.063110 last_seq = 4274 current_ts = 261.080322 current_received_ts = 261.079773 current_seq = 4275 count = 495 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 261.080322 last_received_ts = 261.079773 last_seq = 4275 current_ts = 261.097015 current_received_ts = 261.096436 current_seq = 4276 count = 496 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 69us (kms_flip:5481) DEBUG: name = flip last_ts = 261.097015 last_received_ts = 261.096436 last_seq = 4276 current_ts = 261.113678 current_received_ts = 261.113098 current_seq = 4277 count = 497 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 69us (kms_flip:5481) DEBUG: name = flip last_ts = 261.113678 last_received_ts = 261.113098 last_seq = 4277 current_ts = 261.130341 current_received_ts = 261.129761 current_seq = 4278 count = 498 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 261.130341 last_received_ts = 261.129761 last_seq = 4278 current_ts = 261.147003 current_received_ts = 261.146423 current_seq = 4279 count = 499 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 261.147003 last_received_ts = 261.146423 last_seq = 4279 current_ts = 261.163666 current_received_ts = 261.163116 current_seq = 4280 count = 500 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 261.163666 last_received_ts = 261.163116 last_seq = 4280 current_ts = 261.180328 current_received_ts = 261.179749 current_seq = 4281 count = 501 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.180328 last_received_ts = 261.179749 last_seq = 4281 current_ts = 261.196991 current_received_ts = 261.196411 current_seq = 4282 count = 502 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 261.196991 last_received_ts = 261.196411 last_seq = 4282 current_ts = 261.213654 current_received_ts = 261.213074 current_seq = 4283 count = 503 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 63us (kms_flip:5481) DEBUG: name = flip last_ts = 261.213654 last_received_ts = 261.213074 last_seq = 4283 current_ts = 261.230316 current_received_ts = 261.229736 current_seq = 4284 count = 504 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 261.230316 last_received_ts = 261.229736 last_seq = 4284 current_ts = 261.246979 current_received_ts = 261.246399 current_seq = 4285 count = 505 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.246979 last_received_ts = 261.246399 last_seq = 4285 current_ts = 261.263641 current_received_ts = 261.263092 current_seq = 4286 count = 506 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 261.263641 last_received_ts = 261.263092 last_seq = 4286 current_ts = 261.280304 current_received_ts = 261.279694 current_seq = 4287 count = 507 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.280304 last_received_ts = 261.279694 last_seq = 4287 current_ts = 261.296997 current_received_ts = 261.296448 current_seq = 4288 count = 508 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 66us (kms_flip:5481) DEBUG: name = flip last_ts = 261.296997 last_received_ts = 261.296448 last_seq = 4288 current_ts = 261.313629 current_received_ts = 261.313080 current_seq = 4289 count = 509 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.313629 last_received_ts = 261.313080 last_seq = 4289 current_ts = 261.330322 current_received_ts = 261.329742 current_seq = 4290 count = 510 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 261.330322 last_received_ts = 261.329742 last_seq = 4290 current_ts = 261.346985 current_received_ts = 261.346405 current_seq = 4291 count = 511 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.346985 last_received_ts = 261.346405 last_seq = 4291 current_ts = 261.363647 current_received_ts = 261.363068 current_seq = 4292 count = 512 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 67us (kms_flip:5481) DEBUG: name = flip last_ts = 261.363647 last_received_ts = 261.363068 last_seq = 4292 current_ts = 261.380310 current_received_ts = 261.379730 current_seq = 4293 count = 513 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 61us (kms_flip:5481) DEBUG: name = flip last_ts = 261.380310 last_received_ts = 261.379730 last_seq = 4293 current_ts = 261.396973 current_received_ts = 261.396393 current_seq = 4294 count = 514 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.396973 last_received_ts = 261.396393 last_seq = 4294 current_ts = 261.413635 current_received_ts = 261.413055 current_seq = 4295 count = 515 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.413635 last_received_ts = 261.413055 last_seq = 4295 current_ts = 261.430298 current_received_ts = 261.429718 current_seq = 4296 count = 516 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.430298 last_received_ts = 261.429718 last_seq = 4296 current_ts = 261.446960 current_received_ts = 261.446411 current_seq = 4297 count = 517 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 62us (kms_flip:5481) DEBUG: name = flip last_ts = 261.446960 last_received_ts = 261.446411 last_seq = 4297 current_ts = 261.463623 current_received_ts = 261.463074 current_seq = 4298 count = 518 seq_step = 1 (kms_flip:5481) DEBUG: Vblank took 1575us (kms_flip:5481) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931: (kms_flip:5481) CRITICAL: Failed assertion: end - start < 500 (kms_flip:5481) igt_core-INFO: Stack trace: (kms_flip:5481) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:5481) igt_core-INFO: #1 ../tests/kms_flip.c:926 run_test_on_crtc_set() (kms_flip:5481) igt_core-INFO: #2 ../tests/kms_flip.c:1919 run_test() (kms_flip:5481) igt_core-INFO: #3 ../tests/kms_flip.c:2183 __igt_unique____real_main2104() (kms_flip:5481) igt_core-INFO: #4 ../tests/kms_flip.c:2104 main() (kms_flip:5481) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:5481) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:5481) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (10.153s)
Dmesg	<6> [251.718587] Console: switching to colour dummy device 80x25 <6> [251.718944] [IGT] kms_flip: executing <7> [251.726711] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] <7> [251.726730] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1] <7> [251.726937] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [251.727061] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected <7> [251.727424] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] <7> [251.727432] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2] <7> [251.727593] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [251.727700] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected <7> [251.728039] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] <7> [251.728044] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3] <7> [251.728182] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [251.728291] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected <7> [251.728835] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] <7> [251.728843] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:393:eDP-1] <7> [251.729317] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00 <7> [251.729638] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [251.729784] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [251.729939] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [251.730134] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [251.730144] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [251.730147] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [251.730150] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [251.730154] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [251.730158] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [251.730161] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD monitor <5> [251.730165] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [251.730168] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD size 20, SAD count 0 <5> [251.730171] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [251.730197] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] VRR capable: yes <7> [251.730349] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [251.730501] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [251.730918] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [251.730923] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [251.730925] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [251.731006] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] probed modes: <7> [251.731013] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [251.731017] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [251.731041] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] <7> [251.731045] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1] <7> [251.731191] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected <7> [251.731206] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] <7> [251.731210] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2] <7> [251.731352] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected <7> [251.731365] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] <7> [251.731368] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3] <7> [251.731500] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected <6> [251.732259] [IGT] kms_flip: starting subtest flip-vs-expired-vblank <6> [251.734388] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [251.763579] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430] <7> [251.782917] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432] <7> [251.859921] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [251.860181] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [251.860600] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [251.861013] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [251.861231] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [251.861437] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 8102230/8388608 link 675185/524288, found tu 0, data 0/0 link 0/0) <7> [251.861635] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [251.862076] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [251.862279] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [251.862458] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [251.862632] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [251.862827] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [251.862994] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [251.863156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [251.863315] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [251.863468] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [251.863618] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [251.863774] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [251.863916] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [251.864055] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [251.864189] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [251.864321] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [251.864449] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [251.864593] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [251.864753] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [251.864875] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [251.864995] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [251.865113] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [251.865229] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [251.865343] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [251.865458] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [251.865581] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [251.865709] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [251.865845] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [251.865954] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [251.866061] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0) <7> [251.866164] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [251.866266] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [251.866380] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 270000, found 0) <7> [251.866496] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [251.866609] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0 <7> [251.866784] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [251.866867] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [251.866974] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [251.867061] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [251.867142] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm <7> [251.867212] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [251.867282] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [251.867350] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [251.867437] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0 <7> [251.867543] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [251.867647] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [251.867762] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [251.867860] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [251.867954] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [251.868047] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [251.868162] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [251.868265] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [251.868353] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [251.868439] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [251.868551] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset] <7> [251.868639] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no <7> [251.868730] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [251.868817] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [251.868912] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [251.869000] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [251.869084] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [251.869199] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [251.869297] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [251.869432] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [251.870090] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [251.870184] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [252.079804] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0 <7> [252.080294] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [252.088099] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off <7> [252.088438] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time <7> [252.088807] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [252.140811] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [252.141206] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short <7> [252.149220] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [252.149657] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A] <7> [252.149805] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [252.151274] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [252.151814] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [252.152332] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [252.152750] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [252.153081] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [252.153408] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [252.153731] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [252.154033] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [252.154330] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [252.154625] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [252.155007] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [252.155298] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [252.155584] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [252.155913] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [252.156198] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [252.156515] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [252.156936] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [252.157221] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [252.157516] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [252.158077] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [252.158476] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000) <7> [252.159041] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [252.159377] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [252.159783] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [252.160056] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [252.160930] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B] <7> [252.161312] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C] <7> [252.161614] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A] <7> [252.161680] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1] <7> [252.161867] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 24 (EDID bpp 30, max requested bpp 24, max platform bpp 36) <7> [252.162206] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 24 min link_bpp 18.0000 max link_bpp 24.0000 <7> [252.162542] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 270000 bpp input 24 compressed 0.0000 HDR no link rate required 1043130 available 1080000 <7> [252.162861] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0 <7> [252.163141] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A] <7> [252.163472] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [252.163739] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [252.164029] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [252.164267] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [252.164489] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 8102230/8388608 link 675185/524288) <7> [252.164719] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [252.164966] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [252.165171] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [252.165365] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [252.165550] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [252.165744] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [252.165919] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [252.166092] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [252.166256] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [252.166420] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [252.166577] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [252.166740] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [252.166894] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [252.167043] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [252.167190] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [252.167333] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [252.167472] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [252.167607] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [252.167756] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [252.167903] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [252.168031] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [252.168162] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [252.168290] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [252.168416] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [252.168539] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [252.168661] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [252.168797] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [252.168915] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [252.169027] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [252.169138] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24) <7> [252.169246] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [252.169350] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [252.169451] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 270000) <7> [252.169552] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset <7> [252.169695] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [252.169796] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [252.169900] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [252.169975] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [252.170049] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> wm0,wm1,wm2,wm3,wm4,wm5, wm6, wm7,twm,swm,stwm <7> [252.170120] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 <7> [252.170192] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 <7> [252.170260] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 <7> [252.170343] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1 <7> [252.170448] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [252.170549] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [252.170649] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [252.170758] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [252.170852] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [252.170944] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [252.171052] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [252.171150] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [252.171248] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [252.171344] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [252.171446] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0 <7> [252.171532] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0 <7> [252.171627] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset] <7> [252.171721] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [252.171810] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 24, dithering: 0 <7> [252.171900] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [252.171988] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [252.172069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [252.172148] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [252.172226] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 8102230, data_n: 8388608, link_m: 675185, link_n: 524288, tu: 64 <7> [252.172304] xe 0000:00:02.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> [252.172380] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [252.172454] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [252.172534] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [252.172613] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0 <7> [252.172686] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [252.172832] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [252.172918] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [252.172999] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [252.173082] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [252.173170] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [252.173255] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [252.173338] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [252.173409] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [252.173482] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97 <7> [252.173556] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906 <7> [252.173629] xe 0000:00:02.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> [252.173713] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [252.173803] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [252.173895] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [252.173977] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [252.174054] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [252.174125] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 270000, pixel rate 347710, min cdclk 173855, min voltage level 0 <7> [252.174196] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [252.174266] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [252.174337] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0 <7> [252.174408] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [252.174483] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [252.174558] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [252.174632] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no <7> [252.174711] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: yes, <7> [252.174793] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] quot: 40960, rem: 0, den: 1, <7> [252.174875] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 140, tx_clk_div: 1. <7> [252.174957] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [252.175034] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [252.175109] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0 <7> [252.175183] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [252.175256] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [252.175330] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [252.175404] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23 <7> [252.175478] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [252.175552] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [252.175624] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [252.175697] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [252.175797] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [252.175888] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [252.175978] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [252.176060] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [252.176144] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [252.176221] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [252.176291] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [252.176362] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [252.176434] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [252.176507] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [252.176579] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [252.176650] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no <7> [252.176727] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no <7> [252.176806] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no <7> [252.176891] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no <7> [252.176969] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no <7> [252.177392] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [252.177533] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000) <7> [252.177631] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [252.177739] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [252.177835] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [252.177927] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A] <7> [252.177937] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [252.178003] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1] <7> [252.178029] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [252.178077] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A] <7> [252.178113] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [252.178147] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B] <7> [252.178212] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C] <7> [252.178277] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2] <7> [252.178293] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [252.178346] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A] <7> [252.178415] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B] <7> [252.178482] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C] <7> [252.178544] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3] <7> [252.178605] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A] <7> [252.178665] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B] <7> [252.178737] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C] <7> [252.178843] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [252.179028] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [252.179106] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [252.179219] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [252.180548] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A] <7> [252.180634] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [252.182659] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on <7> [252.182746] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining) <7> [252.654914] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [252.758902] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [252.758904] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [252.759023] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [252.759097] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [252.759357] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on <7> [252.759761] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [252.795491] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [252.795974] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long <7> [252.796396] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [252.796841] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A] <7> [252.967425] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [252.967853] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on <7> [252.968164] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [252.970196] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80 <7> [252.971727] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [252.972553] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 03 <7> [252.973735] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [252.975108] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [252.976173] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK <7> [252.976532] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [252.978054] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [252.978463] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 270000, lane count = 4 <7> [252.979368] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [252.979881] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [252.980286] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [252.980733] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 192000 <7> [252.996765] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [252.998523] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1] <7> [252.999009] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A] <7> [255.510720] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off <7> [255.511224] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067 <7> [261.680222] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [261.681102] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [261.681853] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [261.888535] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

10.15 seconds

Hostname

shard-lnl-2

Igt-Version

IGT-Version: 2.4-g2a9f1c1ae (x86_64) (Linux: 7.0.0-rc7-lgci-xe-xe-4858-9e217a8df7b2f298a-debug+ x86_64)

Out

Using IGT_SRANDOM=1775592189 for randomisation
Opened device: /dev/dri/card0
Using monotonic timestamps
Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1919 run_test()
  #3 ../tests/kms_flip.c:2183 __igt_unique____real_main2104()
  #4 ../tests/kms_flip.c:2104 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest A-eDP1: FAIL (10.153s)

Err

Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
(kms_flip:5481) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:5481) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.430511
last_received_ts = 259.429932
last_seq = 4176
current_ts = 259.447174
current_received_ts = 259.446594
current_seq = 4177
count = 397
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.447174
last_received_ts = 259.446594
last_seq = 4177
current_ts = 259.463837
current_received_ts = 259.463257
current_seq = 4178
count = 398
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.463837
last_received_ts = 259.463257
last_seq = 4178
current_ts = 259.480499
current_received_ts = 259.479767
current_seq = 4179
count = 399
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.480499
last_received_ts = 259.479767
last_seq = 4179
current_ts = 259.497162
current_received_ts = 259.496582
current_seq = 4180
count = 400
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 68us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.497162
last_received_ts = 259.496582
last_seq = 4180
current_ts = 259.513824
current_received_ts = 259.513245
current_seq = 4181
count = 401
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 68us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.513824
last_received_ts = 259.513245
last_seq = 4181
current_ts = 259.530487
current_received_ts = 259.529877
current_seq = 4182
count = 402
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.530487
last_received_ts = 259.529877
last_seq = 4182
current_ts = 259.547150
current_received_ts = 259.546600
current_seq = 4183
count = 403
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 64us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.547150
last_received_ts = 259.546600
last_seq = 4183
current_ts = 259.563812
current_received_ts = 259.563232
current_seq = 4184
count = 404
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 64us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.563812
last_received_ts = 259.563232
last_seq = 4184
current_ts = 259.580475
current_received_ts = 259.579865
current_seq = 4185
count = 405
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.580475
last_received_ts = 259.579865
last_seq = 4185
current_ts = 259.597168
current_received_ts = 259.596405
current_seq = 4186
count = 406
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 58us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.597168
last_received_ts = 259.596405
last_seq = 4186
current_ts = 259.613831
current_received_ts = 259.613251
current_seq = 4187
count = 407
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.613831
last_received_ts = 259.613251
last_seq = 4187
current_ts = 259.630493
current_received_ts = 259.629852
current_seq = 4188
count = 408
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.630493
last_received_ts = 259.629852
last_seq = 4188
current_ts = 259.647156
current_received_ts = 259.646576
current_seq = 4189
count = 409
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.647156
last_received_ts = 259.646576
last_seq = 4189
current_ts = 259.663818
current_received_ts = 259.663239
current_seq = 4190
count = 410
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.663818
last_received_ts = 259.663239
last_seq = 4190
current_ts = 259.680481
current_received_ts = 259.679840
current_seq = 4191
count = 411
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.680481
last_received_ts = 259.679840
last_seq = 4191
current_ts = 259.697144
current_received_ts = 259.696411
current_seq = 4192
count = 412
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 68us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.697144
last_received_ts = 259.696411
last_seq = 4192
current_ts = 259.713806
current_received_ts = 259.713257
current_seq = 4193
count = 413
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 64us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.713806
last_received_ts = 259.713257
last_seq = 4193
current_ts = 259.730469
current_received_ts = 259.729858
current_seq = 4194
count = 414
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.730469
last_received_ts = 259.729858
last_seq = 4194
current_ts = 259.747131
current_received_ts = 259.746460
current_seq = 4195
count = 415
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 57us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.747131
last_received_ts = 259.746460
last_seq = 4195
current_ts = 259.763794
current_received_ts = 259.763214
current_seq = 4196
count = 416
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.763794
last_received_ts = 259.763214
last_seq = 4196
current_ts = 259.780457
current_received_ts = 259.779907
current_seq = 4197
count = 417
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.780457
last_received_ts = 259.779907
last_seq = 4197
current_ts = 259.797119
current_received_ts = 259.796600
current_seq = 4198
count = 418
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.797119
last_received_ts = 259.796600
last_seq = 4198
current_ts = 259.813812
current_received_ts = 259.813232
current_seq = 4199
count = 419
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 64us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.813812
last_received_ts = 259.813232
last_seq = 4199
current_ts = 259.830475
current_received_ts = 259.829834
current_seq = 4200
count = 420
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 60us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.830475
last_received_ts = 259.829834
last_seq = 4200
current_ts = 259.847137
current_received_ts = 259.846558
current_seq = 4201
count = 421
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.847137
last_received_ts = 259.846558
last_seq = 4201
current_ts = 259.863800
current_received_ts = 259.863220
current_seq = 4202
count = 422
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.863800
last_received_ts = 259.863220
last_seq = 4202
current_ts = 259.880463
current_received_ts = 259.879852
current_seq = 4203
count = 423
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.880463
last_received_ts = 259.879852
last_seq = 4203
current_ts = 259.897125
current_received_ts = 259.896545
current_seq = 4204
count = 424
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.897125
last_received_ts = 259.896545
last_seq = 4204
current_ts = 259.913788
current_received_ts = 259.913208
current_seq = 4205
count = 425
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.913788
last_received_ts = 259.913208
last_seq = 4205
current_ts = 259.930450
current_received_ts = 259.929840
current_seq = 4206
count = 426
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.930450
last_received_ts = 259.929840
last_seq = 4206
current_ts = 259.947113
current_received_ts = 259.946564
current_seq = 4207
count = 427
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.947113
last_received_ts = 259.946564
last_seq = 4207
current_ts = 259.963776
current_received_ts = 259.963226
current_seq = 4208
count = 428
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.963776
last_received_ts = 259.963226
last_seq = 4208
current_ts = 259.980438
current_received_ts = 259.979828
current_seq = 4209
count = 429
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.980438
last_received_ts = 259.979828
last_seq = 4209
current_ts = 259.997101
current_received_ts = 259.996521
current_seq = 4210
count = 430
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 259.997101
last_received_ts = 259.996521
last_seq = 4210
current_ts = 260.013794
current_received_ts = 260.013214
current_seq = 4211
count = 431
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.013794
last_received_ts = 260.013214
last_seq = 4211
current_ts = 260.030457
current_received_ts = 260.029877
current_seq = 4212
count = 432
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.030457
last_received_ts = 260.029877
last_seq = 4212
current_ts = 260.047119
current_received_ts = 260.046570
current_seq = 4213
count = 433
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.047119
last_received_ts = 260.046570
last_seq = 4213
current_ts = 260.063782
current_received_ts = 260.063202
current_seq = 4214
count = 434
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.063782
last_received_ts = 260.063202
last_seq = 4214
current_ts = 260.080444
current_received_ts = 260.079865
current_seq = 4215
count = 435
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.080444
last_received_ts = 260.079865
last_seq = 4215
current_ts = 260.097107
current_received_ts = 260.096405
current_seq = 4216
count = 436
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.097107
last_received_ts = 260.096405
last_seq = 4216
current_ts = 260.113770
current_received_ts = 260.113220
current_seq = 4217
count = 437
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.113770
last_received_ts = 260.113220
last_seq = 4217
current_ts = 260.130432
current_received_ts = 260.129822
current_seq = 4218
count = 438
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.130432
last_received_ts = 260.129822
last_seq = 4218
current_ts = 260.147095
current_received_ts = 260.146545
current_seq = 4219
count = 439
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.147095
last_received_ts = 260.146545
last_seq = 4219
current_ts = 260.163757
current_received_ts = 260.163208
current_seq = 4220
count = 440
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.163757
last_received_ts = 260.163208
last_seq = 4220
current_ts = 260.180420
current_received_ts = 260.179871
current_seq = 4221
count = 441
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.180420
last_received_ts = 260.179871
last_seq = 4221
current_ts = 260.197083
current_received_ts = 260.196472
current_seq = 4222
count = 442
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.197083
last_received_ts = 260.196472
last_seq = 4222
current_ts = 260.213745
current_received_ts = 260.213165
current_seq = 4223
count = 443
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 64us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.213745
last_received_ts = 260.213165
last_seq = 4223
current_ts = 260.230408
current_received_ts = 260.229889
current_seq = 4224
count = 444
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.230408
last_received_ts = 260.229889
last_seq = 4224
current_ts = 260.247101
current_received_ts = 260.246521
current_seq = 4225
count = 445
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.247101
last_received_ts = 260.246521
last_seq = 4225
current_ts = 260.263763
current_received_ts = 260.263214
current_seq = 4226
count = 446
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.263763
last_received_ts = 260.263214
last_seq = 4226
current_ts = 260.280426
current_received_ts = 260.279755
current_seq = 4227
count = 447
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.280426
last_received_ts = 260.279755
last_seq = 4227
current_ts = 260.297089
current_received_ts = 260.296539
current_seq = 4228
count = 448
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.297089
last_received_ts = 260.296539
last_seq = 4228
current_ts = 260.313751
current_received_ts = 260.313171
current_seq = 4229
count = 449
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.313751
last_received_ts = 260.313171
last_seq = 4229
current_ts = 260.330414
current_received_ts = 260.329834
current_seq = 4230
count = 450
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.330414
last_received_ts = 260.329834
last_seq = 4230
current_ts = 260.347076
current_received_ts = 260.346527
current_seq = 4231
count = 451
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.347076
last_received_ts = 260.346527
last_seq = 4231
current_ts = 260.363739
current_received_ts = 260.363190
current_seq = 4232
count = 452
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 68us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.363739
last_received_ts = 260.363190
last_seq = 4232
current_ts = 260.380402
current_received_ts = 260.379852
current_seq = 4233
count = 453
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.380402
last_received_ts = 260.379852
last_seq = 4233
current_ts = 260.397064
current_received_ts = 260.396484
current_seq = 4234
count = 454
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.397064
last_received_ts = 260.396484
last_seq = 4234
current_ts = 260.413727
current_received_ts = 260.413177
current_seq = 4235
count = 455
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.413727
last_received_ts = 260.413177
last_seq = 4235
current_ts = 260.430389
current_received_ts = 260.429840
current_seq = 4236
count = 456
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.430389
last_received_ts = 260.429840
last_seq = 4236
current_ts = 260.447083
current_received_ts = 260.446503
current_seq = 4237
count = 457
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 69us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.447083
last_received_ts = 260.446503
last_seq = 4237
current_ts = 260.463745
current_received_ts = 260.463135
current_seq = 4238
count = 458
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.463745
last_received_ts = 260.463135
last_seq = 4238
current_ts = 260.480408
current_received_ts = 260.479828
current_seq = 4239
count = 459
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.480408
last_received_ts = 260.479828
last_seq = 4239
current_ts = 260.497070
current_received_ts = 260.496521
current_seq = 4240
count = 460
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.497070
last_received_ts = 260.496521
last_seq = 4240
current_ts = 260.513733
current_received_ts = 260.513123
current_seq = 4241
count = 461
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.513733
last_received_ts = 260.513123
last_seq = 4241
current_ts = 260.530396
current_received_ts = 260.529816
current_seq = 4242
count = 462
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.530396
last_received_ts = 260.529816
last_seq = 4242
current_ts = 260.547058
current_received_ts = 260.546509
current_seq = 4243
count = 463
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.547058
last_received_ts = 260.546509
last_seq = 4243
current_ts = 260.563721
current_received_ts = 260.563141
current_seq = 4244
count = 464
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.563721
last_received_ts = 260.563141
last_seq = 4244
current_ts = 260.580383
current_received_ts = 260.579803
current_seq = 4245
count = 465
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.580383
last_received_ts = 260.579803
last_seq = 4245
current_ts = 260.597046
current_received_ts = 260.596466
current_seq = 4246
count = 466
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.597046
last_received_ts = 260.596466
last_seq = 4246
current_ts = 260.613708
current_received_ts = 260.613129
current_seq = 4247
count = 467
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.613708
last_received_ts = 260.613129
last_seq = 4247
current_ts = 260.630371
current_received_ts = 260.629822
current_seq = 4248
count = 468
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.630371
last_received_ts = 260.629822
last_seq = 4248
current_ts = 260.647034
current_received_ts = 260.646484
current_seq = 4249
count = 469
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 68us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.647034
last_received_ts = 260.646484
last_seq = 4249
current_ts = 260.663727
current_received_ts = 260.663177
current_seq = 4250
count = 470
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.663727
last_received_ts = 260.663177
last_seq = 4250
current_ts = 260.680389
current_received_ts = 260.679810
current_seq = 4251
count = 471
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 65us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.680389
last_received_ts = 260.679810
last_seq = 4251
current_ts = 260.697052
current_received_ts = 260.696472
current_seq = 4252
count = 472
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.697052
last_received_ts = 260.696472
last_seq = 4252
current_ts = 260.713715
current_received_ts = 260.713135
current_seq = 4253
count = 473
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.713715
last_received_ts = 260.713135
last_seq = 4253
current_ts = 260.730377
current_received_ts = 260.729797
current_seq = 4254
count = 474
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.730377
last_received_ts = 260.729797
last_seq = 4254
current_ts = 260.747040
current_received_ts = 260.746490
current_seq = 4255
count = 475
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.747040
last_received_ts = 260.746490
last_seq = 4255
current_ts = 260.763702
current_received_ts = 260.763123
current_seq = 4256
count = 476
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 133us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.763702
last_received_ts = 260.763123
last_seq = 4256
current_ts = 260.780365
current_received_ts = 260.779755
current_seq = 4257
count = 477
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.780365
last_received_ts = 260.779755
last_seq = 4257
current_ts = 260.797028
current_received_ts = 260.796478
current_seq = 4258
count = 478
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 68us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.797028
last_received_ts = 260.796478
last_seq = 4258
current_ts = 260.813690
current_received_ts = 260.813141
current_seq = 4259
count = 479
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.813690
last_received_ts = 260.813141
last_seq = 4259
current_ts = 260.830353
current_received_ts = 260.829803
current_seq = 4260
count = 480
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 45us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.830353
last_received_ts = 260.829803
last_seq = 4260
current_ts = 260.847015
current_received_ts = 260.846497
current_seq = 4261
count = 481
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.847015
last_received_ts = 260.846497
last_seq = 4261
current_ts = 260.863678
current_received_ts = 260.863129
current_seq = 4262
count = 482
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.863678
last_received_ts = 260.863129
last_seq = 4262
current_ts = 260.880341
current_received_ts = 260.879791
current_seq = 4263
count = 483
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.880341
last_received_ts = 260.879791
last_seq = 4263
current_ts = 260.897034
current_received_ts = 260.896454
current_seq = 4264
count = 484
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.897034
last_received_ts = 260.896454
last_seq = 4264
current_ts = 260.913696
current_received_ts = 260.913116
current_seq = 4265
count = 485
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.913696
last_received_ts = 260.913116
last_seq = 4265
current_ts = 260.930359
current_received_ts = 260.929779
current_seq = 4266
count = 486
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.930359
last_received_ts = 260.929779
last_seq = 4266
current_ts = 260.947021
current_received_ts = 260.946411
current_seq = 4267
count = 487
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 57us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.947021
last_received_ts = 260.946411
last_seq = 4267
current_ts = 260.963684
current_received_ts = 260.963104
current_seq = 4268
count = 488
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 57us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.963684
last_received_ts = 260.963104
last_seq = 4268
current_ts = 260.980347
current_received_ts = 260.979767
current_seq = 4269
count = 489
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 60us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.980347
last_received_ts = 260.979767
last_seq = 4269
current_ts = 260.997009
current_received_ts = 260.996429
current_seq = 4270
count = 490
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 260.997009
last_received_ts = 260.996429
last_seq = 4270
current_ts = 261.013672
current_received_ts = 261.013092
current_seq = 4271
count = 491
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.013672
last_received_ts = 261.013092
last_seq = 4271
current_ts = 261.030334
current_received_ts = 261.029724
current_seq = 4272
count = 492
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.030334
last_received_ts = 261.029724
last_seq = 4272
current_ts = 261.046997
current_received_ts = 261.046448
current_seq = 4273
count = 493
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.046997
last_received_ts = 261.046448
last_seq = 4273
current_ts = 261.063660
current_received_ts = 261.063110
current_seq = 4274
count = 494
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.063660
last_received_ts = 261.063110
last_seq = 4274
current_ts = 261.080322
current_received_ts = 261.079773
current_seq = 4275
count = 495
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.080322
last_received_ts = 261.079773
last_seq = 4275
current_ts = 261.097015
current_received_ts = 261.096436
current_seq = 4276
count = 496
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 69us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.097015
last_received_ts = 261.096436
last_seq = 4276
current_ts = 261.113678
current_received_ts = 261.113098
current_seq = 4277
count = 497
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 69us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.113678
last_received_ts = 261.113098
last_seq = 4277
current_ts = 261.130341
current_received_ts = 261.129761
current_seq = 4278
count = 498
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.130341
last_received_ts = 261.129761
last_seq = 4278
current_ts = 261.147003
current_received_ts = 261.146423
current_seq = 4279
count = 499
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.147003
last_received_ts = 261.146423
last_seq = 4279
current_ts = 261.163666
current_received_ts = 261.163116
current_seq = 4280
count = 500
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.163666
last_received_ts = 261.163116
last_seq = 4280
current_ts = 261.180328
current_received_ts = 261.179749
current_seq = 4281
count = 501
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.180328
last_received_ts = 261.179749
last_seq = 4281
current_ts = 261.196991
current_received_ts = 261.196411
current_seq = 4282
count = 502
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.196991
last_received_ts = 261.196411
last_seq = 4282
current_ts = 261.213654
current_received_ts = 261.213074
current_seq = 4283
count = 503
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 63us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.213654
last_received_ts = 261.213074
last_seq = 4283
current_ts = 261.230316
current_received_ts = 261.229736
current_seq = 4284
count = 504
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.230316
last_received_ts = 261.229736
last_seq = 4284
current_ts = 261.246979
current_received_ts = 261.246399
current_seq = 4285
count = 505
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.246979
last_received_ts = 261.246399
last_seq = 4285
current_ts = 261.263641
current_received_ts = 261.263092
current_seq = 4286
count = 506
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.263641
last_received_ts = 261.263092
last_seq = 4286
current_ts = 261.280304
current_received_ts = 261.279694
current_seq = 4287
count = 507
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.280304
last_received_ts = 261.279694
last_seq = 4287
current_ts = 261.296997
current_received_ts = 261.296448
current_seq = 4288
count = 508
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 66us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.296997
last_received_ts = 261.296448
last_seq = 4288
current_ts = 261.313629
current_received_ts = 261.313080
current_seq = 4289
count = 509
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.313629
last_received_ts = 261.313080
last_seq = 4289
current_ts = 261.330322
current_received_ts = 261.329742
current_seq = 4290
count = 510
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.330322
last_received_ts = 261.329742
last_seq = 4290
current_ts = 261.346985
current_received_ts = 261.346405
current_seq = 4291
count = 511
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.346985
last_received_ts = 261.346405
last_seq = 4291
current_ts = 261.363647
current_received_ts = 261.363068
current_seq = 4292
count = 512
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 67us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.363647
last_received_ts = 261.363068
last_seq = 4292
current_ts = 261.380310
current_received_ts = 261.379730
current_seq = 4293
count = 513
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 61us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.380310
last_received_ts = 261.379730
last_seq = 4293
current_ts = 261.396973
current_received_ts = 261.396393
current_seq = 4294
count = 514
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.396973
last_received_ts = 261.396393
last_seq = 4294
current_ts = 261.413635
current_received_ts = 261.413055
current_seq = 4295
count = 515
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.413635
last_received_ts = 261.413055
last_seq = 4295
current_ts = 261.430298
current_received_ts = 261.429718
current_seq = 4296
count = 516
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.430298
last_received_ts = 261.429718
last_seq = 4296
current_ts = 261.446960
current_received_ts = 261.446411
current_seq = 4297
count = 517
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 62us
(kms_flip:5481) DEBUG: name = flip
last_ts = 261.446960
last_received_ts = 261.446411
last_seq = 4297
current_ts = 261.463623
current_received_ts = 261.463074
current_seq = 4298
count = 518
seq_step = 1
(kms_flip:5481) DEBUG: Vblank took 1575us
(kms_flip:5481) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:5481) CRITICAL: Failed assertion: end - start < 500
(kms_flip:5481) igt_core-INFO: Stack trace:
(kms_flip:5481) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:5481) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:5481) igt_core-INFO:   #2 ../tests/kms_flip.c:1919 run_test()
(kms_flip:5481) igt_core-INFO:   #3 ../tests/kms_flip.c:2183 __igt_unique____real_main2104()
(kms_flip:5481) igt_core-INFO:   #4 ../tests/kms_flip.c:2104 main()
(kms_flip:5481) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:5481) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:5481) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (10.153s)

Dmesg

<6> [251.718587] Console: switching to colour dummy device 80x25

<6> [251.718944] [IGT] kms_flip: executing

<7> [251.726711] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]

<7> [251.726730] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]

<7> [251.726937] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4

<7> [251.727061] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected

<7> [251.727424] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]

<7> [251.727432] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]

<7> [251.727593] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4

<7> [251.727700] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected

<7> [251.728039] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]

<7> [251.728044] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]

<7> [251.728182] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4

<7> [251.728291] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected

<7> [251.728835] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1]

<7> [251.728843] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:393:eDP-1]

<7> [251.729317] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00

<7> [251.729638] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000

<7> [251.729784] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [251.729939] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000

<7> [251.730134] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz

<5> [251.730144] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [251.730147] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [251.730150] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] DisplayID extension version 0x13, primary use 0x00

<7> [251.730154] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc.

<5> [251.730158] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [251.730161] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD monitor

<5> [251.730165] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [251.730168] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:393:eDP-1] ELD size 20, SAD count 0

<5> [251.730171] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [251.730197] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] VRR capable: yes

<7> [251.730349] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps

<7> [251.730501] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:393:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no

<5> [251.730918] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [251.730923] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<5> [251.730925] [drm] DisplayID checksum invalid, remainder is 248 (ignoring)

<7> [251.731006] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:393:eDP-1] probed modes:

<7> [251.731013] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [251.731017] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

<7> [251.731041] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1]

<7> [251.731045] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:402:DP-1]

<7> [251.731191] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:402:DP-1] disconnected

<7> [251.731206] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2]

<7> [251.731210] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:414:DP-2]

<7> [251.731352] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:414:DP-2] disconnected

<7> [251.731365] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3]

<7> [251.731368] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:422:DP-3]

<7> [251.731500] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:422:DP-3] disconnected

<6> [251.732259] [IGT] kms_flip: starting subtest flip-vs-expired-vblank

<6> [251.734388] [IGT] kms_flip: starting dynamic subtest A-eDP1

<7> [251.763579] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]

<7> [251.782917] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]

<7> [251.859921] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

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

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

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

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

<7> [251.861437] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 8102230/8388608 link 675185/524288, found tu 0, data 0/0 link 0/0)

<7> [251.861635] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000)

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

<7> [251.862279] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0)

<7> [251.862458] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0)

<7> [251.862632] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0)

<7> [251.862827] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0)

<7> [251.862994] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0)

<7> [251.863156] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0)

<7> [251.863315] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0)

<7> [251.863468] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0)

<7> [251.863618] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0)

<7> [251.863774] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0)

<7> [251.863916] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0)

<7> [251.864055] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0)

<7> [251.864189] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0)

<7> [251.864321] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0)

<7> [251.864449] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0)

<7> [251.864593] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0)

<7> [251.864753] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0)

<7> [251.864875] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0)

<7> [251.864995] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0)

<7> [251.865113] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0)

<7> [251.865229] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0)

<7> [251.865343] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0)

<7> [251.865458] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0)

<7> [251.865581] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0)

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

<7> [251.865845] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0)

<7> [251.865954] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0)

<7> [251.866061] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 24, found 0)

<7> [251.866164] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0)

<7> [251.866266] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0)

<7> [251.866380] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 270000, found 0)

<7> [251.866496] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset

<7> [251.866609] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0

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

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

<7> [251.866974] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

<7> [251.867061] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0

<7> [251.867142] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm

<7> [251.867212] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [251.867282] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [251.867350] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

<7> [251.867437] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 0 num active planes 0

<7> [251.867543] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400

<7> [251.867647] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400

<7> [251.867762] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [251.867860] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400

<7> [251.867954] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0

<7> [251.868047] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz

<7> [251.868162] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz

<7> [251.868265] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing

<7> [251.868353] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz

<7> [251.868439] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0

<7> [251.868551] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]

<7> [251.868639] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no

<7> [251.868730] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no

<7> [251.868817] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no

<7> [251.868912] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no

<7> [251.869000] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no

<7> [251.869084] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no

<7> [251.869199] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off

<7> [251.869297] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00

<7> [251.869432] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2

<7> [251.870090] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM

<7> [251.870184] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]

<7> [252.079804] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0

<7> [252.080294] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A

<7> [252.088099] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off

<7> [252.088438] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power off time

<7> [252.088807] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060

<7> [252.140811] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000

<7> [252.141206] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short

<7> [252.149220] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [252.149657] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]

<7> [252.149805] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]

<7> [252.151274] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0

<7> [252.151814] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A

<7> [252.152332] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]

<7> [252.152750] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]

<7> [252.153081] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]

<7> [252.153408] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]

<7> [252.153731] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]

<7> [252.154033] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]

<7> [252.154330] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]

<7> [252.154625] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]

<7> [252.155007] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]

<7> [252.155298] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]

<7> [252.155584] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]

<7> [252.155913] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]

<7> [252.156198] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]

<7> [252.156515] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]

<7> [252.156936] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [252.157221] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)

<7> [252.157516] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1

<7> [252.158077] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A

<7> [252.158476] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating disabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xaa000000)

<7> [252.159041] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

<7> [252.159377] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

<7> [252.159783] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [252.160056] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384

<7> [252.160930] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]

<7> [252.161312] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]

<7> [252.161614] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]

<7> [252.161680] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]

<7> [252.161867] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 24 (EDID bpp 30, max requested bpp 24, max platform bpp 36)

<7> [252.162206] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:151:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 24 min link_bpp 18.0000 max link_bpp 24.0000

<7> [252.162542] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 270000 bpp input 24 compressed 0.0000 HDR no link rate required 1043130 available 1080000

<7> [252.162861] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0

<7> [252.163141] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:151:pipe A]

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

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

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

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

<7> [252.164489] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 8102230/8388608 link 675185/524288)

<7> [252.164719] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)

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

<7> [252.165171] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)

<7> [252.165365] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)

<7> [252.165550] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)

<7> [252.165744] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)

<7> [252.165919] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)

<7> [252.166092] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)

<7> [252.166256] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)

<7> [252.166420] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)

<7> [252.166577] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)

<7> [252.166740] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)

<7> [252.166894] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)

<7> [252.167043] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)

<7> [252.167190] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)

<7> [252.167333] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)

<7> [252.167472] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)

<7> [252.167607] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)

<7> [252.167756] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)

<7> [252.167903] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)

<7> [252.168031] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)

<7> [252.168162] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)

<7> [252.168290] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)

<7> [252.168416] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)

<7> [252.168539] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)

<7> [252.168661] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)

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

<7> [252.168915] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)

<7> [252.169027] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)

<7> [252.169138] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)

<7> [252.169246] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)

<7> [252.169350] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)

<7> [252.169451] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 270000)

<7> [252.169552] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset

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

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

<7> [252.169900] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

<7> [252.169975] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45

<7> [252.170049] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm

<7> [252.170120] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0

<7> [252.170192] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197

<7> [252.170260] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198

<7> [252.170343] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:151:pipe A] data rate 1390840 num active planes 1

<7> [252.170448] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400

<7> [252.170549] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400

<7> [252.170649] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [252.170758] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400

<7> [252.170852] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461

<7> [252.170944] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 173855 kHz

<7> [252.171052] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz

<7> [252.171150] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing

<7> [252.171248] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz

<7> [252.171344] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0

<7> [252.171446] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:151:pipe A] allocated DPLL 0

<7> [252.171532] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:151:pipe A] reserving DPLL 0

<7> [252.171627] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: yes [modeset]

<7> [252.171721] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB

<7> [252.171810] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 24, dithering: 0

<7> [252.171900] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>

<7> [252.171988] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0

<7> [252.172069] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0

<7> [252.172148] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0

<7> [252.172226] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 8102230, data_n: 8388608, link_m: 675185, link_n: 524288, tu: 64

<7> [252.172304] xe 0000:00:02.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> [252.172380] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

<7> [252.172454] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled

<7> [252.172534] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled

<7> [252.172613] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0

<7> [252.172686] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4

<7> [252.172832] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14

<7> [252.172918] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB

<7> [252.172999] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB

<7> [252.173082] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0

<7> [252.173170] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range

<7> [252.173255] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined

<7> [252.173338] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1

<7> [252.173409] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0

<7> [252.173482] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97

<7> [252.173556] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906

<7> [252.173629] xe 0000:00:02.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> [252.173713] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [252.173803] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa

<7> [252.173895] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [252.173977] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa

<7> [252.174054] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa

<7> [252.174125] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 270000, pixel rate 347710, min cdclk 173855, min voltage level 0

<7> [252.174196] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0

<7> [252.174266] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0

<7> [252.174337] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0

<7> [252.174408] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no

<7> [252.174483] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0

<7> [252.174558] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0

<7> [252.174632] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no

<7> [252.174711] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: yes,

<7> [252.174793] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] quot: 40960, rem: 0, den: 1,

<7> [252.174875] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 140, tx_clk_div: 1.

<7> [252.174957] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:

<7> [252.175034] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21

<7> [252.175109] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0xf4, pll[1] = 0x0, pll[2] = 0xf8, pll[3] = 0x0

<7> [252.175183] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0

<7> [252.175256] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0

<7> [252.175330] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0xa0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1

<7> [252.175404] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x84, pll[17] = 0x4f, pll[18] = 0xe5, pll[19] = 0x23

<7> [252.175478] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0

<7> [252.175552] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries

<7> [252.175624] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000

<7> [252.175697] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [252.175797] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [252.175888] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000

<7> [252.175978] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000

<7> [252.176060] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000

<7> [252.176144] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [252.176221] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [252.176291] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000

<7> [252.176362] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000

<7> [252.176434] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes

<7> [252.176507] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0

<7> [252.176579] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0

<7> [252.176650] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no

<7> [252.176727] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no

<7> [252.176806] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no

<7> [252.176891] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no

<7> [252.176969] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no

<7> [252.177392] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A

<7> [252.177533] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x1 (CLKGATE_DIS_DSSDSC=0xa8000000)

<7> [252.177631] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0

<7> [252.177739] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)

<7> [252.177835] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480

<7> [252.177927] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]

<7> [252.177937] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

<7> [252.178003] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]

<7> [252.178029] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long

<7> [252.178077] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]

<7> [252.178113] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10

<7> [252.178147] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]

<7> [252.178212] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]

<7> [252.178277] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]

<7> [252.178293] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]

<7> [252.178346] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]

<7> [252.178415] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]

<7> [252.178482] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]

<7> [252.178544] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]

<7> [252.178605] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]

<7> [252.178665] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]

<7> [252.178737] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]

<7> [252.178843] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf

<7> [252.179028] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)

<7> [252.179106] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)

<7> [252.179219] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A

<7> [252.180548] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:151:pipe A]

<7> [252.180634] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0

<7> [252.182659] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on

<7> [252.182746] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (467 ms remaining)

<7> [252.654914] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060

<7> [252.758902] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [252.758904] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [252.759023] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [252.759097] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4

<7> [252.759357] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power on

<7> [252.759761] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063

<7> [252.795491] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010

<7> [252.795974] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long

<7> [252.796396] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20

<7> [252.796841] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]

<7> [252.967425] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete

<7> [252.967853] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on

<7> [252.968164] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b

<7> [252.970196] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80

<7> [252.971727] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Reloading eDP link rates

<7> [252.972553] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 03

<7> [252.973735] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0

<7> [252.975108] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS1

<7> [252.976173] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Clock recovery OK

<7> [252.976532] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Using DP training pattern TPS4

<7> [252.978054] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful

<7> [252.978463] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:393:eDP-1][ENCODER:392:DDI A/PHY A][DPRX] Link Training passed at link rate = 270000, lane count = 4

<7> [252.979368] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A

<7> [252.979881] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]

<7> [252.980286] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A

<7> [252.980733] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 192000

<7> [252.996765] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2

<7> [252.998523] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]

<7> [252.999009] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]

<7> [255.510720] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD off

<7> [255.511224] xe 0000:00:02.0: [drm:intel_pps_vdd_off_sync_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x00000067

<7> [261.680222] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off

<7> [261.681102] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6

<7> [261.681853] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02

<6> [261.888535] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Results for igt@kms_flip@flip-vs-expired-vblank@a-edp1