Results for igt@kms_flip@flip-vs-expired-vblank-interruptible@d-hdmi-a3

Result: Fail

integration-manifest git-log-oneline i915_display_info4 igt_runner4 runtimes4 results4.json results4-i915-load.json guc_logs4.tar i915_display_info_post_exec4 boot4 dmesg4

DetailValue
Duration 3.94 seconds
Hostname 
shard-dg2-5
Igt-Version 
IGT-Version: 2.4-g4568b2c14 (x86_64) (Linux: 7.1.0-rc1-Patchwork_165604v1-gaea2c496abcf+ x86_64)
Out 
Starting dynamic subtest: D-HDMI-A3
  1920x1080: 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5 
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
  #2 ../tests/kms_flip.c:1920 run_test()
  #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
  #4 ../tests/kms_flip.c:2105 main()
  #5 [__libc_init_first+0x8a]
  #6 [__libc_start_main+0x8b]
  #7 [_start+0x25]
Dynamic subtest D-HDMI-A3: FAIL (3.942s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (27.107s)
Stack trace:
  #0 ../lib/igt_core.c:2075 __igt_fail_assert()
  #1 ../lib/igt_kms.c:2352 kmstest_set_connector_dpms()
  #2 ../lib/igt_core.c:2961 igt_atexit_handler()
  #3 [erand48_r+0x1d6]
  #4 [exit+0x1e]
  #5 ../lib/igt_core.c:2416 igt_exit()
  #6 [main+0x3f]
  #7 [__libc_init_first+0x8a]
  #8 [__libc_start_main+0x8b]
  #9 [_start+0x25]
Err 
Starting dynamic subtest: D-HDMI-A3
(kms_flip:2157) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2157) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2157) CRITICAL: Last errno: 4, Interrupted system call
Dynamic subtest D-HDMI-A3 failed.
**** DEBUG ****
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.651642
last_received_ts = 313.651306
last_seq = 107
current_ts = 313.668335
current_received_ts = 313.667969
current_seq = 108
count = 101
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 84us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.668335
last_received_ts = 313.667969
last_seq = 108
current_ts = 313.684998
current_received_ts = 313.684601
current_seq = 109
count = 102
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.684998
last_received_ts = 313.684601
last_seq = 109
current_ts = 313.701660
current_received_ts = 313.701294
current_seq = 110
count = 103
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.701660
last_received_ts = 313.701294
last_seq = 110
current_ts = 313.718323
current_received_ts = 313.717957
current_seq = 111
count = 104
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 93us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.718323
last_received_ts = 313.717957
last_seq = 111
current_ts = 313.734985
current_received_ts = 313.734558
current_seq = 112
count = 105
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.734985
last_received_ts = 313.734558
last_seq = 112
current_ts = 313.751648
current_received_ts = 313.751312
current_seq = 113
count = 106
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.751648
last_received_ts = 313.751312
last_seq = 113
current_ts = 313.768311
current_received_ts = 313.767944
current_seq = 114
count = 107
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 81us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.768311
last_received_ts = 313.767944
last_seq = 114
current_ts = 313.785004
current_received_ts = 313.784515
current_seq = 115
count = 108
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.785004
last_received_ts = 313.784515
last_seq = 115
current_ts = 313.801666
current_received_ts = 313.801300
current_seq = 116
count = 109
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.801666
last_received_ts = 313.801300
last_seq = 116
current_ts = 313.818329
current_received_ts = 313.817963
current_seq = 117
count = 110
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 90us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.818329
last_received_ts = 313.817963
last_seq = 117
current_ts = 313.834991
current_received_ts = 313.834625
current_seq = 118
count = 111
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.834991
last_received_ts = 313.834625
last_seq = 118
current_ts = 313.851654
current_received_ts = 313.851318
current_seq = 119
count = 112
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.851654
last_received_ts = 313.851318
last_seq = 119
current_ts = 313.868347
current_received_ts = 313.867981
current_seq = 120
count = 113
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 94us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.868347
last_received_ts = 313.867981
last_seq = 120
current_ts = 313.885010
current_received_ts = 313.884644
current_seq = 121
count = 114
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.885010
last_received_ts = 313.884644
last_seq = 121
current_ts = 313.901672
current_received_ts = 313.901306
current_seq = 122
count = 115
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.901672
last_received_ts = 313.901306
last_seq = 122
current_ts = 313.918335
current_received_ts = 313.917877
current_seq = 123
count = 116
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.918335
last_received_ts = 313.917877
last_seq = 123
current_ts = 313.934998
current_received_ts = 313.934631
current_seq = 124
count = 117
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.934998
last_received_ts = 313.934631
last_seq = 124
current_ts = 313.951660
current_received_ts = 313.951324
current_seq = 125
count = 118
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.951660
last_received_ts = 313.951324
last_seq = 125
current_ts = 313.968353
current_received_ts = 313.968048
current_seq = 126
count = 119
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.968353
last_received_ts = 313.968048
last_seq = 126
current_ts = 313.985016
current_received_ts = 313.984650
current_seq = 127
count = 120
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 313.985016
last_received_ts = 313.984650
last_seq = 127
current_ts = 314.001678
current_received_ts = 314.001282
current_seq = 128
count = 121
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.001678
last_received_ts = 314.001282
last_seq = 128
current_ts = 314.018341
current_received_ts = 314.017975
current_seq = 129
count = 122
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 57us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.018341
last_received_ts = 314.017975
last_seq = 129
current_ts = 314.035004
current_received_ts = 314.034637
current_seq = 130
count = 123
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.035004
last_received_ts = 314.034637
last_seq = 130
current_ts = 314.051666
current_received_ts = 314.051300
current_seq = 131
count = 124
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.051666
last_received_ts = 314.051300
last_seq = 131
current_ts = 314.068359
current_received_ts = 314.067993
current_seq = 132
count = 125
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.068359
last_received_ts = 314.067993
last_seq = 132
current_ts = 314.085022
current_received_ts = 314.084656
current_seq = 133
count = 126
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.085022
last_received_ts = 314.084656
last_seq = 133
current_ts = 314.101685
current_received_ts = 314.101318
current_seq = 134
count = 127
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.101685
last_received_ts = 314.101318
last_seq = 134
current_ts = 314.118347
current_received_ts = 314.117981
current_seq = 135
count = 128
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.118347
last_received_ts = 314.117981
last_seq = 135
current_ts = 314.135010
current_received_ts = 314.134674
current_seq = 136
count = 129
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.135010
last_received_ts = 314.134674
last_seq = 136
current_ts = 314.151703
current_received_ts = 314.151306
current_seq = 137
count = 130
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.151703
last_received_ts = 314.151306
last_seq = 137
current_ts = 314.168365
current_received_ts = 314.167969
current_seq = 138
count = 131
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.168365
last_received_ts = 314.167969
last_seq = 138
current_ts = 314.185028
current_received_ts = 314.184662
current_seq = 139
count = 132
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.185028
last_received_ts = 314.184662
last_seq = 139
current_ts = 314.201691
current_received_ts = 314.201324
current_seq = 140
count = 133
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.201691
last_received_ts = 314.201324
last_seq = 140
current_ts = 314.218353
current_received_ts = 314.218048
current_seq = 141
count = 134
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.218353
last_received_ts = 314.218048
last_seq = 141
current_ts = 314.235046
current_received_ts = 314.234650
current_seq = 142
count = 135
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.235046
last_received_ts = 314.234650
last_seq = 142
current_ts = 314.251709
current_received_ts = 314.251282
current_seq = 143
count = 136
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.251709
last_received_ts = 314.251282
last_seq = 143
current_ts = 314.268372
current_received_ts = 314.268036
current_seq = 144
count = 137
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 57us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.268372
last_received_ts = 314.268036
last_seq = 144
current_ts = 314.285034
current_received_ts = 314.284668
current_seq = 145
count = 138
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.285034
last_received_ts = 314.284668
last_seq = 145
current_ts = 314.301697
current_received_ts = 314.301331
current_seq = 146
count = 139
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.301697
last_received_ts = 314.301331
last_seq = 146
current_ts = 314.318359
current_received_ts = 314.318024
current_seq = 147
count = 140
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.318359
last_received_ts = 314.318024
last_seq = 147
current_ts = 314.335052
current_received_ts = 314.334656
current_seq = 148
count = 141
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.335052
last_received_ts = 314.334656
last_seq = 148
current_ts = 314.351715
current_received_ts = 314.351318
current_seq = 149
count = 142
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.351715
last_received_ts = 314.351318
last_seq = 149
current_ts = 314.368378
current_received_ts = 314.368042
current_seq = 150
count = 143
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.368378
last_received_ts = 314.368042
last_seq = 150
current_ts = 314.385040
current_received_ts = 314.384674
current_seq = 151
count = 144
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.385040
last_received_ts = 314.384674
last_seq = 151
current_ts = 314.401703
current_received_ts = 314.401306
current_seq = 152
count = 145
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.401703
last_received_ts = 314.401306
last_seq = 152
current_ts = 314.418396
current_received_ts = 314.418030
current_seq = 153
count = 146
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 57us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.418396
last_received_ts = 314.418030
last_seq = 153
current_ts = 314.435059
current_received_ts = 314.434692
current_seq = 154
count = 147
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.435059
last_received_ts = 314.434692
last_seq = 154
current_ts = 314.451721
current_received_ts = 314.451294
current_seq = 155
count = 148
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.451721
last_received_ts = 314.451294
last_seq = 155
current_ts = 314.468384
current_received_ts = 314.468079
current_seq = 156
count = 149
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.468384
last_received_ts = 314.468079
last_seq = 156
current_ts = 314.485046
current_received_ts = 314.484680
current_seq = 157
count = 150
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.485046
last_received_ts = 314.484680
last_seq = 157
current_ts = 314.501709
current_received_ts = 314.501312
current_seq = 158
count = 151
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.501709
last_received_ts = 314.501312
last_seq = 158
current_ts = 314.518402
current_received_ts = 314.518036
current_seq = 159
count = 152
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.518402
last_received_ts = 314.518036
last_seq = 159
current_ts = 314.535065
current_received_ts = 314.534698
current_seq = 160
count = 153
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.535065
last_received_ts = 314.534698
last_seq = 160
current_ts = 314.551727
current_received_ts = 314.551300
current_seq = 161
count = 154
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.551727
last_received_ts = 314.551300
last_seq = 161
current_ts = 314.568390
current_received_ts = 314.568085
current_seq = 162
count = 155
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.568390
last_received_ts = 314.568085
last_seq = 162
current_ts = 314.585052
current_received_ts = 314.584656
current_seq = 163
count = 156
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.585052
last_received_ts = 314.584656
last_seq = 163
current_ts = 314.601746
current_received_ts = 314.601318
current_seq = 164
count = 157
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.601746
last_received_ts = 314.601318
last_seq = 164
current_ts = 314.618408
current_received_ts = 314.618042
current_seq = 165
count = 158
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.618408
last_received_ts = 314.618042
last_seq = 165
current_ts = 314.635071
current_received_ts = 314.634705
current_seq = 166
count = 159
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.635071
last_received_ts = 314.634705
last_seq = 166
current_ts = 314.651733
current_received_ts = 314.651306
current_seq = 167
count = 160
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.651733
last_received_ts = 314.651306
last_seq = 167
current_ts = 314.668396
current_received_ts = 314.667999
current_seq = 168
count = 161
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.668396
last_received_ts = 314.667999
last_seq = 168
current_ts = 314.685059
current_received_ts = 314.684692
current_seq = 169
count = 162
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.685059
last_received_ts = 314.684692
last_seq = 169
current_ts = 314.701721
current_received_ts = 314.701324
current_seq = 170
count = 163
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.701721
last_received_ts = 314.701324
last_seq = 170
current_ts = 314.718414
current_received_ts = 314.718048
current_seq = 171
count = 164
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.718414
last_received_ts = 314.718048
last_seq = 171
current_ts = 314.735077
current_received_ts = 314.734711
current_seq = 172
count = 165
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.735077
last_received_ts = 314.734711
last_seq = 172
current_ts = 314.751740
current_received_ts = 314.751312
current_seq = 173
count = 166
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.751740
last_received_ts = 314.751312
last_seq = 173
current_ts = 314.768402
current_received_ts = 314.768066
current_seq = 174
count = 167
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.768402
last_received_ts = 314.768066
last_seq = 174
current_ts = 314.785095
current_received_ts = 314.784698
current_seq = 175
count = 168
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.785095
last_received_ts = 314.784698
last_seq = 175
current_ts = 314.801727
current_received_ts = 314.801331
current_seq = 176
count = 169
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 86us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.801727
last_received_ts = 314.801331
last_seq = 176
current_ts = 314.818420
current_received_ts = 314.818085
current_seq = 177
count = 170
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.818420
last_received_ts = 314.818085
last_seq = 177
current_ts = 314.835083
current_received_ts = 314.834686
current_seq = 178
count = 171
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.835083
last_received_ts = 314.834686
last_seq = 178
current_ts = 314.851746
current_received_ts = 314.851318
current_seq = 179
count = 172
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.851746
last_received_ts = 314.851318
last_seq = 179
current_ts = 314.868408
current_received_ts = 314.868073
current_seq = 180
count = 173
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 104us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.868408
last_received_ts = 314.868073
last_seq = 180
current_ts = 314.885101
current_received_ts = 314.884552
current_seq = 181
count = 174
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 33us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.885101
last_received_ts = 314.884552
last_seq = 181
current_ts = 314.901764
current_received_ts = 314.901215
current_seq = 182
count = 175
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 35us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.901764
last_received_ts = 314.901215
last_seq = 182
current_ts = 314.918427
current_received_ts = 314.917908
current_seq = 183
count = 176
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 34us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.918427
last_received_ts = 314.917908
last_seq = 183
current_ts = 314.935089
current_received_ts = 314.934540
current_seq = 184
count = 177
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 32us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.935089
last_received_ts = 314.934540
last_seq = 184
current_ts = 314.951752
current_received_ts = 314.951233
current_seq = 185
count = 178
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 33us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.951752
last_received_ts = 314.951233
last_seq = 185
current_ts = 314.968445
current_received_ts = 314.967896
current_seq = 186
count = 179
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 33us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.968445
last_received_ts = 314.967896
last_seq = 186
current_ts = 314.985107
current_received_ts = 314.984650
current_seq = 187
count = 180
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 33us
(kms_flip:2157) DEBUG: name = flip
last_ts = 314.985107
last_received_ts = 314.984650
last_seq = 187
current_ts = 315.001770
current_received_ts = 315.001221
current_seq = 188
count = 181
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 34us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.001770
last_received_ts = 315.001221
last_seq = 188
current_ts = 315.018433
current_received_ts = 315.017883
current_seq = 189
count = 182
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 33us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.018433
last_received_ts = 315.017883
last_seq = 189
current_ts = 315.035095
current_received_ts = 315.034668
current_seq = 190
count = 183
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 32us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.035095
last_received_ts = 315.034668
last_seq = 190
current_ts = 315.051788
current_received_ts = 315.051239
current_seq = 191
count = 184
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 33us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.051788
last_received_ts = 315.051239
last_seq = 191
current_ts = 315.068420
current_received_ts = 315.067902
current_seq = 192
count = 185
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 37us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.068420
last_received_ts = 315.067902
last_seq = 192
current_ts = 315.085114
current_received_ts = 315.084686
current_seq = 193
count = 186
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 46us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.085114
last_received_ts = 315.084686
last_seq = 193
current_ts = 315.101776
current_received_ts = 315.101349
current_seq = 194
count = 187
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.101776
last_received_ts = 315.101349
last_seq = 194
current_ts = 315.118439
current_received_ts = 315.118164
current_seq = 195
count = 188
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.118439
last_received_ts = 315.118164
last_seq = 195
current_ts = 315.135101
current_received_ts = 315.134735
current_seq = 196
count = 189
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.135101
last_received_ts = 315.134735
last_seq = 196
current_ts = 315.151764
current_received_ts = 315.151337
current_seq = 197
count = 190
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.151764
last_received_ts = 315.151337
last_seq = 197
current_ts = 315.168457
current_received_ts = 315.168121
current_seq = 198
count = 191
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 58us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.168457
last_received_ts = 315.168121
last_seq = 198
current_ts = 315.185120
current_received_ts = 315.184753
current_seq = 199
count = 192
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.185120
last_received_ts = 315.184753
last_seq = 199
current_ts = 315.201782
current_received_ts = 315.201355
current_seq = 200
count = 193
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.201782
last_received_ts = 315.201355
last_seq = 200
current_ts = 315.218445
current_received_ts = 315.218079
current_seq = 201
count = 194
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.218445
last_received_ts = 315.218079
last_seq = 201
current_ts = 315.235107
current_received_ts = 315.234589
current_seq = 202
count = 195
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 32us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.235107
last_received_ts = 315.234589
last_seq = 202
current_ts = 315.251770
current_received_ts = 315.251282
current_seq = 203
count = 196
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 34us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.251770
last_received_ts = 315.251282
last_seq = 203
current_ts = 315.268433
current_received_ts = 315.268036
current_seq = 204
count = 197
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 35us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.268433
last_received_ts = 315.268036
last_seq = 204
current_ts = 315.285126
current_received_ts = 315.284698
current_seq = 205
count = 198
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 38us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.285126
last_received_ts = 315.284698
last_seq = 205
current_ts = 315.301788
current_received_ts = 315.301270
current_seq = 206
count = 199
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 43us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.301788
last_received_ts = 315.301270
last_seq = 206
current_ts = 315.318451
current_received_ts = 315.318176
current_seq = 207
count = 200
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 57us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.318451
last_received_ts = 315.318176
last_seq = 207
current_ts = 315.335114
current_received_ts = 315.334747
current_seq = 208
count = 201
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.335114
last_received_ts = 315.334747
last_seq = 208
current_ts = 315.351807
current_received_ts = 315.351379
current_seq = 209
count = 202
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.351807
last_received_ts = 315.351379
last_seq = 209
current_ts = 315.368469
current_received_ts = 315.368134
current_seq = 210
count = 203
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.368469
last_received_ts = 315.368134
last_seq = 210
current_ts = 315.385132
current_received_ts = 315.384766
current_seq = 211
count = 204
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.385132
last_received_ts = 315.384766
last_seq = 211
current_ts = 315.401794
current_received_ts = 315.401367
current_seq = 212
count = 205
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.401794
last_received_ts = 315.401367
last_seq = 212
current_ts = 315.418457
current_received_ts = 315.418121
current_seq = 213
count = 206
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.418457
last_received_ts = 315.418121
last_seq = 213
current_ts = 315.435150
current_received_ts = 315.434753
current_seq = 214
count = 207
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 56us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.435150
last_received_ts = 315.434753
last_seq = 214
current_ts = 315.451813
current_received_ts = 315.451385
current_seq = 215
count = 208
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.451813
last_received_ts = 315.451385
last_seq = 215
current_ts = 315.468475
current_received_ts = 315.468140
current_seq = 216
count = 209
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.468475
last_received_ts = 315.468140
last_seq = 216
current_ts = 315.485138
current_received_ts = 315.484741
current_seq = 217
count = 210
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.485138
last_received_ts = 315.484741
last_seq = 217
current_ts = 315.501801
current_received_ts = 315.501404
current_seq = 218
count = 211
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.501801
last_received_ts = 315.501404
last_seq = 218
current_ts = 315.518463
current_received_ts = 315.518127
current_seq = 219
count = 212
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.518463
last_received_ts = 315.518127
last_seq = 219
current_ts = 315.535156
current_received_ts = 315.534729
current_seq = 220
count = 213
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.535156
last_received_ts = 315.534729
last_seq = 220
current_ts = 315.551819
current_received_ts = 315.551422
current_seq = 221
count = 214
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.551819
last_received_ts = 315.551422
last_seq = 221
current_ts = 315.568481
current_received_ts = 315.568146
current_seq = 222
count = 215
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.568481
last_received_ts = 315.568146
last_seq = 222
current_ts = 315.585144
current_received_ts = 315.584778
current_seq = 223
count = 216
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 87us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.585144
last_received_ts = 315.584778
last_seq = 223
current_ts = 315.601807
current_received_ts = 315.601410
current_seq = 224
count = 217
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.601807
last_received_ts = 315.601410
last_seq = 224
current_ts = 315.618469
current_received_ts = 315.618073
current_seq = 225
count = 218
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.618469
last_received_ts = 315.618073
last_seq = 225
current_ts = 315.635132
current_received_ts = 315.634796
current_seq = 226
count = 219
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 54us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.635132
last_received_ts = 315.634796
last_seq = 226
current_ts = 315.651825
current_received_ts = 315.651398
current_seq = 227
count = 220
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 55us
(kms_flip:2157) DEBUG: name = flip
last_ts = 315.651825
last_received_ts = 315.651398
last_seq = 227
current_ts = 315.668488
current_received_ts = 315.667969
current_seq = 228
count = 221
seq_step = 1
(kms_flip:2157) DEBUG: Vblank took 898us
(kms_flip:2157) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:931:
(kms_flip:2157) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2157) CRITICAL: Last errno: 4, Interrupted system call
(kms_flip:2157) igt_core-INFO: Stack trace:
(kms_flip:2157) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2157) igt_core-INFO:   #1 ../tests/kms_flip.c:926 run_test_on_crtc_set()
(kms_flip:2157) igt_core-INFO:   #2 ../tests/kms_flip.c:1920 run_test()
(kms_flip:2157) igt_core-INFO:   #3 ../tests/kms_flip.c:2220 __igt_unique____real_main2105()
(kms_flip:2157) igt_core-INFO:   #4 ../tests/kms_flip.c:2105 main()
(kms_flip:2157) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2157) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2157) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest D-HDMI-A3: FAIL (3.942s)
Subtest flip-vs-expired-vblank-interruptible: FAIL (27.107s)
(kms_flip:2157) igt_kms-CRITICAL: Test assertion failure function kmstest_set_connector_dpms, file ../lib/igt_kms.c:2352:
(kms_flip:2157) igt_kms-CRITICAL: Failed assertion: found_it
(kms_flip:2157) igt_kms-CRITICAL: Last errno: 9, Bad file descriptor
(kms_flip:2157) igt_kms-CRITICAL: DPMS property not found on 556
Dmesg
<6> [311.502123] [IGT] kms_flip: starting dynamic subtest D-HDMI-A3
<7> [311.502491] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:561]
<7> [311.502649] i915 0000:03:00.0: [drm:drm_mode_addfb2] [FB:563]
<7> [311.503036] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.503435] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.525901] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.526237] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.531814] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.532126] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.551751] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.552069] [drm:eb_validate_vma [i915]] EINVAL at eb_validate_vma:509
<7> [311.558500] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:151:pipe A]
<7> [311.558694] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:269:pipe C]
<7> [311.558812] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe B]
<7> [311.558900] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.enable (expected yes, found no)
<7> [311.559100] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.active (expected yes, found no)
<7> [311.559270] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in cpu_transcoder (expected 1, found -1)
<7> [311.559436] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in lane_count (expected 4, found 0)
<7> [311.559682] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [311.559902] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [311.560068] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [311.560238] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [311.560405] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [311.560597] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [311.560846] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [311.561014] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [311.561181] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [311.561348] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [311.561517] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [311.561725] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [311.561891] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [311.562059] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [311.562225] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [311.562391] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [311.562557] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [311.563184] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [311.563360] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [311.563529] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [311.563734] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [311.563900] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [311.564067] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [311.564232] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [311.564401] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [311.564567] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [311.564771] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [311.564940] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [311.565110] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [311.565277] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [311.565445] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [311.565672] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [311.565839] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:387:pipe B] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [311.566009] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:387:pipe B] fastset requirement not met, forcing full modeset
<7> [311.566196] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x3 -> 0x1 (total dbuf slices 0xf), mbus joined? no->no
<7> [311.566357] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:387:pipe B] dbuf slices 0x3 -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x2 -> 0x0
<7> [311.566544] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:381:cursor B] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [311.566766] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:387:pipe B] min cdclk: 74250 kHz -> 0 kHz
<7> [311.566933] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [311.567098] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [311.567263] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:387:pipe B] enable: no [modeset]
<7> [311.567429] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:271:plane 1B] fb: [NOFB], visible: no
<7> [311.567632] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:301:plane 2B] fb: [NOFB], visible: no
<7> [311.567798] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:331:plane 3B] fb: [NOFB], visible: no
<7> [311.567963] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:361:plane 4B] fb: [NOFB], visible: no
<7> [311.568128] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:371:plane 5B] fb: [NOFB], visible: no
<7> [311.568295] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:381:cursor B] fb: [NOFB], visible: no
<7> [311.568578] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe B
<7> [311.585790] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [311.586042] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [311.586207] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [311.586372] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [311.586538] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [311.586711] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [311.586878] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [311.587045] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [311.587209] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [311.587373] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [311.587537] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [311.587740] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [311.587905] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [311.588068] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [311.588232] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [311.588397] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [311.588561] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [311.588783] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [311.588947] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [311.589112] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [311.589276] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [311.589440] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [311.589683] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x1
<7> [311.589960] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_B
<7> [311.590189] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_2
<7> [311.590400] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:387:pipe B]
<7> [311.590814] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [311.590983] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CRTC:505:pipe D]
<7> [311.591014] i915 0000:03:00.0: [drm:drm_mode_setcrtc] [CONNECTOR:556:HDMI-A-3]
<7> [311.591088] i915 0000:03:00.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [311.591309] i915 0000:03:00.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [311.591466] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [311.591677] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:505:pipe D]
<7> [311.591836] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.enable (expected no, found yes)
<7> [311.592006] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.active (expected no, found yes)
<7> [311.592173] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in cpu_transcoder (expected -1, found 3)
<7> [311.592339] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in lane_count (expected 0, found 4)
<7> [311.592507] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [311.592712] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [311.592879] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [311.593045] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [311.593215] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [311.593383] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [311.593549] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [311.593754] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [311.593920] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [311.594085] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [311.594252] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [311.594418] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [311.594608] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [311.594789] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [311.594954] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [311.595121] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [311.595287] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [311.595453] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [311.595659] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [311.595826] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [311.595992] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [311.596159] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [311.596324] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [311.596491] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [311.596728] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [311.596894] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [311.597059] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [311.597227] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [311.597394] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [311.597560] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [311.597815] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [311.597982] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [311.598148] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [311.598316] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] fastset requirement not met, forcing full modeset
<7> [311.598507] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0x1 -> 0xd (total dbuf slices 0xf), mbus joined? no->no
<7> [311.598711] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:505:pipe D] dbuf slices 0x0 -> 0xc, ddb (0 - 0) -> (0 - 2048), active pipes 0x0 -> 0x8
<7> [311.598899] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:389:plane 1D] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [311.599060] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:499:cursor D] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [311.599222] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389: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> [311.599383] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [311.599543] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0
<7> [311.599742] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0
<7> [311.599920] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:505:pipe D] data rate 594000 num active planes 1
<7> [311.600085] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [311.600249] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [311.600426] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:505:pipe D] min cdclk: 0 kHz -> 74250 kHz
<7> [311.600647] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New cdclk calculated to be logical 163200 kHz, actual 163200 kHz
<7> [311.600844] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] New voltage level calculated to be logical 0, actual 0
<7> [311.601012] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:505:pipe D] enable: yes [modeset]
<7> [311.601177] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [311.601344] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: D, pipe bpp: 24, dithering: 0
<7> [311.601511] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [311.601716] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [311.601882] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [311.602049] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [311.602215] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [311.602381] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [311.602546] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [311.602749] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 41, vsync end: 36
<7> [311.602915] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125
<7> [311.603080] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [311.603247] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [311.603414] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [311.603603] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [311.603784] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [311.603949] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [311.604115] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [311.604280] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [311.604445] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [311.604648] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [311.604814] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [311.604980] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [311.605145] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [311.605310] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [311.605475] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [311.605713] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [311.605878] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [311.606044] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [311.606210] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [311.606376] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [311.606541] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [311.606742] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [311.606906] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [311.607071] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [311.607235] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [311.607400] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [311.607565] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:389:plane 1D] fb: [FB:561] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes
<7> [311.607774] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [311.607939] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [311.608105] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:419:plane 2D] fb: [NOFB], visible: no
<7> [311.608270] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:449:plane 3D] fb: [NOFB], visible: no
<7> [311.608435] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:479:plane 4D] fb: [NOFB], visible: no
<7> [311.608670] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:489:plane 5D] fb: [NOFB], visible: no
<7> [311.608737] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DC_off
<7> [311.608901] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:499:cursor D] fb: [NOFB], visible: no
<7> [311.608974] i915 0000:03:00.0: [drm:gen9_enable_dc5 [i915]] Enabling DC5
<7> [311.609152] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 00 to 01
<7> [311.609684] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DC_off
<7> [311.609976] i915 0000:03:00.0: [drm:gen9_set_dc_state.part.0 [i915]] Setting DC state from 01 to 00
<7> [311.610330] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_2
<7> [311.610520] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_D
<7> [311.610777] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [311.610942] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [311.611107] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [311.611271] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [311.611437] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [311.611637] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [311.611801] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [311.611966] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [311.612131] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [311.612294] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [311.612459] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [311.612661] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [311.612825] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [311.612990] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [311.613155] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [311.613318] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [311.613497] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [311.613670] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [311.613839] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [311.614006] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [311.614176] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xd
<7> [311.614539] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [311.614843] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe D
<7> [311.633923] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [311.634196] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:505:pipe D]
<6> [315.446925] [IGT] kms_flip: finished subtest D-HDMI-A3, FAIL
<6> [315.447745] [IGT] kms_flip: finished subtest flip-vs-expired-vblank-interruptible, FAIL
<7> [315.454669] i915 0000:03:00.0: [drm:drm_mode_rmfb_work_fn] Removing [FB:563] from all active usage due to RMFB ioctl
<7> [315.455276] i915 0000:03:00.0: [drm:atomic_remove_fb] Disabling [PLANE:389:plane 1D] because [FB:563] is removed
<7> [315.455895] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:389:plane 1D] ddb ( 0 - 1963) -> ( 0 - 0), size 1963 -> 0
<7> [315.456874] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389: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> [315.457369] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] lines 4, 4, 4, 5, 9, 11, 17, 25, 0, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [315.457845] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] blocks 62, 62, 62, 78, 139, 169, 261, 383, 137, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [315.458323] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:389:plane 1D] min_ddb 123, 123, 123, 184, 245, 245, 367, 489, 138, 0, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
<7> [315.458967] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:505:pipe D] data rate 0 num active planes 0
<7> [315.459467] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 0
<7> [315.459949] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<6> [315.468447] [IGT] kms_flip: exiting, ret=98
<7> [315.481470] i915 0000:03:00.0: [drm:compute_baseline_pipe_bpp [i915]] [CONNECTOR:556:HDMI-A-3] Limiting target display pipe bpp to 24 (EDID bpp 0, max requested bpp 36, max platform bpp 36)
<7> [315.481743] i915 0000:03:00.0: [drm:intel_hdmi_compute_output_format [i915]] picking 8 bpc for HDMI output (pipe bpp: 24)
<7> [315.481901] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] hw max bpp: 24, pipe bpp: 24, dithering: 0
<7> [315.482086] i915 0000:03:00.0: [drm:intel_ddi_compute_config_late [i915]] [ENCODER:547:DDI D/PHY D] [CRTC:151:pipe A]
<7> [315.482245] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.enable (expected no, found yes)
<7> [315.482423] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.active (expected no, found yes)
<7> [315.482593] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0)
<7> [315.482760] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in lane_count (expected 0, found 4)
<7> [315.482927] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000040)
<7> [315.483094] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1)
<7> [315.483263] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 1920)
<7> [315.483474] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 2200)
<7> [315.483641] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 1920)
<7> [315.483812] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 2200)
<7> [315.483978] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2008)
<7> [315.484144] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2052)
<7> [315.484311] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1080)
<7> [315.484672] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1080)
<7> [315.484840] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1084)
<7> [315.485009] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1089)
<7> [315.485176] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1125)
<7> [315.485605] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1125)
<7> [315.485775] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 1920)
<7> [315.485942] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 2200)
<7> [315.486108] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 1920)
<7> [315.486275] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 2200)
<7> [315.486694] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2008)
<7> [315.486862] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2052)
<7> [315.487028] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1080)
<7> [315.487195] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1080)
<7> [315.487835] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1084)
<7> [315.488006] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1089)
<7> [315.488175] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1125)
<7> [315.488365] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1125)
<7> [315.488545] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1)
<7> [315.488713] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 0, found 1)
<7> [315.488880] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 0, found 4)
<7> [315.489047] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 24)
<7> [315.489214] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 148500)
<7> [315.489387] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 148500)
<7> [315.489558] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:151:pipe A] fastset requirement not met in port_clock (expected 0, found 148500)
<7> [315.489726] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:151:pipe A] fastset requirement not met, forcing full modeset
<7> [315.489892] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.enable (expected yes, found no)
<7> [315.490059] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.active (expected yes, found no)
<7> [315.490226] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in cpu_transcoder (expected 3, found -1)
<7> [315.490460] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in lane_count (expected 4, found 0)
<7> [315.490626] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in output_types (expected 0x00000040, found 0x00000000)
<7> [315.490793] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in framestart_delay (expected 1, found 0)
<7> [315.490959] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 1920, found 0)
<7> [315.491126] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 2200, found 0)
<7> [315.491292] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 1920, found 0)
<7> [315.491499] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 2200, found 0)
<7> [315.491665] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2008, found 0)
<7> [315.491831] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2052, found 0)
<7> [315.491998] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1080, found 0)
<7> [315.492165] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1080, found 0)
<7> [315.492338] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1084, found 0)
<7> [315.492566] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1089, found 0)
<7> [315.492732] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1125, found 0)
<7> [315.492898] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1125, found 0)
<7> [315.493064] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 1920, found 0)
<7> [315.493230] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 2200, found 0)
<7> [315.493457] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 1920, found 0)
<7> [315.493625] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 2200, found 0)
<7> [315.493791] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2008, found 0)
<7> [315.493958] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2052, found 0)
<7> [315.494124] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1080, found 0)
<7> [315.494290] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1080, found 0)
<7> [315.494501] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1084, found 0)
<7> [315.494668] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1089, found 0)
<7> [315.494836] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1125, found 0)
<7> [315.495003] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1125, found 0)
<7> [315.495170] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pixel_multiplier (expected 1, found 0)
<7> [315.495362] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (1) (expected 1, found 0)
<7> [315.495543] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.flags (4) (expected 4, found 0)
<7> [315.495709] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in pipe_bpp (expected 24, found 0)
<7> [315.495876] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 148500, found 0)
<7> [315.496043] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 148500, found 0)
<7> [315.496209] i915 0000:03:00.0: [drm:intel_pipe_config_compare [i915]] [CRTC:505:pipe D] fastset requirement not met in port_clock (expected 148500, found 0)
<7> [315.496417] i915 0000:03:00.0: [drm:intel_atomic_check [i915]] [CRTC:505:pipe D] fastset requirement not met, forcing full modeset
<7> [315.496619] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] Enabled dbuf slices 0xd -> 0x3 (total dbuf slices 0xf), mbus joined? no->no
<7> [315.496783] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:151:pipe A] dbuf slices 0x0 -> 0x3, ddb (0 - 0) -> (0 - 2048), active pipes 0x8 -> 0x1
<7> [315.496944] i915 0000:03:00.0: [drm:skl_compute_wm [i915]] [CRTC:505:pipe D] dbuf slices 0xc -> 0x0, ddb (0 - 2048) -> (0 - 0), active pipes 0x8 -> 0x1
<7> [315.497109] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:35:plane 1A] ddb ( 0 - 0) -> ( 0 - 1963), size 0 -> 1963
<7> [315.497272] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:145:cursor A] ddb ( 0 - 0) -> (1963 - 2048), size 0 -> 85
<7> [315.497507] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] level wm0, wm1, wm2, wm3, wm4, wm5, wm6, wm7, twm, swm, stwm -> *wm0,*wm1,*wm2,*wm3,*wm4,*wm5,*wm6,*wm7,*twm, swm, stwm
<7> [315.497668] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 1, 3, 4, 5, 9, 11, 17, 25, 0, 0, 0
<7> [315.497829] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 16, 49, 65, 81, 145, 177, 273, 401, 30, 0, 0
<7> [315.497990] i915 0000:03:00.0: [drm:skl_print_plane_wm_changes [i915]] [PLANE:35:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 19, 55, 73, 91, 161, 196, 302, 443, 31, 0, 0
<7> [315.498154] i915 0000:03:00.0: [drm:skl_print_plane_ddb_changes [i915]] [PLANE:499:cursor D] ddb (1963 - 2048) -> ( 0 - 0), size 85 -> 0
<7> [315.498342] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] [CRTC:151:pipe A] data rate 594000 num active planes 1
<7> [315.498546] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] QGV point 0: max bw 50000 required 624
<7> [315.498710] i915 0000:03:00.0: [drm:intel_bw_atomic_check [i915]] No SAGV, using single QGV point mask 0x1
<7> [315.498891] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:151:pipe A] min cdclk: 0 kHz -> 74250 kHz
<7> [315.499057] i915 0000:03:00.0: [drm:intel_cdclk_atomic_check [i915]] [CRTC:505:pipe D] min cdclk: 74250 kHz -> 0 kHz
<7> [315.499244] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:151:pipe A] enable: yes [modeset]
<7> [315.499450] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] active: yes, output_types: HDMI (0x40), output format: RGB, sink format: RGB
<7> [315.499617] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] cpu_transcoder: A, pipe bpp: 24, dithering: 0
<7> [315.499782] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] MST master transcoder: <invalid>
<7> [315.499948] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0
<7> [315.500113] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] joiner: no, pipes: 0x0
<7> [315.500279] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] splitter: disabled, link count 0, overlap 0
<7> [315.500487] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] audio: 0, infoframes: 0, infoframes enabled: 0x0
<7> [315.500652] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] scanline offset: 2
<7> [315.500818] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] framestart delay: 1, MSA timing delay: 0, set context latency: 0
<7> [315.500983] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: no, fixed rr: yes, vmin: 1125, vmax: 1125, flipline: 1125, pipeline full: 0, guardband: 45 vsync start: 41, vsync end: 36
<7> [315.501150] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: vmin vblank: 1080, vmax vblank: 1080, vmin vtotal: 1125, vmax vtotal: 1125
<7> [315.501316] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0
<7> [315.501605] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] requested mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [315.501773] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] adjusted mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x48 0x5
<7> [315.501940] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [315.502107] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe mode: "1920x1080": 60 148500 1920 2008 2052 2200 1080 1084 1089 1125 0x40 0x5
<7> [315.502273] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] 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> [315.502517] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] port clock: 148500, pixel rate 148500, min cdclk 74250, min voltage level 0
<7> [315.502685] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] linetime: 119, ips linetime: 0
<7> [315.502850] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0, sharpness_strength: 0
<7> [315.503016] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe src: 1920x1080+0+0
<7> [315.503182] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pch pfit: 0x0+0+0, disabled, force thru: no
<7> [315.503391] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0
<7> [315.503585] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] ips: 0, double wide: 0, drrs: 0
<7> [315.503750] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] dpll_hw_state: dpll: 0x24414, dpll_md: 0x18000000, fp0: 0x8801ef8, fp1: 0x2b000440
<7> [315.503915] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0
<7> [315.504081] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pre csc lut: 0 entries, post csc lut: 0 entries
<7> [315.504246] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: pre offsets: 0x0000 0x0000 0x0000
<7> [315.504453] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [315.504623] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [315.504788] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: coefficients: 0x0000 0x0000 0x0000
<7> [315.504953] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] output csc: post offsets: 0x0000 0x0000 0x0000
<7> [315.505119] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: pre offsets: 0x0000 0x0000 0x0000
<7> [315.505284] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [315.505489] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [315.505654] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: coefficients: 0x0000 0x0000 0x0000
<7> [315.505818] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] pipe csc: post offsets: 0x0000 0x0000 0x0000
<7> [315.505983] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:35:plane 1A] fb: [FB:560] 1920x1080 format = XR24 little-endian (0x34325258) modifier = 0x0, visible: yes
<7> [315.506150] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] rotation: 0x1, scaler: -1, scaling_filter: 0
<7> [315.506315] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] src: 1920.000000x1080.000000+0.000000+0.000000 dst: 1920x1080+0+0
<7> [315.506523] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:65:plane 2A] fb: [NOFB], visible: no
<7> [315.506689] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:95:plane 3A] fb: [NOFB], visible: no
<7> [315.506856] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:125:plane 4A] fb: [NOFB], visible: no
<7> [315.507022] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:135:plane 5A] fb: [NOFB], visible: no
<7> [315.507187] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:145:cursor A] fb: [NOFB], visible: no
<7> [315.507380] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [CRTC:505:pipe D] enable: no [modeset]
<7> [315.507560] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:389:plane 1D] fb: [NOFB], visible: no
<7> [315.507727] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:419:plane 2D] fb: [NOFB], visible: no
<7> [315.507892] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:449:plane 3D] fb: [NOFB], visible: no
<7> [315.508059] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:479:plane 4D] fb: [NOFB], visible: no
<7> [315.508223] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:489:plane 5D] fb: [NOFB], visible: no
<7> [315.508396] i915 0000:03:00.0: [drm:intel_crtc_state_dump [i915]] [PLANE:499:cursor D] fb: [NOFB], visible: no
<7> [315.508678] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling PW_A
<7> [315.509004] i915 0000:03:00.0: [drm:intel_disable_transcoder [i915]] disabling pipe D
<7> [315.517451] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling DDI_IO_D
<7> [315.517690] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:507:DDI A/PHY A]
<7> [315.517856] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:509:DP-MST A]
<7> [315.518022] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:510:DP-MST B]
<7> [315.518187] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:511:DP-MST C]
<7> [315.518391] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:512:DP-MST D]
<7> [315.518604] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:520:DDI B/PHY B]
<7> [315.518769] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:522:DP-MST A]
<7> [315.518933] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:523:DP-MST B]
<7> [315.519097] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:524:DP-MST C]
<7> [315.519262] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:525:DP-MST D]
<7> [315.519496] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:535:DDI C/PHY C]
<7> [315.519662] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:537:DP-MST A]
<7> [315.519826] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:538:DP-MST B]
<7> [315.519991] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:539:DP-MST C]
<7> [315.520156] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:540:DP-MST D]
<7> [315.520320] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:547:DDI D/PHY D]
<7> [315.520525] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:549:DP-MST A]
<7> [315.520690] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:550:DP-MST B]
<7> [315.520854] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:551:DP-MST C]
<7> [315.521018] i915 0000:03:00.0: [drm:intel_modeset_verify_disabled [i915]] [ENCODER:552:DP-MST D]
<7> [315.521189] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0xf
<7> [315.521618] i915 0000:03:00.0: [drm:intel_power_well_enable [i915]] enabling DDI_IO_D
<7> [315.521917] i915 0000:03:00.0: [drm:intel_enable_transcoder [i915]] enabling pipe A
<7> [315.524424] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] reserved 17694720 bytes of contiguous stolen space for FBC, limit: 1
<7> [315.524596] i915 0000:03:00.0: [drm:intel_fbc_update [i915]] Enabling FBC on [PLANE:35:plane 1A]
<7> [315.540763] i915 0000:03:00.0: [drm:gen9_dbuf_slices_update [i915]] Updating dbuf slices to 0x3
<7> [315.541369] i915 0000:03:00.0: [drm:verify_connector_state [i915]] [CONNECTOR:556:HDMI-A-3]
<7> [315.541647] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:151:pipe A]
<7> [315.542645] i915 0000:03:00.0: [drm:intel_power_well_disable [i915]] disabling PW_D
<7> [315.542887] i915 0000:03:00.0: [drm:intel_modeset_verify_crtc [i915]] [CRTC:505:pipe D]
<7> [315.543454] i915 0000:03:00.0: [drm:drm_client_dev_restore] fbdev: ret=0
Created at 2026-04-28 16:15:39