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

Machine description: shard-bmg-4

Result: Fail

i915_display_info2 igt_runner2 results2.json i915_display_info_post_exec2 boot2 dmesg2

DetailValue
Duration 5.74 seconds
Hostname 
shard-bmg-4
Igt-Version 
IGT-Version: 1.29-NO-GIT (x86_64) (Linux: 6.12.0-rc2-xe x86_64)
Out 
Starting dynamic subtest: B-DP2
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2051 __igt_fail_assert()
  #1 ../tests/kms_flip.c:919 run_test_on_crtc_set.constprop.0()
  #2 ../tests/kms_flip.c:1845 run_test()
  #3 ../tests/kms_flip.c:2078 __igt_unique____real_main2001()
  #4 ../tests/kms_flip.c:2001 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest B-DP2: FAIL (5.739s)
Err 
Starting dynamic subtest: B-DP2
(kms_flip:2064) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:924:
(kms_flip:2064) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest B-DP2 failed.
**** DEBUG ****
(kms_flip:2064) DEBUG: name = flip
last_ts = 52.963665
last_received_ts = 52.963280
last_seq = 746
current_ts = 52.980488
current_received_ts = 52.980522
current_seq = 747
count = 98
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 46us
(kms_flip:2064) DEBUG: name = flip
last_ts = 52.980488
last_received_ts = 52.980522
last_seq = 747
current_ts = 52.997303
current_received_ts = 52.997124
current_seq = 748
count = 99
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 52.997303
last_received_ts = 52.997124
last_seq = 748
current_ts = 53.014122
current_received_ts = 53.013897
current_seq = 749
count = 100
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.014122
last_received_ts = 53.013897
last_seq = 749
current_ts = 53.030933
current_received_ts = 53.030819
current_seq = 750
count = 101
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 52us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.030933
last_received_ts = 53.030819
last_seq = 750
current_ts = 53.047745
current_received_ts = 53.047382
current_seq = 751
count = 102
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.047745
last_received_ts = 53.047382
last_seq = 751
current_ts = 53.064575
current_received_ts = 53.064281
current_seq = 752
count = 103
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.064575
last_received_ts = 53.064281
last_seq = 752
current_ts = 53.081379
current_received_ts = 53.081093
current_seq = 753
count = 104
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.081379
last_received_ts = 53.081093
last_seq = 753
current_ts = 53.098198
current_received_ts = 53.097923
current_seq = 754
count = 105
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 44us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.098198
last_received_ts = 53.097923
last_seq = 754
current_ts = 53.115021
current_received_ts = 53.115421
current_seq = 755
count = 106
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.115021
last_received_ts = 53.115421
last_seq = 755
current_ts = 53.131832
current_received_ts = 53.131470
current_seq = 756
count = 107
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.131832
last_received_ts = 53.131470
last_seq = 756
current_ts = 53.148659
current_received_ts = 53.148453
current_seq = 757
count = 108
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 51us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.148659
last_received_ts = 53.148453
last_seq = 757
current_ts = 53.165470
current_received_ts = 53.165138
current_seq = 758
count = 109
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.165470
last_received_ts = 53.165138
last_seq = 758
current_ts = 53.182297
current_received_ts = 53.182030
current_seq = 759
count = 110
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 45us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.182297
last_received_ts = 53.182030
last_seq = 759
current_ts = 53.199100
current_received_ts = 53.198734
current_seq = 760
count = 111
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 36us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.199100
last_received_ts = 53.198734
last_seq = 760
current_ts = 53.215931
current_received_ts = 53.215652
current_seq = 761
count = 112
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.215931
last_received_ts = 53.215652
last_seq = 761
current_ts = 53.232742
current_received_ts = 53.232403
current_seq = 762
count = 113
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.232742
last_received_ts = 53.232403
last_seq = 762
current_ts = 53.249565
current_received_ts = 53.249290
current_seq = 763
count = 114
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 44us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.249565
last_received_ts = 53.249290
last_seq = 763
current_ts = 53.266376
current_received_ts = 53.266113
current_seq = 764
count = 115
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 44us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.266376
last_received_ts = 53.266113
last_seq = 764
current_ts = 53.283195
current_received_ts = 53.282806
current_seq = 765
count = 116
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.283195
last_received_ts = 53.282806
last_seq = 765
current_ts = 53.300007
current_received_ts = 53.299652
current_seq = 766
count = 117
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 39us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.300007
last_received_ts = 53.299652
last_seq = 766
current_ts = 53.316826
current_received_ts = 53.316368
current_seq = 767
count = 118
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.316826
last_received_ts = 53.316368
last_seq = 767
current_ts = 53.333645
current_received_ts = 53.333336
current_seq = 768
count = 119
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.333645
last_received_ts = 53.333336
last_seq = 768
current_ts = 53.350460
current_received_ts = 53.350044
current_seq = 769
count = 120
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.350460
last_received_ts = 53.350044
last_seq = 769
current_ts = 53.367279
current_received_ts = 53.366970
current_seq = 770
count = 121
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.367279
last_received_ts = 53.366970
last_seq = 770
current_ts = 53.384094
current_received_ts = 53.383781
current_seq = 771
count = 122
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.384094
last_received_ts = 53.383781
last_seq = 771
current_ts = 53.400921
current_received_ts = 53.400513
current_seq = 772
count = 123
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.400921
last_received_ts = 53.400513
last_seq = 772
current_ts = 53.417728
current_received_ts = 53.417362
current_seq = 773
count = 124
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.417728
last_received_ts = 53.417362
last_seq = 773
current_ts = 53.434547
current_received_ts = 53.434284
current_seq = 774
count = 125
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.434547
last_received_ts = 53.434284
last_seq = 774
current_ts = 53.451363
current_received_ts = 53.450989
current_seq = 775
count = 126
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 34us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.451363
last_received_ts = 53.450989
last_seq = 775
current_ts = 53.468185
current_received_ts = 53.467831
current_seq = 776
count = 127
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.468185
last_received_ts = 53.467831
last_seq = 776
current_ts = 53.485004
current_received_ts = 53.484646
current_seq = 777
count = 128
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.485004
last_received_ts = 53.484646
last_seq = 777
current_ts = 53.501827
current_received_ts = 53.501549
current_seq = 778
count = 129
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.501827
last_received_ts = 53.501549
last_seq = 778
current_ts = 53.518646
current_received_ts = 53.518257
current_seq = 779
count = 130
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 34us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.518646
last_received_ts = 53.518257
last_seq = 779
current_ts = 53.535461
current_received_ts = 53.535187
current_seq = 780
count = 131
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.535461
last_received_ts = 53.535187
last_seq = 780
current_ts = 53.552277
current_received_ts = 53.551991
current_seq = 781
count = 132
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 79us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.552277
last_received_ts = 53.551991
last_seq = 781
current_ts = 53.569088
current_received_ts = 53.568626
current_seq = 782
count = 133
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.569088
last_received_ts = 53.568626
last_seq = 782
current_ts = 53.585892
current_received_ts = 53.585613
current_seq = 783
count = 134
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.585892
last_received_ts = 53.585613
last_seq = 783
current_ts = 53.602676
current_received_ts = 53.602303
current_seq = 784
count = 135
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 34us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.602676
last_received_ts = 53.602303
last_seq = 784
current_ts = 53.619476
current_received_ts = 53.619213
current_seq = 785
count = 136
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.619476
last_received_ts = 53.619213
last_seq = 785
current_ts = 53.636284
current_received_ts = 53.636005
current_seq = 786
count = 137
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.636284
last_received_ts = 53.636005
last_seq = 786
current_ts = 53.653072
current_received_ts = 53.652752
current_seq = 787
count = 138
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.653072
last_received_ts = 53.652752
last_seq = 787
current_ts = 53.669884
current_received_ts = 53.669502
current_seq = 788
count = 139
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.669884
last_received_ts = 53.669502
last_seq = 788
current_ts = 53.686680
current_received_ts = 53.686405
current_seq = 789
count = 140
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.686680
last_received_ts = 53.686405
last_seq = 789
current_ts = 53.703480
current_received_ts = 53.703094
current_seq = 790
count = 141
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.703480
last_received_ts = 53.703094
last_seq = 790
current_ts = 53.720276
current_received_ts = 53.720097
current_seq = 791
count = 142
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.720276
last_received_ts = 53.720097
last_seq = 791
current_ts = 53.737080
current_received_ts = 53.736782
current_seq = 792
count = 143
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 52us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.737080
last_received_ts = 53.736782
last_seq = 792
current_ts = 53.753880
current_received_ts = 53.753502
current_seq = 793
count = 144
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 39us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.753880
last_received_ts = 53.753502
last_seq = 793
current_ts = 53.770676
current_received_ts = 53.770401
current_seq = 794
count = 145
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.770676
last_received_ts = 53.770401
last_seq = 794
current_ts = 53.787464
current_received_ts = 53.787098
current_seq = 795
count = 146
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 36us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.787464
last_received_ts = 53.787098
last_seq = 795
current_ts = 53.804260
current_received_ts = 53.804218
current_seq = 796
count = 147
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 51us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.804260
last_received_ts = 53.804218
last_seq = 796
current_ts = 53.821060
current_received_ts = 53.820717
current_seq = 797
count = 148
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 47us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.821060
last_received_ts = 53.820717
last_seq = 797
current_ts = 53.837864
current_received_ts = 53.837605
current_seq = 798
count = 149
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 47us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.837864
last_received_ts = 53.837605
last_seq = 798
current_ts = 53.854656
current_received_ts = 53.854397
current_seq = 799
count = 150
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 46us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.854656
last_received_ts = 53.854397
last_seq = 799
current_ts = 53.871468
current_received_ts = 53.871090
current_seq = 800
count = 151
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.871468
last_received_ts = 53.871090
last_seq = 800
current_ts = 53.888268
current_received_ts = 53.887878
current_seq = 801
count = 152
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 34us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.888268
last_received_ts = 53.887878
last_seq = 801
current_ts = 53.905052
current_received_ts = 53.904758
current_seq = 802
count = 153
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 53us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.905052
last_received_ts = 53.904758
last_seq = 802
current_ts = 53.921864
current_received_ts = 53.921486
current_seq = 803
count = 154
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 39us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.921864
last_received_ts = 53.921486
last_seq = 803
current_ts = 53.938652
current_received_ts = 53.938393
current_seq = 804
count = 155
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.938652
last_received_ts = 53.938393
last_seq = 804
current_ts = 53.955463
current_received_ts = 53.955078
current_seq = 805
count = 156
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 36us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.955463
last_received_ts = 53.955078
last_seq = 805
current_ts = 53.972260
current_received_ts = 53.971981
current_seq = 806
count = 157
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 76us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.972260
last_received_ts = 53.971981
last_seq = 806
current_ts = 53.989044
current_received_ts = 53.988747
current_seq = 807
count = 158
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 44us
(kms_flip:2064) DEBUG: name = flip
last_ts = 53.989044
last_received_ts = 53.988747
last_seq = 807
current_ts = 54.005859
current_received_ts = 54.005585
current_seq = 808
count = 159
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.005859
last_received_ts = 54.005585
last_seq = 808
current_ts = 54.022655
current_received_ts = 54.022377
current_seq = 809
count = 160
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.022655
last_received_ts = 54.022377
last_seq = 809
current_ts = 54.039455
current_received_ts = 54.039070
current_seq = 810
count = 161
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 35us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.039455
last_received_ts = 54.039070
last_seq = 810
current_ts = 54.056252
current_received_ts = 54.055866
current_seq = 811
count = 162
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.056252
last_received_ts = 54.055866
last_seq = 811
current_ts = 54.073051
current_received_ts = 54.072685
current_seq = 812
count = 163
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.073051
last_received_ts = 54.072685
last_seq = 812
current_ts = 54.089851
current_received_ts = 54.089466
current_seq = 813
count = 164
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 35us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.089851
last_received_ts = 54.089466
last_seq = 813
current_ts = 54.106640
current_received_ts = 54.106266
current_seq = 814
count = 165
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.106640
last_received_ts = 54.106266
last_seq = 814
current_ts = 54.123447
current_received_ts = 54.123322
current_seq = 815
count = 166
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 52us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.123447
last_received_ts = 54.123322
last_seq = 815
current_ts = 54.140240
current_received_ts = 54.139977
current_seq = 816
count = 167
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 81us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.140240
last_received_ts = 54.139977
last_seq = 816
current_ts = 54.157040
current_received_ts = 54.156631
current_seq = 817
count = 168
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 39us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.157040
last_received_ts = 54.156631
last_seq = 817
current_ts = 54.173840
current_received_ts = 54.173462
current_seq = 818
count = 169
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.173840
last_received_ts = 54.173462
last_seq = 818
current_ts = 54.190632
current_received_ts = 54.190376
current_seq = 819
count = 170
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.190632
last_received_ts = 54.190376
last_seq = 819
current_ts = 54.207439
current_received_ts = 54.207138
current_seq = 820
count = 171
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 39us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.207439
last_received_ts = 54.207138
last_seq = 820
current_ts = 54.224236
current_received_ts = 54.223911
current_seq = 821
count = 172
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.224236
last_received_ts = 54.223911
last_seq = 821
current_ts = 54.241024
current_received_ts = 54.240677
current_seq = 822
count = 173
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 45us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.241024
last_received_ts = 54.240677
last_seq = 822
current_ts = 54.257839
current_received_ts = 54.257515
current_seq = 823
count = 174
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 39us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.257839
last_received_ts = 54.257515
last_seq = 823
current_ts = 54.274635
current_received_ts = 54.274391
current_seq = 824
count = 175
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.274635
last_received_ts = 54.274391
last_seq = 824
current_ts = 54.291424
current_received_ts = 54.291168
current_seq = 825
count = 176
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 45us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.291424
last_received_ts = 54.291168
last_seq = 825
current_ts = 54.308228
current_received_ts = 54.307903
current_seq = 826
count = 177
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.308228
last_received_ts = 54.307903
last_seq = 826
current_ts = 54.325020
current_received_ts = 54.324604
current_seq = 827
count = 178
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 36us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.325020
last_received_ts = 54.324604
last_seq = 827
current_ts = 54.341827
current_received_ts = 54.341457
current_seq = 828
count = 179
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.341827
last_received_ts = 54.341457
last_seq = 828
current_ts = 54.358620
current_received_ts = 54.358395
current_seq = 829
count = 180
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 53us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.358620
last_received_ts = 54.358395
last_seq = 829
current_ts = 54.375427
current_received_ts = 54.375046
current_seq = 830
count = 181
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.375427
last_received_ts = 54.375046
last_seq = 830
current_ts = 54.392223
current_received_ts = 54.392166
current_seq = 831
count = 182
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 57us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.392223
last_received_ts = 54.392166
last_seq = 831
current_ts = 54.409023
current_received_ts = 54.408627
current_seq = 832
count = 183
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 40us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.409023
last_received_ts = 54.408627
last_seq = 832
current_ts = 54.425812
current_received_ts = 54.425499
current_seq = 833
count = 184
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 36us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.425812
last_received_ts = 54.425499
last_seq = 833
current_ts = 54.442623
current_received_ts = 54.442245
current_seq = 834
count = 185
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 33us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.442623
last_received_ts = 54.442245
last_seq = 834
current_ts = 54.459412
current_received_ts = 54.459297
current_seq = 835
count = 186
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 51us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.459412
last_received_ts = 54.459297
last_seq = 835
current_ts = 54.476215
current_received_ts = 54.475945
current_seq = 836
count = 187
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 115us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.476215
last_received_ts = 54.475945
last_seq = 836
current_ts = 54.493008
current_received_ts = 54.492634
current_seq = 837
count = 188
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 41us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.493008
last_received_ts = 54.492634
last_seq = 837
current_ts = 54.509808
current_received_ts = 54.509483
current_seq = 838
count = 189
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.509808
last_received_ts = 54.509483
last_seq = 838
current_ts = 54.526608
current_received_ts = 54.526436
current_seq = 839
count = 190
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 44us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.526608
last_received_ts = 54.526436
last_seq = 839
current_ts = 54.543407
current_received_ts = 54.543179
current_seq = 840
count = 191
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.543407
last_received_ts = 54.543179
last_seq = 840
current_ts = 54.560204
current_received_ts = 54.559864
current_seq = 841
count = 192
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.560204
last_received_ts = 54.559864
last_seq = 841
current_ts = 54.576996
current_received_ts = 54.576595
current_seq = 842
count = 193
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 38us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.576996
last_received_ts = 54.576595
last_seq = 842
current_ts = 54.593784
current_received_ts = 54.593407
current_seq = 843
count = 194
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.593784
last_received_ts = 54.593407
last_seq = 843
current_ts = 54.610565
current_received_ts = 54.610394
current_seq = 844
count = 195
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.610565
last_received_ts = 54.610394
last_seq = 844
current_ts = 54.627346
current_received_ts = 54.627102
current_seq = 845
count = 196
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.627346
last_received_ts = 54.627102
last_seq = 845
current_ts = 54.644131
current_received_ts = 54.643745
current_seq = 846
count = 197
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.644131
last_received_ts = 54.643745
last_seq = 846
current_ts = 54.660908
current_received_ts = 54.660557
current_seq = 847
count = 198
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 53us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.660908
last_received_ts = 54.660557
last_seq = 847
current_ts = 54.677681
current_received_ts = 54.677315
current_seq = 848
count = 199
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.677681
last_received_ts = 54.677315
last_seq = 848
current_ts = 54.694477
current_received_ts = 54.694202
current_seq = 849
count = 200
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.694477
last_received_ts = 54.694202
last_seq = 849
current_ts = 54.711258
current_received_ts = 54.710873
current_seq = 850
count = 201
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 37us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.711258
last_received_ts = 54.710873
last_seq = 850
current_ts = 54.728043
current_received_ts = 54.727654
current_seq = 851
count = 202
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 32us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.728043
last_received_ts = 54.727654
last_seq = 851
current_ts = 54.744816
current_received_ts = 54.744419
current_seq = 852
count = 203
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.744816
last_received_ts = 54.744419
last_seq = 852
current_ts = 54.761604
current_received_ts = 54.761337
current_seq = 853
count = 204
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.761604
last_received_ts = 54.761337
last_seq = 853
current_ts = 54.778385
current_received_ts = 54.778107
current_seq = 854
count = 205
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.778385
last_received_ts = 54.778107
last_seq = 854
current_ts = 54.795170
current_received_ts = 54.794788
current_seq = 855
count = 206
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 35us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.795170
last_received_ts = 54.794788
last_seq = 855
current_ts = 54.811951
current_received_ts = 54.811676
current_seq = 856
count = 207
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.811951
last_received_ts = 54.811676
last_seq = 856
current_ts = 54.828732
current_received_ts = 54.828373
current_seq = 857
count = 208
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 42us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.828732
last_received_ts = 54.828373
last_seq = 857
current_ts = 54.845516
current_received_ts = 54.845234
current_seq = 858
count = 209
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.845516
last_received_ts = 54.845234
last_seq = 858
current_ts = 54.862301
current_received_ts = 54.862022
current_seq = 859
count = 210
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.862301
last_received_ts = 54.862022
last_seq = 859
current_ts = 54.879078
current_received_ts = 54.878693
current_seq = 860
count = 211
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 36us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.879078
last_received_ts = 54.878693
last_seq = 860
current_ts = 54.895855
current_received_ts = 54.895550
current_seq = 861
count = 212
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.895855
last_received_ts = 54.895550
last_seq = 861
current_ts = 54.912632
current_received_ts = 54.912346
current_seq = 862
count = 213
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 44us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.912632
last_received_ts = 54.912346
last_seq = 862
current_ts = 54.929417
current_received_ts = 54.929157
current_seq = 863
count = 214
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.929417
last_received_ts = 54.929157
last_seq = 863
current_ts = 54.946205
current_received_ts = 54.945889
current_seq = 864
count = 215
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 44us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.946205
last_received_ts = 54.945889
last_seq = 864
current_ts = 54.962994
current_received_ts = 54.962608
current_seq = 865
count = 216
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 36us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.962994
last_received_ts = 54.962608
last_seq = 865
current_ts = 54.979771
current_received_ts = 54.979404
current_seq = 866
count = 217
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.979771
last_received_ts = 54.979404
last_seq = 866
current_ts = 54.996548
current_received_ts = 54.996384
current_seq = 867
count = 218
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 43us
(kms_flip:2064) DEBUG: name = flip
last_ts = 54.996548
last_received_ts = 54.996384
last_seq = 867
current_ts = 55.013340
current_received_ts = 55.013683
current_seq = 868
count = 219
seq_step = 1
(kms_flip:2064) DEBUG: Vblank took 513us
(kms_flip:2064) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:924:
(kms_flip:2064) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2064) igt_core-INFO: Stack trace:
(kms_flip:2064) igt_core-INFO:   #0 ../lib/igt_core.c:2051 __igt_fail_assert()
(kms_flip:2064) igt_core-INFO:   #1 ../tests/kms_flip.c:919 run_test_on_crtc_set.constprop.0()
(kms_flip:2064) igt_core-INFO:   #2 ../tests/kms_flip.c:1845 run_test()
(kms_flip:2064) igt_core-INFO:   #3 ../tests/kms_flip.c:2078 __igt_unique____real_main2001()
(kms_flip:2064) igt_core-INFO:   #4 ../tests/kms_flip.c:2001 main()
(kms_flip:2064) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2064) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2064) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest B-DP2: FAIL (5.739s)
Dmesg
<6> [50.954423] [IGT] kms_flip: starting dynamic subtest B-DP2
<7> [50.954958] xe 0000:03:00.0: [drm:drm_mode_addfb2 [drm]] [FB:290]
<7> [50.955288] xe 0000:03:00.0: [drm:drm_mode_addfb2 [drm]] [FB:294]
<7> [51.012020] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:82:pipe A]
<7> [51.012233] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.enable (expected yes, found no)
<7> [51.012465] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.active (expected yes, found no)
<7> [51.012659] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1)
<7> [51.012842] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in lane_count (expected 4, found 0)
<7> [51.013022] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 5190451/8388608 link 288358/524288, found tu 0, data 0/0 link 0/0)
<7> [51.013191] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000)
<7> [51.013363] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [51.013526] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [51.013687] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [51.013846] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [51.014003] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [51.014155] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [51.014297] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [51.014440] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [51.014583] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [51.014727] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [51.014871] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [51.015008] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [51.015144] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [51.015279] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [51.015412] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [51.015539] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [51.015666] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [51.015794] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [51.015948] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [51.016145] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [51.016261] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [51.016375] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [51.016487] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [51.016596] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [51.016706] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [51.016817] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [51.016926] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [51.017033] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [51.017138] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in enhanced_framing (expected yes, found no)
<7> [51.017241] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [51.017341] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [51.017442] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [51.017544] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:82:pipe A] fastset requirement not met in port_clock (expected 270000, found 0)
<7> [51.017644] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:82:pipe A] fastset requirement not met, forcing full modeset
<7> [51.017882] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no
<7> [51.018049] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:82:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0
<7> [51.018257] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:32:plane 1A] ddb ( 0 - 4037) -> ( 0 - 0), size 4037 -> 0
<7> [51.018397] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:77:cursor A] ddb (4037 - 4096) -> ( 0 - 0), size 59 -> 0
<7> [51.018534] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:32:plane 1A] level *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm -> wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm
<7> [51.018670] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:32:plane 1A] lines 1, 3, 7, 11, 17, 17, 17, 17, 0, 15, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [51.018807] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:32:plane 1A] blocks 16, 49, 113, 177, 273, 273, 273, 273, 30, 241, 255 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [51.018948] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:32:plane 1A] min_ddb 19, 55, 126, 196, 302, 302, 0, 0, 31, 267, 267 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [51.019093] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:82:pipe A] data rate 0 num active planes 0
<7> [51.019296] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 0 qgv_peak_bw: 48000
<7> [51.019496] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 0 qgv_peak_bw: 48000
<7> [51.019695] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 0
<7> [51.019924] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 652800 kHz, actual 652800 kHz
<7> [51.020132] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 3, actual 3
<7> [51.020374] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:82:pipe A] enable: no [modeset]
<7> [51.020586] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:32:plane 1A] fb: [NOFB], visible: no
<7> [51.020796] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:41:plane 2A] fb: [NOFB], visible: no
<7> [51.021013] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:50:plane 3A] fb: [NOFB], visible: no
<7> [51.021235] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:59:plane 4A] fb: [NOFB], visible: no
<7> [51.021407] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:68:plane 5A] fb: [NOFB], visible: no
<7> [51.021515] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:77:cursor A] fb: [NOFB], visible: no
<7> [51.022009] xe 0000:03:00.0: [drm:intel_audio_codec_disable [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G] Disable audio codec on [CRTC:82:pipe A]
<7> [51.041488] xe 0000:03:00.0: [drm:i915_audio_component_get_eld [xe]] Not valid for port E
<7> [51.042490] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe A
<7> [51.061985] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2
<7> [51.064205] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:240:DDI TC1/PHY F]
<7> [51.064651] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:242:DP-MST A]
<7> [51.065031] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:243:DP-MST B]
<7> [51.065400] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:244:DP-MST C]
<7> [51.065761] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:245:DP-MST D]
<7> [51.066121] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:259:DDI TC2/PHY G]
<7> [51.066490] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:261:DP-MST A]
<7> [51.066850] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:262:DP-MST B]
<7> [51.067208] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:263:DP-MST C]
<7> [51.067608] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:264:DP-MST D]
<7> [51.067971] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:271:DDI TC3/PHY H]
<7> [51.068328] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:275:DDI TC4/PHY I]
<7> [51.068685] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:277:DP-MST A]
<7> [51.069042] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:278:DP-MST B]
<7> [51.069399] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:279:DP-MST C]
<7> [51.069758] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:280:DP-MST D]
<7> [51.070117] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:260:DP-2]
<7> [51.070663] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)
<7> [51.071071] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: *)
<7> [51.071478] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [51.072314] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_A
<7> [51.072803] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [51.073302] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:82:pipe A]
<7> [51.073784] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:134:pipe B]
<7> [51.074617] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:186:pipe C]
<7> [51.075401] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:238:pipe D]
<7> [51.076078] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:134:pipe B]
<7> [51.076108] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CONNECTOR:260:DP-2]
<7> [51.076173] xe 0000:03:00.0: [drm:intel_dp_compute_config_link_bpp_limits [xe]] [ENCODER:259:DDI TC2/PHY G][CRTC:134:pipe B] DP link limits: pixel clock 148500 kHz DSC off max lanes 4 max rate 540000 max pipe_bpp 36 max link_bpp 36.0000
<7> [51.076246] xe 0000:03:00.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 270000 bpp input 36 compressed 0.0000 link rate required 668250 available 1080000
<7> [51.076314] xe 0000:03:00.0: [drm:intel_psr_compute_config [xe]] PSR disabled by flag
<7> [51.076376] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:134:pipe B] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [51.076447] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:259:DDI TC2/PHY G] [CRTC:134:pipe B]
<7> [51.076519] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.enable (expected no, found yes)
<7> [51.076592] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.active (expected no, found yes)
<7> [51.076662] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in cpu_transcoder (expected -1, found 1)
<7> [51.076730] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in lane_count (expected 0, found 4)
<7> [51.076795] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 5190451/8388608 link 288358/524288)
<7> [51.076860] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in output_types (expected 0x00000000, found 0x00000080)
<7> [51.076925] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [51.076989] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [51.077052] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [51.077116] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [51.077179] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [51.077242] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [51.077305] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [51.077369] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [51.077432] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [51.077496] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [51.077559] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [51.077622] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [51.077684] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [51.077746] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [51.077809] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [51.077871] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [51.077932] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [51.077994] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [51.078055] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [51.078117] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [51.078180] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [51.078241] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [51.078303] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [51.078365] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [51.078427] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [51.078489] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [51.078551] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [51.078614] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [51.078678] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in enhanced_framing (expected no, found yes)
<7> [51.078742] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in dpll_hw_state.cx0pll C20
<7> [51.078805] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [51.078867] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] c20pll_hw_state:
<7> [51.078937] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] tx[0] = 0xbe88, tx[1] = 0x9800, tx[2] = 0x0000
<7> [51.079006] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000
<7> [51.079073] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[0] = 0x40e8
<7> [51.079143] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[1] = 0x7d20
<7> [51.079218] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[2] = 0x0a06
<7> [51.079291] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[3] = 0x8f1c
<7> [51.079364] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[4] = 0x0000
<7> [51.079430] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[5] = 0x0000
<7> [51.079495] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[6] = 0x2200
<7> [51.079558] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[7] = 0xffff
<7> [51.079621] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[8] = 0x0400
<7> [51.079686] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[9] = 0x0000
<7> [51.079750] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[10] = 0x0001
<7> [51.079814] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [51.079882] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] c20pll_hw_state:
<7> [51.079947] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] tx[0] = 0xbe88, tx[1] = 0x4800, tx[2] = 0x0000
<7> [51.080012] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] cmn[0] = 0x0500, cmn[1] = 0x0005, cmn[2] = 0x0000, cmn[3] = 0x0000
<7> [51.080077] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[0] = 0x308c
<7> [51.080141] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[1] = 0x2110
<7> [51.080205] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[2] = 0xcc9c
<7> [51.080268] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[3] = 0xbfc1
<7> [51.080332] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[4] = 0x4b9a
<7> [51.080396] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[5] = 0x3f81
<7> [51.080459] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[6] = 0x2000
<7> [51.080523] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[7] = 0x0001
<7> [51.080586] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[8] = 0x5000
<7> [51.080649] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[9] = 0x0000
<7> [51.080713] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[10] = 0x0000
<7> [51.080778] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [51.080848] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [51.080916] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [51.080983] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:134:pipe B] fastset requirement not met in port_clock (expected 0, found 270000)
<7> [51.081051] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:134:pipe B] fastset requirement not met, forcing full modeset
<7> [51.081558] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes
<7> [51.081623] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:134:pipe B] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x2
<7> [51.081706] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] ddb ( 0 - 0) -> ( 0 - 4037), size 0 -> 4037
<7> [51.081765] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:129:cursor B] ddb ( 0 - 0) -> (4037 - 4096), size 0 -> 59
<7> [51.081822] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84: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> [51.081877] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 7, 11, 17, 17, 17, 17, 0, 15, 0
<7> [51.081932] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 113, 177, 273, 273, 273, 273, 30, 241, 255
<7> [51.081988] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:84:plane 1B] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 55, 126, 196, 302, 302, 0, 0, 31, 267, 267
<7> [51.082042] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:134:pipe B] data rate 594000 num active planes 1
<7> [51.082112] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 594 qgv_peak_bw: 48000
<7> [51.082180] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 594 qgv_peak_bw: 48000
<7> [51.082246] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 594
<7> [51.082313] xe 0000:03:00.0: [drm:intel_plane_calc_min_cdclk [xe]] [PLANE:84:plane 1B] min cdclk (74250 kHz) > [CRTC:134:pipe B] min cdclk (0 kHz)
<7> [51.082382] xe 0000:03:00.0: [drm:intel_bw_calc_min_cdclk [xe]] new bandwidth min cdclk (11602 kHz) > old min cdclk (0 kHz)
<7> [51.082451] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 652800 kHz, actual 652800 kHz
<7> [51.082518] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 3, actual 3
<7> [51.082594] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:134:pipe B] enable: yes [modeset]
<7> [51.082663] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB
<7> [51.082731] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: B, pipe bpp: 36, dithering: 0
<7> [51.082798] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [51.082869] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [51.082941] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [51.083007] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [51.083073] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 5190451, data_n: 8388608, link_m: 288358, link_n: 524288, tu: 64
<7> [51.083153] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0
<7> [51.083226] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled
<7> [51.083297] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [51.083366] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [51.083432] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0
<7> [51.083497] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 0, infoframes enabled: 0x0
<7> [51.083563] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00
<7> [51.083564] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11
<7> [51.083565] ELD: 17 50 51 07 00 00 00 00
<7> [51.083566] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] vrr: no, vmin: 0, vmax: 0, pipeline full: 0, guardband: 0 flipline: 0, vmin vblank: 1, vmax vblank: 0
<7> [51.083631] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [51.083697] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [51.083762] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [51.083829] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [51.083892] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=148500, hd=1920 hb=1920-2200 hs=2008-2052 ht=2200, vd=1080 vb=1080-1125 vs=1084-1089 vt=1125, flags=0x5
<7> [51.083955] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 270000, pipe src: 1920x1080+0+0, pixel rate 148500
<7> [51.084018] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0
<7> [51.084082] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [51.084146] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [51.084209] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [51.084272] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dpll_hw_state: dpll: 0x41eb0, dpll_md: 0x4800be88, fp0: 0x5000000, fp1: 0x5
<7> [51.084336] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [51.084400] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [51.084462] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [51.084525] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [51.084588] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [51.084650] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [51.084712] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [51.084775] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [51.084837] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [51.084899] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [51.084962] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [51.085025] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [51.085088] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:84:plane 1B] fb: [FB:290] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [51.085152] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [51.085215] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [51.085278] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:93:plane 2B] fb: [NOFB], visible: no
<7> [51.085341] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:102:plane 3B] fb: [NOFB], visible: no
<7> [51.085406] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:111:plane 4B] fb: [NOFB], visible: no
<7> [51.085469] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:120:plane 5B] fb: [NOFB], visible: no
<7> [51.085533] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:129:cursor B] fb: [NOFB], visible: no
<7> [51.085988] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [51.086192] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_B
<7> [51.086316] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:240:DDI TC1/PHY F]
<7> [51.086383] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:242:DP-MST A]
<7> [51.086443] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:243:DP-MST B]
<7> [51.086501] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:244:DP-MST C]
<7> [51.086557] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:245:DP-MST D]
<7> [51.086612] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:259:DDI TC2/PHY G]
<7> [51.086668] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:261:DP-MST A]
<7> [51.086723] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:262:DP-MST B]
<7> [51.086777] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:263:DP-MST C]
<7> [51.086831] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:264:DP-MST D]
<7> [51.086884] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:271:DDI TC3/PHY H]
<7> [51.086936] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:275:DDI TC4/PHY I]
<7> [51.086989] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:277:DP-MST A]
<7> [51.087049] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:278:DP-MST B]
<7> [51.087107] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:279:DP-MST C]
<7> [51.087167] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:280:DP-MST D]
<7> [51.087226] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf
<7> [51.087355] xe 0000:03:00.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: *)
<7> [51.087411] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: yes)
<7> [51.091197] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [51.097047] xe 0000:03:00.0: [drm:intel_dp_init_lttpr_and_dprx_caps [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] LTTPR common capabilities: 00 00 00 00 00 00 00 00
<7> [51.098190] xe 0000:03:00.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX USBC2/DDI TC2/PHY G: DPCD: 12 14 c4 01 01 15 01 81 00 01 04 01 0f 00 01
<7> [51.098536] xe 0000:03:00.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] Using LINK_BW_SET value 0a
<7> [51.099973] xe 0000:03:00.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0
<7> [51.100247] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] Using DP training pattern TPS1
<7> [51.110065] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] Clock recovery OK
<7> [51.110149] xe 0000:03:00.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] Using DP training pattern TPS3
<7> [51.119776] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] Channel EQ done. DP Training successful
<7> [51.120026] xe 0000:03:00.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G][DPRX] Link Training passed at link rate = 270000, lane count = 4
<7> [51.120815] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe B
<7> [51.138052] xe 0000:03:00.0: [drm:intel_audio_codec_enable [xe]] [CONNECTOR:260:DP-2][ENCODER:259:DDI TC2/PHY G] Enable audio codec on [CRTC:134:pipe B], 40 bytes ELD
<7> [51.154588] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:260:DP-2]
<7> [51.155076] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:134:pipe B]
<7> [51.221633] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2
<7> [53.107036] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2
<7> [53.126745] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2
<6> [56.693563] [IGT] kms_flip: finished subtest B-DP2, FAIL
Created at 2024-10-10 12:10:02