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

Machine description: shard-bmg-7

Result: Fail

i915_display_info17 igt_runner17 results17.json i915_display_info_post_exec17 boot17 dmesg17

DetailValue
Duration 5.33 seconds
Hostname 
shard-bmg-7
Igt-Version 
IGT-Version: 1.29-NO-GIT (x86_64) (Linux: 6.12.0-rc3-xe x86_64)
Out 
Starting dynamic subtest: D-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 D-DP2: FAIL (5.328s)
Err 
Starting dynamic subtest: D-DP2
(kms_flip:2533) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:924:
(kms_flip:2533) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest D-DP2 failed.
**** DEBUG ****
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.759583
last_received_ts = 272.759308
last_seq = 1033
current_ts = 272.776245
current_received_ts = 272.775970
current_seq = 1034
count = 94
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 42us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.776245
last_received_ts = 272.775970
last_seq = 1034
current_ts = 272.792908
current_received_ts = 272.792511
current_seq = 1035
count = 95
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.792908
last_received_ts = 272.792511
last_seq = 1035
current_ts = 272.809601
current_received_ts = 272.809326
current_seq = 1036
count = 96
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 47us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.809601
last_received_ts = 272.809326
last_seq = 1036
current_ts = 272.826263
current_received_ts = 272.825867
current_seq = 1037
count = 97
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.826263
last_received_ts = 272.825867
last_seq = 1037
current_ts = 272.842926
current_received_ts = 272.842804
current_seq = 1038
count = 98
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 55us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.842926
last_received_ts = 272.842804
last_seq = 1038
current_ts = 272.859589
current_received_ts = 272.859222
current_seq = 1039
count = 99
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.859589
last_received_ts = 272.859222
last_seq = 1039
current_ts = 272.876251
current_received_ts = 272.876160
current_seq = 1040
count = 100
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 64us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.876251
last_received_ts = 272.876160
last_seq = 1040
current_ts = 272.892914
current_received_ts = 272.892578
current_seq = 1041
count = 101
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 48us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.892914
last_received_ts = 272.892578
last_seq = 1041
current_ts = 272.909576
current_received_ts = 272.909210
current_seq = 1042
count = 102
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.909576
last_received_ts = 272.909210
last_seq = 1042
current_ts = 272.926270
current_received_ts = 272.925995
current_seq = 1043
count = 103
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 46us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.926270
last_received_ts = 272.925995
last_seq = 1043
current_ts = 272.942932
current_received_ts = 272.942535
current_seq = 1044
count = 104
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.942932
last_received_ts = 272.942535
last_seq = 1044
current_ts = 272.959595
current_received_ts = 272.959320
current_seq = 1045
count = 105
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.959595
last_received_ts = 272.959320
last_seq = 1045
current_ts = 272.976257
current_received_ts = 272.975952
current_seq = 1046
count = 106
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 42us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.976257
last_received_ts = 272.975952
last_seq = 1046
current_ts = 272.992920
current_received_ts = 272.992493
current_seq = 1047
count = 107
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 272.992920
last_received_ts = 272.992493
last_seq = 1047
current_ts = 273.009583
current_received_ts = 273.009338
current_seq = 1048
count = 108
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 47us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.009583
last_received_ts = 273.009338
last_seq = 1048
current_ts = 273.026276
current_received_ts = 273.025879
current_seq = 1049
count = 109
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.026276
last_received_ts = 273.025879
last_seq = 1049
current_ts = 273.042938
current_received_ts = 273.042816
current_seq = 1050
count = 110
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 56us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.042938
last_received_ts = 273.042816
last_seq = 1050
current_ts = 273.059601
current_received_ts = 273.059204
current_seq = 1051
count = 111
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.059601
last_received_ts = 273.059204
last_seq = 1051
current_ts = 273.076263
current_received_ts = 273.076202
current_seq = 1052
count = 112
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 53us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.076263
last_received_ts = 273.076202
last_seq = 1052
current_ts = 273.092926
current_received_ts = 273.092590
current_seq = 1053
count = 113
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 50us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.092926
last_received_ts = 273.092590
last_seq = 1053
current_ts = 273.109589
current_received_ts = 273.109344
current_seq = 1054
count = 114
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 49us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.109589
last_received_ts = 273.109344
last_seq = 1054
current_ts = 273.126251
current_received_ts = 273.125977
current_seq = 1055
count = 115
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 48us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.126251
last_received_ts = 273.125977
last_seq = 1055
current_ts = 273.142944
current_received_ts = 273.142548
current_seq = 1056
count = 116
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 40us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.142944
last_received_ts = 273.142548
last_seq = 1056
current_ts = 273.159607
current_received_ts = 273.159332
current_seq = 1057
count = 117
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.159607
last_received_ts = 273.159332
last_seq = 1057
current_ts = 273.176270
current_received_ts = 273.175964
current_seq = 1058
count = 118
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 42us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.176270
last_received_ts = 273.175964
last_seq = 1058
current_ts = 273.192932
current_received_ts = 273.192505
current_seq = 1059
count = 119
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.192932
last_received_ts = 273.192505
last_seq = 1059
current_ts = 273.209595
current_received_ts = 273.209198
current_seq = 1060
count = 120
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 33us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.209595
last_received_ts = 273.209198
last_seq = 1060
current_ts = 273.226257
current_received_ts = 273.225952
current_seq = 1061
count = 121
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.226257
last_received_ts = 273.225952
last_seq = 1061
current_ts = 273.242920
current_received_ts = 273.242493
current_seq = 1062
count = 122
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 35us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.242920
last_received_ts = 273.242493
last_seq = 1062
current_ts = 273.259583
current_received_ts = 273.259277
current_seq = 1063
count = 123
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.259583
last_received_ts = 273.259277
last_seq = 1063
current_ts = 273.276276
current_received_ts = 273.275848
current_seq = 1064
count = 124
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 35us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.276276
last_received_ts = 273.275848
last_seq = 1064
current_ts = 273.292938
current_received_ts = 273.292450
current_seq = 1065
count = 125
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 33us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.292938
last_received_ts = 273.292450
last_seq = 1065
current_ts = 273.309601
current_received_ts = 273.309296
current_seq = 1066
count = 126
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.309601
last_received_ts = 273.309296
last_seq = 1066
current_ts = 273.326263
current_received_ts = 273.325836
current_seq = 1067
count = 127
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 36us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.326263
last_received_ts = 273.325836
last_seq = 1067
current_ts = 273.342926
current_received_ts = 273.342621
current_seq = 1068
count = 128
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.342926
last_received_ts = 273.342621
last_seq = 1068
current_ts = 273.359589
current_received_ts = 273.359192
current_seq = 1069
count = 129
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 36us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.359589
last_received_ts = 273.359192
last_seq = 1069
current_ts = 273.376282
current_received_ts = 273.376068
current_seq = 1070
count = 130
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.376282
last_received_ts = 273.376068
last_seq = 1070
current_ts = 273.392944
current_received_ts = 273.392578
current_seq = 1071
count = 131
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 47us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.392944
last_received_ts = 273.392578
last_seq = 1071
current_ts = 273.409607
current_received_ts = 273.409241
current_seq = 1072
count = 132
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.409607
last_received_ts = 273.409241
last_seq = 1072
current_ts = 273.426270
current_received_ts = 273.425995
current_seq = 1073
count = 133
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.426270
last_received_ts = 273.425995
last_seq = 1073
current_ts = 273.442932
current_received_ts = 273.442566
current_seq = 1074
count = 134
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.442932
last_received_ts = 273.442566
last_seq = 1074
current_ts = 273.459595
current_received_ts = 273.459351
current_seq = 1075
count = 135
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.459595
last_received_ts = 273.459351
last_seq = 1075
current_ts = 273.476257
current_received_ts = 273.476013
current_seq = 1076
count = 136
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 47us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.476257
last_received_ts = 273.476013
last_seq = 1076
current_ts = 273.492950
current_received_ts = 273.492523
current_seq = 1077
count = 137
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 40us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.492950
last_received_ts = 273.492523
last_seq = 1077
current_ts = 273.509583
current_received_ts = 273.509308
current_seq = 1078
count = 138
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.509583
last_received_ts = 273.509308
last_seq = 1078
current_ts = 273.526276
current_received_ts = 273.525909
current_seq = 1079
count = 139
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 33us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.526276
last_received_ts = 273.525909
last_seq = 1079
current_ts = 273.542938
current_received_ts = 273.542816
current_seq = 1080
count = 140
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 52us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.542938
last_received_ts = 273.542816
last_seq = 1080
current_ts = 273.559601
current_received_ts = 273.559235
current_seq = 1081
count = 141
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 40us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.559601
last_received_ts = 273.559235
last_seq = 1081
current_ts = 273.576263
current_received_ts = 273.575928
current_seq = 1082
count = 142
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 84us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.576263
last_received_ts = 273.575928
last_seq = 1082
current_ts = 273.592926
current_received_ts = 273.592590
current_seq = 1083
count = 143
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 47us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.592926
last_received_ts = 273.592590
last_seq = 1083
current_ts = 273.609589
current_received_ts = 273.609222
current_seq = 1084
count = 144
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.609589
last_received_ts = 273.609222
last_seq = 1084
current_ts = 273.626251
current_received_ts = 273.626007
current_seq = 1085
count = 145
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 44us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.626251
last_received_ts = 273.626007
last_seq = 1085
current_ts = 273.642944
current_received_ts = 273.642548
current_seq = 1086
count = 146
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.642944
last_received_ts = 273.642548
last_seq = 1086
current_ts = 273.659607
current_received_ts = 273.659363
current_seq = 1087
count = 147
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.659607
last_received_ts = 273.659363
last_seq = 1087
current_ts = 273.676270
current_received_ts = 273.675995
current_seq = 1088
count = 148
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 43us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.676270
last_received_ts = 273.675995
last_seq = 1088
current_ts = 273.692932
current_received_ts = 273.692505
current_seq = 1089
count = 149
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 34us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.692932
last_received_ts = 273.692505
last_seq = 1089
current_ts = 273.709595
current_received_ts = 273.709381
current_seq = 1090
count = 150
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 44us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.709595
last_received_ts = 273.709381
last_seq = 1090
current_ts = 273.726288
current_received_ts = 273.725891
current_seq = 1091
count = 151
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 36us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.726288
last_received_ts = 273.725891
last_seq = 1091
current_ts = 273.742950
current_received_ts = 273.742676
current_seq = 1092
count = 152
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.742950
last_received_ts = 273.742676
last_seq = 1092
current_ts = 273.759613
current_received_ts = 273.759247
current_seq = 1093
count = 153
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 36us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.759613
last_received_ts = 273.759247
last_seq = 1093
current_ts = 273.776276
current_received_ts = 273.775909
current_seq = 1094
count = 154
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 34us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.776276
last_received_ts = 273.775909
last_seq = 1094
current_ts = 273.792938
current_received_ts = 273.792633
current_seq = 1095
count = 155
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 54us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.792938
last_received_ts = 273.792633
last_seq = 1095
current_ts = 273.809601
current_received_ts = 273.809265
current_seq = 1096
count = 156
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 40us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.809601
last_received_ts = 273.809265
last_seq = 1096
current_ts = 273.826263
current_received_ts = 273.826019
current_seq = 1097
count = 157
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.826263
last_received_ts = 273.826019
last_seq = 1097
current_ts = 273.842926
current_received_ts = 273.842560
current_seq = 1098
count = 158
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.842926
last_received_ts = 273.842560
last_seq = 1098
current_ts = 273.859619
current_received_ts = 273.859344
current_seq = 1099
count = 159
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 43us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.859619
last_received_ts = 273.859344
last_seq = 1099
current_ts = 273.876282
current_received_ts = 273.876007
current_seq = 1100
count = 160
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 42us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.876282
last_received_ts = 273.876007
last_seq = 1100
current_ts = 273.892944
current_received_ts = 273.892548
current_seq = 1101
count = 161
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.892944
last_received_ts = 273.892548
last_seq = 1101
current_ts = 273.909607
current_received_ts = 273.909363
current_seq = 1102
count = 162
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 46us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.909607
last_received_ts = 273.909363
last_seq = 1102
current_ts = 273.926300
current_received_ts = 273.925903
current_seq = 1103
count = 163
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.926300
last_received_ts = 273.925903
last_seq = 1103
current_ts = 273.942963
current_received_ts = 273.942688
current_seq = 1104
count = 164
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.942963
last_received_ts = 273.942688
last_seq = 1104
current_ts = 273.959625
current_received_ts = 273.959229
current_seq = 1105
count = 165
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.959625
last_received_ts = 273.959229
last_seq = 1105
current_ts = 273.976288
current_received_ts = 273.976196
current_seq = 1106
count = 166
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 67us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.976288
last_received_ts = 273.976196
last_seq = 1106
current_ts = 273.992950
current_received_ts = 273.992554
current_seq = 1107
count = 167
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 42us
(kms_flip:2533) DEBUG: name = flip
last_ts = 273.992950
last_received_ts = 273.992554
last_seq = 1107
current_ts = 274.009613
current_received_ts = 274.009308
current_seq = 1108
count = 168
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.009613
last_received_ts = 274.009308
last_seq = 1108
current_ts = 274.026276
current_received_ts = 274.025879
current_seq = 1109
count = 169
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 33us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.026276
last_received_ts = 274.025879
last_seq = 1109
current_ts = 274.042938
current_received_ts = 274.042664
current_seq = 1110
count = 170
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.042938
last_received_ts = 274.042664
last_seq = 1110
current_ts = 274.059631
current_received_ts = 274.059204
current_seq = 1111
count = 171
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.059631
last_received_ts = 274.059204
last_seq = 1111
current_ts = 274.076294
current_received_ts = 274.075989
current_seq = 1112
count = 172
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.076294
last_received_ts = 274.075989
last_seq = 1112
current_ts = 274.092957
current_received_ts = 274.092468
current_seq = 1113
count = 173
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 35us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.092957
last_received_ts = 274.092468
last_seq = 1113
current_ts = 274.109619
current_received_ts = 274.109314
current_seq = 1114
count = 174
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 44us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.109619
last_received_ts = 274.109314
last_seq = 1114
current_ts = 274.126282
current_received_ts = 274.126129
current_seq = 1115
count = 175
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 49us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.126282
last_received_ts = 274.126129
last_seq = 1115
current_ts = 274.142975
current_received_ts = 274.142792
current_seq = 1116
count = 176
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 49us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.142975
last_received_ts = 274.142792
last_seq = 1116
current_ts = 274.159607
current_received_ts = 274.159454
current_seq = 1117
count = 177
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.159607
last_received_ts = 274.159454
last_seq = 1117
current_ts = 274.176300
current_received_ts = 274.175995
current_seq = 1118
count = 178
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.176300
last_received_ts = 274.175995
last_seq = 1118
current_ts = 274.192963
current_received_ts = 274.192596
current_seq = 1119
count = 179
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.192963
last_received_ts = 274.192596
last_seq = 1119
current_ts = 274.209625
current_received_ts = 274.209320
current_seq = 1120
count = 180
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.209625
last_received_ts = 274.209320
last_seq = 1120
current_ts = 274.226288
current_received_ts = 274.226044
current_seq = 1121
count = 181
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.226288
last_received_ts = 274.226044
last_seq = 1121
current_ts = 274.242950
current_received_ts = 274.242859
current_seq = 1122
count = 182
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 53us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.242950
last_received_ts = 274.242859
last_seq = 1122
current_ts = 274.259613
current_received_ts = 274.259247
current_seq = 1123
count = 183
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.259613
last_received_ts = 274.259247
last_seq = 1123
current_ts = 274.276306
current_received_ts = 274.275909
current_seq = 1124
count = 184
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 33us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.276306
last_received_ts = 274.275909
last_seq = 1124
current_ts = 274.292969
current_received_ts = 274.292694
current_seq = 1125
count = 185
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 52us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.292969
last_received_ts = 274.292694
last_seq = 1125
current_ts = 274.309631
current_received_ts = 274.309265
current_seq = 1126
count = 186
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.309631
last_received_ts = 274.309265
last_seq = 1126
current_ts = 274.326294
current_received_ts = 274.326019
current_seq = 1127
count = 187
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.326294
last_received_ts = 274.326019
last_seq = 1127
current_ts = 274.342957
current_received_ts = 274.342590
current_seq = 1128
count = 188
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 36us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.342957
last_received_ts = 274.342590
last_seq = 1128
current_ts = 274.359650
current_received_ts = 274.359375
current_seq = 1129
count = 189
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 45us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.359650
last_received_ts = 274.359375
last_seq = 1129
current_ts = 274.376282
current_received_ts = 274.376160
current_seq = 1130
count = 190
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 48us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.376282
last_received_ts = 274.376160
last_seq = 1130
current_ts = 274.392975
current_received_ts = 274.392639
current_seq = 1131
count = 191
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 51us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.392975
last_received_ts = 274.392639
last_seq = 1131
current_ts = 274.409637
current_received_ts = 274.409393
current_seq = 1132
count = 192
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 51us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.409637
last_received_ts = 274.409393
last_seq = 1132
current_ts = 274.426300
current_received_ts = 274.426056
current_seq = 1133
count = 193
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 51us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.426300
last_received_ts = 274.426056
last_seq = 1133
current_ts = 274.442963
current_received_ts = 274.442749
current_seq = 1134
count = 194
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 50us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.442963
last_received_ts = 274.442749
last_seq = 1134
current_ts = 274.459625
current_received_ts = 274.459381
current_seq = 1135
count = 195
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 51us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.459625
last_received_ts = 274.459381
last_seq = 1135
current_ts = 274.476318
current_received_ts = 274.475983
current_seq = 1136
count = 196
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.476318
last_received_ts = 274.475983
last_seq = 1136
current_ts = 274.492981
current_received_ts = 274.492523
current_seq = 1137
count = 197
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 33us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.492981
last_received_ts = 274.492523
last_seq = 1137
current_ts = 274.509644
current_received_ts = 274.509521
current_seq = 1138
count = 198
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 54us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.509644
last_received_ts = 274.509521
last_seq = 1138
current_ts = 274.526306
current_received_ts = 274.526062
current_seq = 1139
count = 199
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 37us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.526306
last_received_ts = 274.526062
last_seq = 1139
current_ts = 274.542969
current_received_ts = 274.542755
current_seq = 1140
count = 200
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 54us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.542969
last_received_ts = 274.542755
last_seq = 1140
current_ts = 274.559631
current_received_ts = 274.559265
current_seq = 1141
count = 201
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 40us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.559631
last_received_ts = 274.559265
last_seq = 1141
current_ts = 274.576294
current_received_ts = 274.576233
current_seq = 1142
count = 202
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 63us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.576294
last_received_ts = 274.576233
last_seq = 1142
current_ts = 274.592987
current_received_ts = 274.592529
current_seq = 1143
count = 203
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.592987
last_received_ts = 274.592529
last_seq = 1143
current_ts = 274.609619
current_received_ts = 274.609375
current_seq = 1144
count = 204
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 44us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.609619
last_received_ts = 274.609375
last_seq = 1144
current_ts = 274.626312
current_received_ts = 274.625916
current_seq = 1145
count = 205
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 38us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.626312
last_received_ts = 274.625916
last_seq = 1145
current_ts = 274.642975
current_received_ts = 274.642853
current_seq = 1146
count = 206
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 54us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.642975
last_received_ts = 274.642853
last_seq = 1146
current_ts = 274.659637
current_received_ts = 274.659302
current_seq = 1147
count = 207
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 49us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.659637
last_received_ts = 274.659302
last_seq = 1147
current_ts = 274.676300
current_received_ts = 274.676086
current_seq = 1148
count = 208
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 48us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.676300
last_received_ts = 274.676086
last_seq = 1148
current_ts = 274.692963
current_received_ts = 274.692657
current_seq = 1149
count = 209
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 48us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.692963
last_received_ts = 274.692657
last_seq = 1149
current_ts = 274.709625
current_received_ts = 274.709259
current_seq = 1150
count = 210
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 49us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.709625
last_received_ts = 274.709259
last_seq = 1150
current_ts = 274.726318
current_received_ts = 274.726044
current_seq = 1151
count = 211
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 49us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.726318
last_received_ts = 274.726044
last_seq = 1151
current_ts = 274.742981
current_received_ts = 274.742615
current_seq = 1152
count = 212
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 39us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.742981
last_received_ts = 274.742615
last_seq = 1152
current_ts = 274.759644
current_received_ts = 274.759338
current_seq = 1153
count = 213
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 44us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.759644
last_received_ts = 274.759338
last_seq = 1153
current_ts = 274.776306
current_received_ts = 274.776062
current_seq = 1154
count = 214
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 195us
(kms_flip:2533) DEBUG: name = flip
last_ts = 274.776306
last_received_ts = 274.776062
last_seq = 1154
current_ts = 274.792969
current_received_ts = 274.792999
current_seq = 1155
count = 215
seq_step = 1
(kms_flip:2533) DEBUG: Vblank took 765us
(kms_flip:2533) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:924:
(kms_flip:2533) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2533) igt_core-INFO: Stack trace:
(kms_flip:2533) igt_core-INFO:   #0 ../lib/igt_core.c:2051 __igt_fail_assert()
(kms_flip:2533) igt_core-INFO:   #1 ../tests/kms_flip.c:919 run_test_on_crtc_set.constprop.0()
(kms_flip:2533) igt_core-INFO:   #2 ../tests/kms_flip.c:1845 run_test()
(kms_flip:2533) igt_core-INFO:   #3 ../tests/kms_flip.c:2078 __igt_unique____real_main2001()
(kms_flip:2533) igt_core-INFO:   #4 ../tests/kms_flip.c:2001 main()
(kms_flip:2533) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2533) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2533) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest D-DP2: FAIL (5.328s)
Dmesg
<6> [284.282524] [IGT] kms_flip: starting dynamic subtest D-DP2
<7> [284.284751] xe 0000:03:00.0: [drm:drm_mode_addfb2 [drm]] [FB:289]
<7> [284.286102] xe 0000:03:00.0: [drm:drm_mode_addfb2 [drm]] [FB:291]
<7> [284.349281] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:82:pipe A]
<7> [284.349940] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:134:pipe B]
<7> [284.350174] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:186:pipe C]
<7> [284.350346] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.enable (expected yes, found no)
<7> [284.350576] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.active (expected yes, found no)
<7> [284.350782] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in cpu_transcoder (expected 2, found -1)
<7> [284.350969] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in lane_count (expected 4, found 0)
<7> [284.351158] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] 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> [284.351346] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in output_types (expected 0x00000080, found 0x00000000)
<7> [284.351530] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [284.351711] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [284.351893] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [284.352051] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [284.352211] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [284.352360] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [284.352508] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [284.352655] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [284.352800] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [284.352944] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [284.353083] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [284.353247] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [284.353387] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [284.353519] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [284.353650] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [284.353784] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [284.353912] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [284.354038] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [284.354167] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [284.354294] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [284.354418] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [284.354542] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [284.354660] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [284.354778] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [284.354895] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [284.355014] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [284.355128] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [284.355245] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [284.355363] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in enhanced_framing (expected yes, found no)
<7> [284.355477] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in pipe_bpp (expected 36, found 0)
<7> [284.355588] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [284.355699] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [284.355810] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:186:pipe C] fastset requirement not met in port_clock (expected 270000, found 0)
<7> [284.355915] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:186:pipe C] fastset requirement not met, forcing full modeset
<7> [284.356106] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xd -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [284.356203] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:186:pipe C] dbuf slices 0xc -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x4 -> 0x0
<7> [284.356338] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:181:cursor C] ddb (1989 - 2048) -> ( 0 - 0), size 59 -> 0
<7> [284.356453] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 652800 kHz, actual 652800 kHz
<7> [284.356559] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 3, actual 3
<7> [284.356681] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:186:pipe C] enable: no [modeset]
<7> [284.356787] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:136:plane 1C] fb: [NOFB], visible: no
<7> [284.356895] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:145:plane 2C] fb: [NOFB], visible: no
<7> [284.356995] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:154:plane 3C] fb: [NOFB], visible: no
<7> [284.357096] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:163:plane 4C] fb: [NOFB], visible: no
<7> [284.357299] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:172:plane 5C] fb: [NOFB], visible: no
<7> [284.357403] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:181:cursor C] fb: [NOFB], visible: no
<7> [284.357895] 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:186:pipe C]
<7> [284.376262] xe 0000:03:00.0: [drm:i915_audio_component_get_eld [xe]] Not valid for port E
<7> [284.376669] xe 0000:03:00.0: [drm:intel_disable_transcoder [xe]] disabling pipe C
<7> [284.393544] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2
<7> [284.396101] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:240:DDI TC1/PHY F]
<7> [284.396506] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:242:DP-MST A]
<7> [284.396856] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:243:DP-MST B]
<7> [284.397239] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:244:DP-MST C]
<7> [284.397556] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:245:DP-MST D]
<7> [284.397874] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:259:DDI TC2/PHY G]
<7> [284.398190] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:261:DP-MST A]
<7> [284.398493] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:262:DP-MST B]
<7> [284.398789] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:263:DP-MST C]
<7> [284.399082] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:264:DP-MST D]
<7> [284.399371] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:271:DDI TC3/PHY H]
<7> [284.399659] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:275:DDI TC4/PHY I]
<7> [284.399947] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:277:DP-MST A]
<7> [284.400238] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:278:DP-MST B]
<7> [284.400530] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:279:DP-MST C]
<7> [284.400829] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:280:DP-MST D]
<7> [284.400970] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:260:DP-2]
<7> [284.401032] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)
<7> [284.401105] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1
<7> [284.401256] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_C
<7> [284.401384] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling PW_2
<7> [284.401490] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:186:pipe C]
<7> [284.401570] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:238:pipe D]
<7> [284.401996] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CRTC:238:pipe D]
<7> [284.402027] xe 0000:03:00.0: [drm:drm_mode_setcrtc [drm]] [CONNECTOR:260:DP-2]
<7> [284.402093] xe 0000:03:00.0: [drm:intel_dp_compute_config_link_bpp_limits [xe]] [ENCODER:259:DDI TC2/PHY G][CRTC:238:pipe D] 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> [284.402158] 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> [284.402222] xe 0000:03:00.0: [drm:intel_psr_compute_config [xe]] PSR disabled by flag
<7> [284.402277] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:238:pipe D] hw max bpp: 36, pipe bpp: 36, dithering: 0
<7> [284.402343] xe 0000:03:00.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:259:DDI TC2/PHY G] [CRTC:238:pipe D]
<7> [284.402408] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.enable (expected no, found yes)
<7> [284.402473] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.active (expected no, found yes)
<7> [284.402538] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in cpu_transcoder (expected -1, found 3)
<7> [284.402598] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in lane_count (expected 0, found 4)
<7> [284.402659] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] 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> [284.402719] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in output_types (expected 0x00000000, found 0x00000080)
<7> [284.402778] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [284.402837] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [284.402896] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [284.402955] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [284.403013] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [284.403071] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [284.403129] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [284.403188] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [284.403247] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [284.403305] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [284.403364] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [284.403422] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [284.403480] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [284.403538] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [284.403597] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [284.403655] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [284.403712] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [284.403769] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [284.403827] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [284.403884] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [284.403943] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [284.404000] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [284.404058] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [284.404116] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [284.404173] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [284.404231] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [284.404289] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [284.404347] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [284.404405] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in enhanced_framing (expected no, found yes)
<7> [284.404463] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in dpll_hw_state.cx0pll C20
<7> [284.404520] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] expected:
<7> [284.404576] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] c20pll_hw_state:
<7> [284.404639] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] tx[0] = 0xbe88, tx[1] = 0x9800, tx[2] = 0x0000
<7> [284.404701] 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> [284.404761] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[0] = 0x40e8
<7> [284.404822] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[1] = 0x7d20
<7> [284.404880] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[2] = 0x0a06
<7> [284.404937] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[3] = 0x8f1c
<7> [284.404995] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[4] = 0x0000
<7> [284.405054] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[5] = 0x0000
<7> [284.405112] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[6] = 0x2200
<7> [284.405180] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[7] = 0xffff
<7> [284.405246] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[8] = 0x0400
<7> [284.405307] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[9] = 0x0000
<7> [284.405367] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[10] = 0x0001
<7> [284.405427] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] found:
<7> [284.405490] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] c20pll_hw_state:
<7> [284.405550] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] tx[0] = 0xbe88, tx[1] = 0x4800, tx[2] = 0x0000
<7> [284.405609] 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> [284.405668] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[0] = 0x308c
<7> [284.405727] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[1] = 0x2110
<7> [284.405785] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[2] = 0xcc9c
<7> [284.405843] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[3] = 0xbfc1
<7> [284.405901] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[4] = 0x4b9a
<7> [284.405958] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[5] = 0x3f81
<7> [284.406015] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[6] = 0x2000
<7> [284.406072] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[7] = 0x0001
<7> [284.406129] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[8] = 0x5000
<7> [284.406185] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[9] = 0x0000
<7> [284.406244] xe 0000:03:00.0: [drm:intel_cx0pll_dump_hw_state [xe]] mpllb[10] = 0x0000
<7> [284.406304] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in pipe_bpp (expected 0, found 36)
<7> [284.406367] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [284.406429] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [284.406488] xe 0000:03:00.0: [drm:intel_pipe_config_compare [xe]] [CRTC:238:pipe D] fastset requirement not met in port_clock (expected 0, found 270000)
<7> [284.406548] xe 0000:03:00.0: [drm:intel_atomic_check [xe]] [CRTC:238:pipe D] fastset requirement not met, forcing full modeset
<7> [284.406696] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [284.406752] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [CRTC:238:pipe D] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x8
<7> [284.406833] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:188:plane 1D] ddb ( 0 - 0) -> ( 0 - 1989), size 0 -> 1989
<7> [284.406888] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:233:cursor D] ddb ( 0 - 0) -> (1989 - 2048), size 0 -> 59
<7> [284.406942] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:188:plane 1D] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5, wm6, wm7,*twm,*swm,*stwm
<7> [284.406993] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:188:plane 1D] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 7, 11, 17, 17, 17, 17, 0, 15, 0
<7> [284.407046] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:188:plane 1D] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 113, 177, 273, 273, 273, 273, 30, 241, 255
<7> [284.407098] xe 0000:03:00.0: [drm:skl_compute_wm [xe]] [PLANE:188:plane 1D] 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> [284.407149] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] [CRTC:238:pipe D] data rate 594000 num active planes 1
<7> [284.407215] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 33600 required 594 qgv_peak_bw: 48000
<7> [284.407280] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 53000 required 594 qgv_peak_bw: 48000
<7> [284.407344] xe 0000:03:00.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 48000 for required data rate: 594
<7> [284.407414] xe 0000:03:00.0: [drm:intel_plane_calc_min_cdclk [xe]] [PLANE:188:plane 1D] min cdclk (74250 kHz) > [CRTC:238:pipe D] min cdclk (0 kHz)
<7> [284.407479] xe 0000:03:00.0: [drm:intel_bw_calc_min_cdclk [xe]] new bandwidth min cdclk (11602 kHz) > old min cdclk (0 kHz)
<7> [284.407545] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New cdclk calculated to be logical 652800 kHz, actual 652800 kHz
<7> [284.407608] xe 0000:03:00.0: [drm:intel_modeset_calc_cdclk [xe]] New voltage level calculated to be logical 3, actual 3
<7> [284.407678] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [CRTC:238:pipe D] enable: yes [modeset]
<7> [284.407741] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: DP (0x80), output format: RGB, sink format: RGB
<7> [284.407804] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: D, pipe bpp: 36, dithering: 0
<7> [284.407863] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid>
<7> [284.407922] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [284.407980] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0
<7> [284.408039] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0
<7> [284.408098] 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> [284.408156] 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> [284.408213] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: enabled
<7> [284.408271] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled
<7> [284.408329] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] psr: disabled, selective update: disabled, panel replay: disabled, selective fetch: disabled
<7> [284.408386] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0
<7> [284.408444] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] audio: 1, infoframes: 0, infoframes enabled: 0x0
<7> [284.408502] ELD: 10 00 09 00 68 36 00 01 00 00 00 00 00 00 00 00
<7> [284.408503] ELD: 61 a4 9a 00 44 50 46 39 30 34 33 35 09 07 07 11
<7> [284.408504] ELD: 17 50 51 07 00 00 00 00
<7> [284.408505] 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> [284.408563] 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> [284.408621] 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> [284.408678] 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> [284.408736] 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> [284.408793] 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> [284.408851] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] port clock: 270000, pipe src: 1920x1080+0+0, pixel rate 148500
<7> [284.408908] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] linetime: 119, ips linetime: 0
<7> [284.408965] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0
<7> [284.409022] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [284.409078] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0
<7> [284.409135] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] dpll_hw_state: dpll: 0x41eb0, dpll_md: 0x4800be88, fp0: 0x5000000, fp1: 0x5
<7> [284.409217] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [284.409282] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [284.409341] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [284.409400] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [284.409459] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [284.409517] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [284.409575] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [284.409630] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [284.409686] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [284.409743] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [284.409798] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [284.409855] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [284.409911] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:188:plane 1D] fb: [FB:289] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [284.409968] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [284.410025] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [284.410082] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:197:plane 2D] fb: [NOFB], visible: no
<7> [284.410138] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:206:plane 3D] fb: [NOFB], visible: no
<7> [284.410194] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:215:plane 4D] fb: [NOFB], visible: no
<7> [284.410249] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:224:plane 5D] fb: [NOFB], visible: no
<7> [284.410304] xe 0000:03:00.0: [drm:intel_crtc_state_dump [xe]] [PLANE:233:cursor D] fb: [NOFB], visible: no
<7> [284.410746] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_2
<7> [284.410847] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling PW_D
<7> [284.410975] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:240:DDI TC1/PHY F]
<7> [284.411031] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:242:DP-MST A]
<7> [284.411085] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:243:DP-MST B]
<7> [284.411138] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:244:DP-MST C]
<7> [284.411189] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:245:DP-MST D]
<7> [284.411241] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:259:DDI TC2/PHY G]
<7> [284.411294] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:261:DP-MST A]
<7> [284.411344] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:262:DP-MST B]
<7> [284.411397] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:263:DP-MST C]
<7> [284.411450] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:264:DP-MST D]
<7> [284.411503] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:271:DDI TC3/PHY H]
<7> [284.411554] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:275:DDI TC4/PHY I]
<7> [284.411604] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:277:DP-MST A]
<7> [284.411653] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:278:DP-MST B]
<7> [284.411703] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:279:DP-MST C]
<7> [284.411753] xe 0000:03:00.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:280:DP-MST D]
<7> [284.411802] xe 0000:03:00.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x3
<7> [284.411929] xe 0000:03:00.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 2 (mbus joined: no)
<7> [284.415815] 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> [284.422040] 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> [284.423282] 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> [284.423644] 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> [284.424535] 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> [284.424858] 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> [284.434266] 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> [284.434352] 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> [284.442302] 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> [284.442449] 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> [284.443165] xe 0000:03:00.0: [drm:intel_enable_transcoder [xe]] enabling pipe D
<7> [284.460438] 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:238:pipe D], 40 bytes ELD
<7> [284.477070] xe 0000:03:00.0: [drm:verify_connector_state [xe]] [CONNECTOR:260:DP-2]
<7> [284.477610] xe 0000:03:00.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:238:pipe D]
<7> [284.545295] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2
<7> [286.473455] xe 0000:03:00.0: [drm:intel_power_well_enable [xe]] enabling AUX_TC2
<7> [286.577357] xe 0000:03:00.0: [drm:intel_power_well_disable [xe]] disabling AUX_TC2
<6> [289.612037] [IGT] kms_flip: finished subtest D-DP2, FAIL
Created at 2024-10-16 03:18:23