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

Result: Fail

i915_display_info15 igt_runner15 results15.json results15-xe-load.json guc_logs15.tar i915_display_info_post_exec15 serial_data15 boot15 dmesg15

DetailValue
Duration 7.60 seconds
Hostname 
shard-lnl-1
Igt-Version 
IGT-Version: 2.4-g6eb4c17a1 (x86_64) (Linux: 7.1.0-rc3-lgci-xe-xe-5051-45be122deb2eaa128-debug+ x86_64)
Out 
Starting dynamic subtest: B-eDP1
  2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
Stack trace:
  #0 ../lib/igt_core.c:2074 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-eDP1: FAIL (7.599s)
Err 
Starting dynamic subtest: B-eDP1
[230.083611] (kms_flip:4481) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[230.083679] (kms_flip:4481) CRITICAL: Failed assertion: end - start < 500
[230.083716] (kms_flip:4481) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest B-eDP1 failed.
**** DEBUG ****
[228.066634] (kms_flip:4481) DEBUG: Vblank took 42us
[228.083237] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.388275
last_received_ts = 229.387466
last_seq = 259
current_ts = 229.404953
current_received_ts = 229.404114
current_seq = 260
count = 255
seq_step = 1
[228.083280] (kms_flip:4481) DEBUG: Vblank took 41us
[228.099937] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.404953
last_received_ts = 229.404114
last_seq = 260
current_ts = 229.421616
current_received_ts = 229.420822
current_seq = 261
count = 256
seq_step = 1
[228.099979] (kms_flip:4481) DEBUG: Vblank took 39us
[228.116580] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.421616
last_received_ts = 229.420822
last_seq = 261
current_ts = 229.438278
current_received_ts = 229.437469
current_seq = 262
count = 257
seq_step = 1
[228.116623] (kms_flip:4481) DEBUG: Vblank took 41us
[228.133235] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.438278
last_received_ts = 229.437469
last_seq = 262
current_ts = 229.454941
current_received_ts = 229.454117
current_seq = 263
count = 258
seq_step = 1
[228.133277] (kms_flip:4481) DEBUG: Vblank took 40us
[228.149935] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.454941
last_received_ts = 229.454117
last_seq = 263
current_ts = 229.471603
current_received_ts = 229.470810
current_seq = 264
count = 259
seq_step = 1
[228.149978] (kms_flip:4481) DEBUG: Vblank took 40us
[228.166573] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.471603
last_received_ts = 229.470810
last_seq = 264
current_ts = 229.488266
current_received_ts = 229.487457
current_seq = 265
count = 260
seq_step = 1
[228.166618] (kms_flip:4481) DEBUG: Vblank took 44us
[228.183219] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.488266
last_received_ts = 229.487457
last_seq = 265
current_ts = 229.504944
current_received_ts = 229.504105
current_seq = 266
count = 261
seq_step = 1
[228.183259] (kms_flip:4481) DEBUG: Vblank took 38us
[228.199883] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.504944
last_received_ts = 229.504105
last_seq = 266
current_ts = 229.521591
current_received_ts = 229.520767
current_seq = 267
count = 262
seq_step = 1
[228.199924] (kms_flip:4481) DEBUG: Vblank took 39us
[228.216528] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.521591
last_received_ts = 229.520767
last_seq = 267
current_ts = 229.538269
current_received_ts = 229.537415
current_seq = 268
count = 263
seq_step = 1
[228.216570] (kms_flip:4481) DEBUG: Vblank took 39us
[228.233206] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.538269
last_received_ts = 229.537415
last_seq = 268
current_ts = 229.554932
current_received_ts = 229.554092
current_seq = 269
count = 264
seq_step = 1
[228.233250] (kms_flip:4481) DEBUG: Vblank took 42us
[228.249875] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.554932
last_received_ts = 229.554092
last_seq = 269
current_ts = 229.571594
current_received_ts = 229.570755
current_seq = 270
count = 265
seq_step = 1
[228.249921] (kms_flip:4481) DEBUG: Vblank took 43us
[228.266539] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.571594
last_received_ts = 229.570755
last_seq = 270
current_ts = 229.588257
current_received_ts = 229.587433
current_seq = 271
count = 266
seq_step = 1
[228.266584] (kms_flip:4481) DEBUG: Vblank took 43us
[228.283200] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.588257
last_received_ts = 229.587433
last_seq = 271
current_ts = 229.604919
current_received_ts = 229.604080
current_seq = 272
count = 267
seq_step = 1
[228.283242] (kms_flip:4481) DEBUG: Vblank took 40us
[228.299863] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.604919
last_received_ts = 229.604080
last_seq = 272
current_ts = 229.621582
current_received_ts = 229.620758
current_seq = 273
count = 268
seq_step = 1
[228.299905] (kms_flip:4481) DEBUG: Vblank took 41us
[228.316528] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.621582
last_received_ts = 229.620758
last_seq = 273
current_ts = 229.638245
current_received_ts = 229.637421
current_seq = 274
count = 269
seq_step = 1
[228.316571] (kms_flip:4481) DEBUG: Vblank took 41us
[228.333193] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.638245
last_received_ts = 229.637421
last_seq = 274
current_ts = 229.654907
current_received_ts = 229.654083
current_seq = 275
count = 270
seq_step = 1
[228.333237] (kms_flip:4481) DEBUG: Vblank took 42us
[228.349845] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.654907
last_received_ts = 229.654083
last_seq = 275
current_ts = 229.671570
current_received_ts = 229.670731
current_seq = 276
count = 271
seq_step = 1
[228.349885] (kms_flip:4481) DEBUG: Vblank took 39us
[228.366513] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.671570
last_received_ts = 229.670731
last_seq = 276
current_ts = 229.688248
current_received_ts = 229.687408
current_seq = 277
count = 272
seq_step = 1
[228.366556] (kms_flip:4481) DEBUG: Vblank took 42us
[228.383203] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.688248
last_received_ts = 229.687408
last_seq = 277
current_ts = 229.704910
current_received_ts = 229.704086
current_seq = 278
count = 273
seq_step = 1
[228.383260] (kms_flip:4481) DEBUG: Vblank took 55us
[228.399878] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.704910
last_received_ts = 229.704086
last_seq = 278
current_ts = 229.721573
current_received_ts = 229.720764
current_seq = 279
count = 274
seq_step = 1
[228.399937] (kms_flip:4481) DEBUG: Vblank took 56us
[228.416559] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.721573
last_received_ts = 229.720764
last_seq = 279
current_ts = 229.738235
current_received_ts = 229.737457
current_seq = 280
count = 275
seq_step = 1
[228.416703] (kms_flip:4481) DEBUG: Vblank took 141us
[228.433191] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.738235
last_received_ts = 229.737457
last_seq = 280
current_ts = 229.754898
current_received_ts = 229.754089
current_seq = 281
count = 276
seq_step = 1
[228.433235] (kms_flip:4481) DEBUG: Vblank took 42us
[228.449991] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.754898
last_received_ts = 229.754089
last_seq = 281
current_ts = 229.771561
current_received_ts = 229.770889
current_seq = 282
count = 277
seq_step = 1
[228.450033] (kms_flip:4481) DEBUG: Vblank took 39us
[228.466646] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.771561
last_received_ts = 229.770889
last_seq = 282
current_ts = 229.788223
current_received_ts = 229.787537
current_seq = 283
count = 278
seq_step = 1
[228.466685] (kms_flip:4481) DEBUG: Vblank took 36us
[228.483278] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.788223
last_received_ts = 229.787537
last_seq = 283
current_ts = 229.804901
current_received_ts = 229.804169
current_seq = 284
count = 279
seq_step = 1
[228.483320] (kms_flip:4481) DEBUG: Vblank took 40us
[228.499969] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.804901
last_received_ts = 229.804169
last_seq = 284
current_ts = 229.821548
current_received_ts = 229.820862
current_seq = 285
count = 280
seq_step = 1
[228.500098] (kms_flip:4481) DEBUG: Vblank took 127us
[228.516618] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.821548
last_received_ts = 229.820862
last_seq = 285
current_ts = 229.838226
current_received_ts = 229.837509
current_seq = 286
count = 281
seq_step = 1
[228.516673] (kms_flip:4481) DEBUG: Vblank took 53us
[228.533273] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.838226
last_received_ts = 229.837509
last_seq = 286
current_ts = 229.854889
current_received_ts = 229.854172
current_seq = 287
count = 282
seq_step = 1
[228.533315] (kms_flip:4481) DEBUG: Vblank took 40us
[228.549947] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.854889
last_received_ts = 229.854172
last_seq = 287
current_ts = 229.871552
current_received_ts = 229.870850
current_seq = 288
count = 283
seq_step = 1
[228.549987] (kms_flip:4481) DEBUG: Vblank took 38us
[228.566643] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.871552
last_received_ts = 229.870850
last_seq = 288
current_ts = 229.888214
current_received_ts = 229.887543
current_seq = 289
count = 284
seq_step = 1
[228.566780] (kms_flip:4481) DEBUG: Vblank took 135us
[228.583250] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.888214
last_received_ts = 229.887543
last_seq = 289
current_ts = 229.904877
current_received_ts = 229.904144
current_seq = 290
count = 285
seq_step = 1
[228.583293] (kms_flip:4481) DEBUG: Vblank took 42us
[228.599948] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.904877
last_received_ts = 229.904144
last_seq = 290
current_ts = 229.921539
current_received_ts = 229.920853
current_seq = 291
count = 286
seq_step = 1
[228.600000] (kms_flip:4481) DEBUG: Vblank took 50us
[228.616574] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.921539
last_received_ts = 229.920853
last_seq = 291
current_ts = 229.938217
current_received_ts = 229.937469
current_seq = 292
count = 287
seq_step = 1
[228.616702] (kms_flip:4481) DEBUG: Vblank took 126us
[228.633257] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.938217
last_received_ts = 229.937469
last_seq = 292
current_ts = 229.954880
current_received_ts = 229.954163
current_seq = 293
count = 288
seq_step = 1
[228.633310] (kms_flip:4481) DEBUG: Vblank took 51us
[228.649947] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.954880
last_received_ts = 229.954163
last_seq = 293
current_ts = 229.971542
current_received_ts = 229.970840
current_seq = 294
count = 289
seq_step = 1
[228.650086] (kms_flip:4481) DEBUG: Vblank took 138us
[228.666600] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.971542
last_received_ts = 229.970840
last_seq = 294
current_ts = 229.988205
current_received_ts = 229.987503
current_seq = 295
count = 290
seq_step = 1
[228.666643] (kms_flip:4481) DEBUG: Vblank took 41us
[228.683265] (kms_flip:4481) DEBUG: name = flip
last_ts = 229.988205
last_received_ts = 229.987503
last_seq = 295
current_ts = 230.004868
current_received_ts = 230.004166
current_seq = 296
count = 291
seq_step = 1
[228.683321] (kms_flip:4481) DEBUG: Vblank took 53us
[228.699950] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.004868
last_received_ts = 230.004166
last_seq = 296
current_ts = 230.021545
current_received_ts = 230.020844
current_seq = 297
count = 292
seq_step = 1
[228.700002] (kms_flip:4481) DEBUG: Vblank took 50us
[228.716607] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.021545
last_received_ts = 230.020844
last_seq = 297
current_ts = 230.038193
current_received_ts = 230.037506
current_seq = 298
count = 293
seq_step = 1
[228.716660] (kms_flip:4481) DEBUG: Vblank took 52us
[228.733250] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.038193
last_received_ts = 230.037506
last_seq = 298
current_ts = 230.054871
current_received_ts = 230.054153
current_seq = 299
count = 294
seq_step = 1
[228.733295] (kms_flip:4481) DEBUG: Vblank took 42us
[228.749945] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.054871
last_received_ts = 230.054153
last_seq = 299
current_ts = 230.071533
current_received_ts = 230.070847
current_seq = 300
count = 295
seq_step = 1
[228.749989] (kms_flip:4481) DEBUG: Vblank took 42us
[228.766544] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.071533
last_received_ts = 230.070847
last_seq = 300
current_ts = 230.088196
current_received_ts = 230.087448
current_seq = 301
count = 296
seq_step = 1
[228.766711] (kms_flip:4481) DEBUG: Vblank took 161us
[228.783258] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.088196
last_received_ts = 230.087448
last_seq = 301
current_ts = 230.104858
current_received_ts = 230.104156
current_seq = 302
count = 297
seq_step = 1
[228.783313] (kms_flip:4481) DEBUG: Vblank took 50us
[228.799856] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.104858
last_received_ts = 230.104156
last_seq = 302
current_ts = 230.121521
current_received_ts = 230.120758
current_seq = 303
count = 298
seq_step = 1
[228.799999] (kms_flip:4481) DEBUG: Vblank took 141us
[228.816592] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.121521
last_received_ts = 230.120758
last_seq = 303
current_ts = 230.138184
current_received_ts = 230.137497
current_seq = 304
count = 299
seq_step = 1
[228.816634] (kms_flip:4481) DEBUG: Vblank took 40us
[228.833221] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.138184
last_received_ts = 230.137497
last_seq = 304
current_ts = 230.154846
current_received_ts = 230.154129
current_seq = 305
count = 300
seq_step = 1
[228.833265] (kms_flip:4481) DEBUG: Vblank took 42us
[228.849920] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.154846
last_received_ts = 230.154129
last_seq = 305
current_ts = 230.171509
current_received_ts = 230.170822
current_seq = 306
count = 301
seq_step = 1
[228.850054] (kms_flip:4481) DEBUG: Vblank took 131us
[228.866590] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.171509
last_received_ts = 230.170822
last_seq = 306
current_ts = 230.188187
current_received_ts = 230.187500
current_seq = 307
count = 302
seq_step = 1
[228.866632] (kms_flip:4481) DEBUG: Vblank took 40us
[228.883217] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.188187
last_received_ts = 230.187500
last_seq = 307
current_ts = 230.204849
current_received_ts = 230.204117
current_seq = 308
count = 303
seq_step = 1
[228.883260] (kms_flip:4481) DEBUG: Vblank took 41us
[228.899899] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.204849
last_received_ts = 230.204117
last_seq = 308
current_ts = 230.221512
current_received_ts = 230.220810
current_seq = 309
count = 304
seq_step = 1
[228.899941] (kms_flip:4481) DEBUG: Vblank took 39us
[228.916553] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.221512
last_received_ts = 230.220810
last_seq = 309
current_ts = 230.238174
current_received_ts = 230.237457
current_seq = 310
count = 305
seq_step = 1
[228.916589] (kms_flip:4481) DEBUG: Vblank took 33us
[228.933210] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.238174
last_received_ts = 230.237457
last_seq = 310
current_ts = 230.254837
current_received_ts = 230.254120
current_seq = 311
count = 306
seq_step = 1
[228.933251] (kms_flip:4481) DEBUG: Vblank took 39us
[228.949893] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.254837
last_received_ts = 230.254120
last_seq = 311
current_ts = 230.271500
current_received_ts = 230.270798
current_seq = 312
count = 307
seq_step = 1
[228.949934] (kms_flip:4481) DEBUG: Vblank took 39us
[228.966555] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.271500
last_received_ts = 230.270798
last_seq = 312
current_ts = 230.288162
current_received_ts = 230.287460
current_seq = 313
count = 308
seq_step = 1
[228.966684] (kms_flip:4481) DEBUG: Vblank took 127us
[228.983192] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.288162
last_received_ts = 230.287460
last_seq = 313
current_ts = 230.304840
current_received_ts = 230.304108
current_seq = 314
count = 309
seq_step = 1
[228.983238] (kms_flip:4481) DEBUG: Vblank took 43us
[228.999889] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.304840
last_received_ts = 230.304108
last_seq = 314
current_ts = 230.321503
current_received_ts = 230.320801
current_seq = 315
count = 310
seq_step = 1
[229.000015] (kms_flip:4481) DEBUG: Vblank took 122us
[229.016559] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.321503
last_received_ts = 230.320801
last_seq = 315
current_ts = 230.338165
current_received_ts = 230.337463
current_seq = 316
count = 311
seq_step = 1
[229.016602] (kms_flip:4481) DEBUG: Vblank took 40us
[229.033196] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.338165
last_received_ts = 230.337463
last_seq = 316
current_ts = 230.354828
current_received_ts = 230.354111
current_seq = 317
count = 312
seq_step = 1
[229.033243] (kms_flip:4481) DEBUG: Vblank took 44us
[229.049864] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.354828
last_received_ts = 230.354111
last_seq = 317
current_ts = 230.371490
current_received_ts = 230.370773
current_seq = 318
count = 313
seq_step = 1
[229.049907] (kms_flip:4481) DEBUG: Vblank took 41us
[229.066552] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.371490
last_received_ts = 230.370773
last_seq = 318
current_ts = 230.388153
current_received_ts = 230.387466
current_seq = 319
count = 314
seq_step = 1
[229.066594] (kms_flip:4481) DEBUG: Vblank took 40us
[229.083172] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.388153
last_received_ts = 230.387466
last_seq = 319
current_ts = 230.404816
current_received_ts = 230.404083
current_seq = 320
count = 315
seq_step = 1
[229.083214] (kms_flip:4481) DEBUG: Vblank took 39us
[229.099874] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.404816
last_received_ts = 230.404083
last_seq = 320
current_ts = 230.421478
current_received_ts = 230.420792
current_seq = 321
count = 316
seq_step = 1
[229.099926] (kms_flip:4481) DEBUG: Vblank took 49us
[229.116477] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.421478
last_received_ts = 230.420792
last_seq = 321
current_ts = 230.438141
current_received_ts = 230.437393
current_seq = 322
count = 317
seq_step = 1
[229.116589] (kms_flip:4481) DEBUG: Vblank took 109us
[229.133168] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.438141
last_received_ts = 230.437393
last_seq = 322
current_ts = 230.454819
current_received_ts = 230.454086
current_seq = 323
count = 318
seq_step = 1
[229.133211] (kms_flip:4481) DEBUG: Vblank took 42us
[229.149744] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.454819
last_received_ts = 230.454086
last_seq = 323
current_ts = 230.471481
current_received_ts = 230.470657
current_seq = 324
count = 319
seq_step = 1
[229.149784] (kms_flip:4481) DEBUG: Vblank took 39us
[229.166507] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.471481
last_received_ts = 230.470657
last_seq = 324
current_ts = 230.488144
current_received_ts = 230.487427
current_seq = 325
count = 320
seq_step = 1
[229.166552] (kms_flip:4481) DEBUG: Vblank took 43us
[229.183165] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.488144
last_received_ts = 230.487427
last_seq = 325
current_ts = 230.504807
current_received_ts = 230.504089
current_seq = 326
count = 321
seq_step = 1
[229.183209] (kms_flip:4481) DEBUG: Vblank took 42us
[229.199791] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.504807
last_received_ts = 230.504089
last_seq = 326
current_ts = 230.521469
current_received_ts = 230.520706
current_seq = 327
count = 322
seq_step = 1
[229.199932] (kms_flip:4481) DEBUG: Vblank took 139us
[229.216480] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.521469
last_received_ts = 230.520706
last_seq = 327
current_ts = 230.538132
current_received_ts = 230.537399
current_seq = 328
count = 323
seq_step = 1
[229.216524] (kms_flip:4481) DEBUG: Vblank took 41us
[229.233165] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.538132
last_received_ts = 230.537399
last_seq = 328
current_ts = 230.554810
current_received_ts = 230.554077
current_seq = 329
count = 324
seq_step = 1
[229.233212] (kms_flip:4481) DEBUG: Vblank took 45us
[229.249727] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.554810
last_received_ts = 230.554077
last_seq = 329
current_ts = 230.571472
current_received_ts = 230.570648
current_seq = 330
count = 325
seq_step = 1
[229.249768] (kms_flip:4481) DEBUG: Vblank took 38us
[229.266499] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.571472
last_received_ts = 230.570648
last_seq = 330
current_ts = 230.588135
current_received_ts = 230.587418
current_seq = 331
count = 326
seq_step = 1
[229.266542] (kms_flip:4481) DEBUG: Vblank took 40us
[229.283150] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.588135
last_received_ts = 230.587418
last_seq = 331
current_ts = 230.604797
current_received_ts = 230.604065
current_seq = 332
count = 327
seq_step = 1
[229.283197] (kms_flip:4481) DEBUG: Vblank took 45us
[229.299759] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.604797
last_received_ts = 230.604065
last_seq = 332
current_ts = 230.621460
current_received_ts = 230.620682
current_seq = 333
count = 328
seq_step = 1
[229.299799] (kms_flip:4481) DEBUG: Vblank took 39us
[229.316484] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.621460
last_received_ts = 230.620682
last_seq = 333
current_ts = 230.638123
current_received_ts = 230.637405
current_seq = 334
count = 329
seq_step = 1
[229.316523] (kms_flip:4481) DEBUG: Vblank took 38us
[229.333141] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.638123
last_received_ts = 230.637405
last_seq = 334
current_ts = 230.654785
current_received_ts = 230.654068
current_seq = 335
count = 330
seq_step = 1
[229.333185] (kms_flip:4481) DEBUG: Vblank took 42us
[229.349843] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.654785
last_received_ts = 230.654068
last_seq = 335
current_ts = 230.671448
current_received_ts = 230.670761
current_seq = 336
count = 331
seq_step = 1
[229.349884] (kms_flip:4481) DEBUG: Vblank took 38us
[229.366478] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.671448
last_received_ts = 230.670761
last_seq = 336
current_ts = 230.688110
current_received_ts = 230.687408
current_seq = 337
count = 332
seq_step = 1
[229.366519] (kms_flip:4481) DEBUG: Vblank took 39us
[229.383132] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.688110
last_received_ts = 230.687408
last_seq = 337
current_ts = 230.704788
current_received_ts = 230.704056
current_seq = 338
count = 333
seq_step = 1
[229.383171] (kms_flip:4481) DEBUG: Vblank took 37us
[229.399813] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.704788
last_received_ts = 230.704056
last_seq = 338
current_ts = 230.721451
current_received_ts = 230.720734
current_seq = 339
count = 334
seq_step = 1
[229.399929] (kms_flip:4481) DEBUG: Vblank took 114us
[229.416468] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.721451
last_received_ts = 230.720734
last_seq = 339
current_ts = 230.738113
current_received_ts = 230.737396
current_seq = 340
count = 335
seq_step = 1
[229.416581] (kms_flip:4481) DEBUG: Vblank took 112us
[229.433125] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.738113
last_received_ts = 230.737396
last_seq = 340
current_ts = 230.754776
current_received_ts = 230.754044
current_seq = 341
count = 336
seq_step = 1
[229.433169] (kms_flip:4481) DEBUG: Vblank took 41us
[229.449725] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.754776
last_received_ts = 230.754044
last_seq = 341
current_ts = 230.771439
current_received_ts = 230.770645
current_seq = 342
count = 337
seq_step = 1
[229.449766] (kms_flip:4481) DEBUG: Vblank took 39us
[229.466485] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.771439
last_received_ts = 230.770645
last_seq = 342
current_ts = 230.788101
current_received_ts = 230.787415
current_seq = 343
count = 338
seq_step = 1
[229.466610] (kms_flip:4481) DEBUG: Vblank took 122us
[229.483115] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.788101
last_received_ts = 230.787415
last_seq = 343
current_ts = 230.804764
current_received_ts = 230.804047
current_seq = 344
count = 339
seq_step = 1
[229.483156] (kms_flip:4481) DEBUG: Vblank took 39us
[229.499794] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.804764
last_received_ts = 230.804047
last_seq = 344
current_ts = 230.821426
current_received_ts = 230.820724
current_seq = 345
count = 340
seq_step = 1
[229.499833] (kms_flip:4481) DEBUG: Vblank took 38us
[229.516479] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.821426
last_received_ts = 230.820724
last_seq = 345
current_ts = 230.838104
current_received_ts = 230.837402
current_seq = 346
count = 341
seq_step = 1
[229.516523] (kms_flip:4481) DEBUG: Vblank took 42us
[229.533119] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.838104
last_received_ts = 230.837402
last_seq = 346
current_ts = 230.854767
current_received_ts = 230.854050
current_seq = 347
count = 342
seq_step = 1
[229.533161] (kms_flip:4481) DEBUG: Vblank took 39us
[229.549803] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.854767
last_received_ts = 230.854050
last_seq = 347
current_ts = 230.871429
current_received_ts = 230.870728
current_seq = 348
count = 343
seq_step = 1
[229.549844] (kms_flip:4481) DEBUG: Vblank took 39us
[229.566465] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.871429
last_received_ts = 230.870728
last_seq = 348
current_ts = 230.888092
current_received_ts = 230.887390
current_seq = 349
count = 344
seq_step = 1
[229.566511] (kms_flip:4481) DEBUG: Vblank took 44us
[229.583117] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.888092
last_received_ts = 230.887390
last_seq = 349
current_ts = 230.904755
current_received_ts = 230.904053
current_seq = 350
count = 345
seq_step = 1
[229.583158] (kms_flip:4481) DEBUG: Vblank took 39us
[229.599790] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.904755
last_received_ts = 230.904053
last_seq = 350
current_ts = 230.921417
current_received_ts = 230.920715
current_seq = 351
count = 346
seq_step = 1
[229.599834] (kms_flip:4481) DEBUG: Vblank took 41us
[229.616468] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.921417
last_received_ts = 230.920715
last_seq = 351
current_ts = 230.938080
current_received_ts = 230.937408
current_seq = 352
count = 347
seq_step = 1
[229.616595] (kms_flip:4481) DEBUG: Vblank took 125us
[229.633110] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.938080
last_received_ts = 230.937408
last_seq = 352
current_ts = 230.954742
current_received_ts = 230.954041
current_seq = 353
count = 348
seq_step = 1
[229.633148] (kms_flip:4481) DEBUG: Vblank took 37us
[229.649782] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.954742
last_received_ts = 230.954041
last_seq = 353
current_ts = 230.971420
current_received_ts = 230.970718
current_seq = 354
count = 349
seq_step = 1
[229.649824] (kms_flip:4481) DEBUG: Vblank took 40us
[229.666338] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.971420
last_received_ts = 230.970718
last_seq = 354
current_ts = 230.988083
current_received_ts = 230.987274
current_seq = 355
count = 350
seq_step = 1
[229.666383] (kms_flip:4481) DEBUG: Vblank took 43us
[229.683112] (kms_flip:4481) DEBUG: name = flip
last_ts = 230.988083
last_received_ts = 230.987274
last_seq = 355
current_ts = 231.004745
current_received_ts = 231.004044
current_seq = 356
count = 351
seq_step = 1
[229.683158] (kms_flip:4481) DEBUG: Vblank took 44us
[229.699678] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.004745
last_received_ts = 231.004044
last_seq = 356
current_ts = 231.021408
current_received_ts = 231.020615
current_seq = 357
count = 352
seq_step = 1
[229.699723] (kms_flip:4481) DEBUG: Vblank took 42us
[229.716332] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.021408
last_received_ts = 231.020615
last_seq = 357
current_ts = 231.038071
current_received_ts = 231.037262
current_seq = 358
count = 353
seq_step = 1
[229.716377] (kms_flip:4481) DEBUG: Vblank took 43us
[229.733104] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.038071
last_received_ts = 231.037262
last_seq = 358
current_ts = 231.054733
current_received_ts = 231.054047
current_seq = 359
count = 354
seq_step = 1
[229.733144] (kms_flip:4481) DEBUG: Vblank took 37us
[229.749785] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.054733
last_received_ts = 231.054047
last_seq = 359
current_ts = 231.071396
current_received_ts = 231.070724
current_seq = 360
count = 355
seq_step = 1
[229.749826] (kms_flip:4481) DEBUG: Vblank took 38us
[229.766431] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.071396
last_received_ts = 231.070724
last_seq = 360
current_ts = 231.088074
current_received_ts = 231.087372
current_seq = 361
count = 356
seq_step = 1
[229.766477] (kms_flip:4481) DEBUG: Vblank took 44us
[229.783054] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.088074
last_received_ts = 231.087372
last_seq = 361
current_ts = 231.104736
current_received_ts = 231.103989
current_seq = 362
count = 357
seq_step = 1
[229.783113] (kms_flip:4481) DEBUG: Vblank took 57us
[229.799742] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.104736
last_received_ts = 231.103989
last_seq = 362
current_ts = 231.121399
current_received_ts = 231.120682
current_seq = 363
count = 358
seq_step = 1
[229.799786] (kms_flip:4481) DEBUG: Vblank took 41us
[229.816349] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.121399
last_received_ts = 231.120682
last_seq = 363
current_ts = 231.138062
current_received_ts = 231.137283
current_seq = 364
count = 359
seq_step = 1
[229.816400] (kms_flip:4481) DEBUG: Vblank took 49us
[229.833091] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.138062
last_received_ts = 231.137283
last_seq = 364
current_ts = 231.154724
current_received_ts = 231.154037
current_seq = 365
count = 360
seq_step = 1
[229.833218] (kms_flip:4481) DEBUG: Vblank took 123us
[229.849745] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.154724
last_received_ts = 231.154037
last_seq = 365
current_ts = 231.171402
current_received_ts = 231.170685
current_seq = 366
count = 361
seq_step = 1
[229.849789] (kms_flip:4481) DEBUG: Vblank took 42us
[229.866416] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.171402
last_received_ts = 231.170685
last_seq = 366
current_ts = 231.188049
current_received_ts = 231.187363
current_seq = 367
count = 362
seq_step = 1
[229.866464] (kms_flip:4481) DEBUG: Vblank took 46us
[229.883088] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.188049
last_received_ts = 231.187363
last_seq = 367
current_ts = 231.204727
current_received_ts = 231.204025
current_seq = 368
count = 363
seq_step = 1
[229.883129] (kms_flip:4481) DEBUG: Vblank took 39us
[229.899733] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.204727
last_received_ts = 231.204025
last_seq = 368
current_ts = 231.221375
current_received_ts = 231.220673
current_seq = 369
count = 364
seq_step = 1
[229.899862] (kms_flip:4481) DEBUG: Vblank took 126us
[229.916405] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.221375
last_received_ts = 231.220673
last_seq = 369
current_ts = 231.238052
current_received_ts = 231.237350
current_seq = 370
count = 365
seq_step = 1
[229.916450] (kms_flip:4481) DEBUG: Vblank took 43us
[229.933076] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.238052
last_received_ts = 231.237350
last_seq = 370
current_ts = 231.254715
current_received_ts = 231.254013
current_seq = 371
count = 366
seq_step = 1
[229.933198] (kms_flip:4481) DEBUG: Vblank took 119us
[229.949663] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.254715
last_received_ts = 231.254013
last_seq = 371
current_ts = 231.271378
current_received_ts = 231.270599
current_seq = 372
count = 367
seq_step = 1
[229.949791] (kms_flip:4481) DEBUG: Vblank took 125us
[229.966413] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.271378
last_received_ts = 231.270599
last_seq = 372
current_ts = 231.288040
current_received_ts = 231.287354
current_seq = 373
count = 368
seq_step = 1
[229.966532] (kms_flip:4481) DEBUG: Vblank took 117us
[229.983085] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.288040
last_received_ts = 231.287354
last_seq = 373
current_ts = 231.304718
current_received_ts = 231.304031
current_seq = 374
count = 369
seq_step = 1
[229.983214] (kms_flip:4481) DEBUG: Vblank took 126us
[229.999734] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.304718
last_received_ts = 231.304031
last_seq = 374
current_ts = 231.321381
current_received_ts = 231.320679
current_seq = 375
count = 370
seq_step = 1
[229.999863] (kms_flip:4481) DEBUG: Vblank took 127us
[230.016372] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.321381
last_received_ts = 231.320679
last_seq = 375
current_ts = 231.338043
current_received_ts = 231.337311
current_seq = 376
count = 371
seq_step = 1
[230.016420] (kms_flip:4481) DEBUG: Vblank took 44us
[230.033081] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.338043
last_received_ts = 231.337311
last_seq = 376
current_ts = 231.354706
current_received_ts = 231.354034
current_seq = 377
count = 372
seq_step = 1
[230.033124] (kms_flip:4481) DEBUG: Vblank took 41us
[230.049711] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.354706
last_received_ts = 231.354034
last_seq = 377
current_ts = 231.371368
current_received_ts = 231.370667
current_seq = 378
count = 373
seq_step = 1
[230.049829] (kms_flip:4481) DEBUG: Vblank took 115us
[230.066367] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.371368
last_received_ts = 231.370667
last_seq = 378
current_ts = 231.388031
current_received_ts = 231.387299
current_seq = 379
count = 374
seq_step = 1
[230.066411] (kms_flip:4481) DEBUG: Vblank took 38us
[230.083068] (kms_flip:4481) DEBUG: name = flip
last_ts = 231.388031
last_received_ts = 231.387299
last_seq = 379
current_ts = 231.404694
current_received_ts = 231.404022
current_seq = 380
count = 375
seq_step = 1
[230.083608] (kms_flip:4481) DEBUG: Vblank took 537us
[230.083611] (kms_flip:4481) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
[230.083679] (kms_flip:4481) CRITICAL: Failed assertion: end - start < 500
[230.083716] (kms_flip:4481) CRITICAL: Last errno: 4, Interrupted system call
[230.103225] (kms_flip:4481) igt_core-INFO: Stack trace:
[230.113397] (kms_flip:4481) igt_core-INFO:   #0 ../lib/igt_core.c:2074 __igt_fail_assert()
[230.114642] (kms_flip:4481) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
[230.114730] (kms_flip:4481) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
[230.114769] (kms_flip:4481) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
[230.114803] (kms_flip:4481) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
[230.118827] (kms_flip:4481) igt_core-INFO:   #5 [__libc_init_first+0x8a]
[230.119873] (kms_flip:4481) igt_core-INFO:   #6 [__libc_start_main+0x8b]
[230.120124] (kms_flip:4481) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-eDP1: FAIL (7.599s)
Dmesg
<6> [224.269162] [IGT] kms_flip: starting dynamic subtest B-eDP1
<7> [224.273875] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430]
<7> [224.275692] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:432]
<7> [224.280537] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [224.280940] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [224.281208] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [224.348664] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [224.348794] 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> [224.348954] 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> [224.349082] 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> [224.349209] 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> [224.349340] 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 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0)
<7> [224.349475] 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> [224.349633] 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> [224.349753] 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> [224.349868] 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> [224.349983] 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> [224.350093] 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> [224.350205] 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> [224.350314] 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> [224.350431] 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> [224.350564] 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> [224.350685] 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> [224.350802] 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> [224.350915] 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> [224.351032] 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> [224.351158] 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> [224.351280] 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> [224.351389] 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> [224.351506] 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> [224.351622] 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> [224.351730] 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> [224.351842] 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> [224.351958] 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> [224.352078] 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> [224.352202] 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> [224.352319] 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> [224.352438] 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> [224.352560] 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> [224.352674] 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> [224.352782] 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> [224.352891] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0)
<7> [224.353001] 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> [224.353113] 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> [224.353228] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 432000, found 0)
<7> [224.353352] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [224.353474] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:151:pipe A] releasing DPLL 0
<7> [224.353791] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [224.353887] 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> [224.353998] 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> [224.354085] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:151:pipe A] min cdclk: 173855 kHz -> 0 kHz
<7> [224.354213] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [224.354337] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz
<7> [224.354465] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [224.354662] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:151:pipe A] enable: no [modeset]
<7> [224.354787] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:35:plane 1A] fb: [NOFB], visible: no
<7> [224.354907] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [224.355022] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [224.355136] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [224.355250] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [224.355370] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [224.355562] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [224.355692] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [224.355970] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM
<7> [224.356100] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]]
<7> [224.561585] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 0
<7> [224.562900] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [224.580932] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power off
<7> [224.581544] 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> [224.582082] 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> [224.634297] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000
<7> [224.634783] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - short
<7> [224.642914] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [224.643444] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:151:pipe A]
<7> [224.643467] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [224.645215] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0
<7> [224.645912] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A
<7> [224.646625] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [224.647104] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [224.647587] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [224.648041] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [224.648520] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [224.648965] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [224.649405] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [224.649860] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [224.650288] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [224.650748] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [224.651187] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [224.651645] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [224.652082] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [224.652540] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [224.653086] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [224.653516] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [224.653903] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [224.654601] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [224.655176] 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> [224.655824] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:151:pipe A]
<7> [224.656284] 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> [224.656824] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [224.657165] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384
<7> [224.658236] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [224.658810] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:389:pipe C]
<7> [224.659180] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:270:pipe B]
<7> [224.659268] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:393:eDP-1]
<7> [224.659522] xe 0000:00:02.0: [drm:compute_baseline_pipe_bpp [xe]] [CONNECTOR:393:eDP-1] Limiting target display pipe bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36)
<7> [224.659909] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:392:DDI A/PHY A][CRTC:270:pipe B] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000
<7> [224.660211] xe 0000:00:02.0: [drm:intel_dp_compute_output_format [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 HDR no link rate required 1303913 available 1728000
<7> [224.660561] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] hw max bpp: 30, pipe bpp: 30, dithering: 0
<7> [224.660860] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:392:DDI A/PHY A] [CRTC:270:pipe B]
<7> [224.661138] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.enable (expected no, found yes)
<7> [224.661388] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.active (expected no, found yes)
<7> [224.661650] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)
<7> [224.661900] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in lane_count (expected 0, found 4)
<7> [224.662143] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288)
<7> [224.662371] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100)
<7> [224.662613] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [224.662827] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880)
<7> [224.663035] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040)
<7> [224.663240] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880)
<7> [224.663422] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040)
<7> [224.663619] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928)
<7> [224.663802] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960)
<7> [224.663986] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800)
<7> [224.664185] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800)
<7> [224.664366] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803)
<7> [224.664548] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809)
<7> [224.664721] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906)
<7> [224.664863] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906)
<7> [224.665007] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880)
<7> [224.665132] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040)
<7> [224.665254] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880)
<7> [224.665377] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040)
<7> [224.665505] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928)
<7> [224.665656] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960)
<7> [224.665793] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800)
<7> [224.665934] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800)
<7> [224.666080] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803)
<7> [224.666224] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809)
<7> [224.666343] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906)
<7> [224.666455] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906)
<7> [224.666578] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [224.666696] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2)
<7> [224.666804] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8)
<7> [224.666914] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in dpll_hw_state
<7> [224.667021] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [224.667133] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 0, ssc_enabled: no, use_c10: no, tbt_mode: no
<7> [224.667251] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] c20pll_hw_state:
<7> [224.667367] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] tx[0] = 0x0000, tx[1] = 0x0000, tx[2] = 0x0000
<7> [224.667501] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] cmn[0] = 0x0000, cmn[1] = 0x0000, cmn[2] = 0x0000, cmn[3] = 0x0000
<7> [224.667622] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[0] = 0x0000
<7> [224.667733] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[1] = 0x0000
<7> [224.667843] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[2] = 0x0000
<7> [224.667950] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[3] = 0x0000
<7> [224.668057] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[4] = 0x0000
<7> [224.668164] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[5] = 0x0000
<7> [224.668273] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[6] = 0x0000
<7> [224.668386] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[7] = 0x0000
<7> [224.668570] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[8] = 0x0000
<7> [224.668694] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mplla[9] = 0x0000
<7> [224.668803] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] mpllb[10] = 0x0000
<7> [224.668920] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] vdr: custom width: 0x00, serdes rate: 0x00, hdmi rate: 0x00
<7> [224.669039] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [224.669147] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no
<7> [224.669254] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] c10pll_hw_state: fracen: no,
<7> [224.669361] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] multiplier: 225, tx_clk_div: 1.
<7> [224.669468] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] c10pll_rawhw_state:
<7> [224.669590] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] tx: 0x10, cmn: 0x21
<7> [224.669710] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [224.669824] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [224.669939] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [224.670053] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [224.670165] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [224.670281] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 30)
<7> [224.670389] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710)
<7> [224.670506] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710)
<7> [224.670619] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:270:pipe B] fastset requirement not met in port_clock (expected 0, found 432000)
<7> [224.670728] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:270:pipe B] fastset requirement not met, forcing full modeset
<7> [224.670909] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [224.671004] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:270:pipe B] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x2
<7> [224.671146] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:154:plane 1B] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051
<7> [224.671255] xe 0000:00:02.0: [drm:skl_print_plane_ddb_changes [xe]] [PLANE:264:cursor B] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45
<7> [224.671335] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [224.671419] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0
<7> [224.671513] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197
<7> [224.671595] xe 0000:00:02.0: [drm:skl_print_plane_wm_changes [xe]] [PLANE:154:plane 1B] 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> [224.671689] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:270:pipe B] data rate 1390840 num active planes 1
<7> [224.671683] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [224.671814] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400
<7> [224.671878] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [224.671933] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400
<7> [224.671982] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10
<7> [224.672051] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [224.672104] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [224.672167] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400
<7> [224.672284] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461
<7> [224.672407] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:270:pipe B] min cdclk: 0 kHz -> 173855 kHz
<7> [224.672561] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing
<7> [224.672684] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz
<7> [224.672804] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0
<7> [224.672942] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:270:pipe B] allocated DPLL 0
<7> [224.673050] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:270:pipe B] reserving DPLL 0
<7> [224.673157] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:270:pipe B] enable: yes [modeset]
<7> [224.673277] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB
<7> [224.673395] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: B, pipe bpp: 30, dithering: 0
<7> [224.673524] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [224.673642] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [224.673756] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [224.673871] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [224.673985] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64
<7> [224.674101] 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> [224.674223] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled
<7> [224.674343] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [224.674467] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled
<7> [224.674597] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum hblank: 0
<7> [224.674717] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4
<7> [224.674836] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14
<7> [224.674950] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB
<7> [224.675064] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB
<7> [224.675178] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0
<7> [224.675292] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range
<7> [224.675409] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined
<7> [224.675539] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1
<7> [224.675662] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [224.675779] 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> [224.675898] 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> [224.676014] 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> [224.676128] 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> [224.676243] 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> [224.676357] 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> [224.676481] 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> [224.676603] 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> [224.676723] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pixel rate 347710, min cdclk 173855, min voltage level 0
<7> [224.676841] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0
<7> [224.676958] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [224.677080] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe src: 2880x1800+0+0
<7> [224.677198] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [224.677312] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [224.677426] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [224.677553] 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> [224.677561] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [224.677672] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: fracen: no,
<7> [224.677730] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [224.677796] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1.
<7> [224.677871] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<7> [224.677923] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state:
<7> [224.678037] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling always-on
<7> [224.678051] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21
<7> [224.678170] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1
<7> [224.678293] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0
<7> [224.678416] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0
<7> [224.678541] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1
<7> [224.678657] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23
<7> [224.678771] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [224.678885] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [224.679003] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [224.679121] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [224.679244] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [224.679366] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [224.679497] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [224.679622] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [224.679738] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [224.679851] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [224.679964] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [224.680077] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [224.680193] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:154:plane 1B] fb: [FB:430] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [224.680319] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [224.680443] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0
<7> [224.680575] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:184:plane 2B] fb: [NOFB], visible: no
<7> [224.680693] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:214:plane 3B] fb: [NOFB], visible: no
<7> [224.680810] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:244:plane 4B] fb: [NOFB], visible: no
<7> [224.680924] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:254:plane 5B] fb: [NOFB], visible: no
<7> [224.681037] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:264:cursor B] fb: [NOFB], visible: no
<7> [224.681467] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling always-on
<7> [224.681622] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off
<7> [224.681897] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00
<7> [224.682077] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [224.682245] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_B
<7> [224.682416] xe 0000:00:02.0: [drm:dss_pipe_gating_enable_disable [xe]] DSS clock gating enabled for pipe_mask=0x2 (CLKGATE_DIS_DSSDSC=0xa2000000)
<7> [224.682568] 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> [224.682714] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no)
<7> [224.682834] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480
<7> [224.682965] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:392:DDI A/PHY A]
<7> [224.683062] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DDI TC1/PHY TC1]
<7> [224.683157] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST A]
<7> [224.683258] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:404:DP-MST B]
<7> [224.683356] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:405:DP-MST C]
<7> [224.683455] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DDI TC2/PHY TC2]
<7> [224.683556] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST A]
<7> [224.683649] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:416:DP-MST B]
<7> [224.683734] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:417:DP-MST C]
<7> [224.683820] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DDI TC3/PHY TC3]
<7> [224.683906] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST A]
<7> [224.683996] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:424:DP-MST B]
<7> [224.684090] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:425:DP-MST C]
<7> [224.684213] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [224.684427] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [224.684546] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes)
<7> [224.684687] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A
<7> [224.685490] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x2, on? 0) for [CRTC:270:pipe B]
<7> [224.685613] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0
<7> [224.687649] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turn panel power on
<7> [224.687749] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 wait for panel power cycle (456 ms remaining)
<7> [225.145596] 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> [225.246387] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [225.247044] 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> [225.247649] 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> [225.283628] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010
<7> [225.283969] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:392:DDI A/PHY A] - long
<7> [225.284275] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20
<7> [225.284714] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:392:DDI A/PHY A]
<7> [225.460795] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete
<7> [225.462032] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:392:DDI A/PHY A] PPS 0 turning VDD on
<7> [225.462979] 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> [225.466056] 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> [225.468220] 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> [225.469710] 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 05
<7> [225.471396] 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> [225.473104] 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> [225.474546] 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> [225.475147] 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> [225.476946] 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> [225.477556] 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 = 432000, lane count = 4
<7> [225.480717] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe B
<7> [225.481352] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]]
<7> [225.481786] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe B
<7> [225.482238] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:393:eDP-1] set backlight PWM = 4518
<7> [225.514932] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2
<7> [225.517309] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:393:eDP-1]
<7> [225.518079] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:270:pipe B]
<7> [228.060258] 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> [228.060951] 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> [231.816262] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off
<7> [231.816644] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6
<7> [231.816918] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02
<6> [231.869631] [IGT] kms_flip: finished subtest B-eDP1, FAIL
Created at 2026-05-13 18:07:31