igt@kms_flip@flip-vs-expired-vblank@a-edp1 on shard-lnl@xe-4375-0e1b1ce1c8adbc0a8ad1ee763a8a9eeaee297998 Test details

Detail	Value
Duration	3.19 seconds
Hostname	shard-lnl-7
Igt-Version	IGT-Version: 2.3-g0b67ab25f (x86_64) (Linux: 6.19.0-rc5-lgci-xe-xe-4375-0e1b1ce1c8adbc0a8+ x86_64)
Out	Using IGT_SRANDOM=1768321166 for randomisation Opened device: /dev/dri/card0 Using monotonic timestamps Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa Stack trace: #0 ../lib/igt_core.c:2075 __igt_fail_assert() #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() #2 ../tests/kms_flip.c:1889 run_test() #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() #4 ../tests/kms_flip.c:2045 main() #5 [__libc_init_first+0x8a] #6 [__libc_start_main+0x8b] #7 [_start+0x25] Dynamic subtest A-eDP1: FAIL (3.187s)
Err	Starting subtest: flip-vs-expired-vblank Starting dynamic subtest: A-eDP1 (kms_flip:2517) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2517) CRITICAL: Failed assertion: end - start < 500 Dynamic subtest A-eDP1 failed. ** DEBUG (kms_flip:2517) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2517) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=11520) (kms_flip:2517) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2517) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0) (kms_flip:2517) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2517) drmtest-DEBUG: Test requirement passed: is_intel_device(fd) (kms_flip:2517) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=11520) (kms_flip:2517) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd) (kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281d7490, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281d7490, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4590, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4590, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4470, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4470, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281da720, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281da720, fd: 5> objects: 3, reserved_areas: 0 (kms_flip:2517) igt_kms-INFO: 2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa (kms_flip:2517) DEBUG: No stale events found (kms_flip:2517) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0 (kms_flip:2517) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0 (kms_flip:2517) DEBUG: name = flip last_ts = 0.000000 last_received_ts = 0.000000 last_seq = 0 current_ts = 100.110405 current_received_ts = 100.109634 current_seq = 1001 count = 0 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 136us (kms_flip:2517) DEBUG: name = flip last_ts = 100.110405 last_received_ts = 100.109634 last_seq = 1001 current_ts = 100.127060 current_received_ts = 100.126358 current_seq = 1002 count = 1 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 45us (kms_flip:2517) DEBUG: name = flip last_ts = 100.127060 last_received_ts = 100.126358 last_seq = 1002 current_ts = 100.143723 current_received_ts = 100.143028 current_seq = 1003 count = 2 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 46us (kms_flip:2517) DEBUG: name = flip last_ts = 100.143723 last_received_ts = 100.143028 last_seq = 1003 current_ts = 100.160385 current_received_ts = 100.159653 current_seq = 1004 count = 3 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 34us (kms_flip:2517) DEBUG: name = flip last_ts = 100.160385 last_received_ts = 100.159653 last_seq = 1004 current_ts = 100.177055 current_received_ts = 100.176514 current_seq = 1005 count = 4 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 115us (kms_flip:2517) DEBUG: name = flip last_ts = 100.177055 last_received_ts = 100.176514 last_seq = 1005 current_ts = 100.193718 current_received_ts = 100.193169 current_seq = 1006 count = 5 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 32us (kms_flip:2517) DEBUG: name = flip last_ts = 100.193718 last_received_ts = 100.193169 last_seq = 1006 current_ts = 100.210373 current_received_ts = 100.209831 current_seq = 1007 count = 6 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 116us (kms_flip:2517) DEBUG: name = flip last_ts = 100.210373 last_received_ts = 100.209831 last_seq = 1007 current_ts = 100.227043 current_received_ts = 100.226524 current_seq = 1008 count = 7 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 125us (kms_flip:2517) DEBUG: name = flip last_ts = 100.227043 last_received_ts = 100.226524 last_seq = 1008 current_ts = 100.243698 current_received_ts = 100.243065 current_seq = 1009 count = 8 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 122us (kms_flip:2517) DEBUG: name = flip last_ts = 100.243698 last_received_ts = 100.243065 last_seq = 1009 current_ts = 100.260361 current_received_ts = 100.259583 current_seq = 1010 count = 9 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 120us (kms_flip:2517) DEBUG: name = flip last_ts = 100.260361 last_received_ts = 100.259583 last_seq = 1010 current_ts = 100.277023 current_received_ts = 100.276207 current_seq = 1011 count = 10 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 44us (kms_flip:2517) DEBUG: name = flip last_ts = 100.277023 last_received_ts = 100.276207 last_seq = 1011 current_ts = 100.293686 current_received_ts = 100.292908 current_seq = 1012 count = 11 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 118us (kms_flip:2517) DEBUG: name = flip last_ts = 100.293686 last_received_ts = 100.292908 last_seq = 1012 current_ts = 100.310349 current_received_ts = 100.309822 current_seq = 1013 count = 12 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 115us (kms_flip:2517) DEBUG: name = flip last_ts = 100.310349 last_received_ts = 100.309822 last_seq = 1013 current_ts = 100.327011 current_received_ts = 100.326202 current_seq = 1014 count = 13 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 44us (kms_flip:2517) DEBUG: name = flip last_ts = 100.327011 last_received_ts = 100.326202 last_seq = 1014 current_ts = 100.343674 current_received_ts = 100.343018 current_seq = 1015 count = 14 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 35us (kms_flip:2517) DEBUG: name = flip last_ts = 100.343674 last_received_ts = 100.343018 last_seq = 1015 current_ts = 100.360336 current_received_ts = 100.359634 current_seq = 1016 count = 15 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 131us (kms_flip:2517) DEBUG: name = flip last_ts = 100.360336 last_received_ts = 100.359634 last_seq = 1016 current_ts = 100.376991 current_received_ts = 100.376183 current_seq = 1017 count = 16 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 44us (kms_flip:2517) DEBUG: name = flip last_ts = 100.376991 last_received_ts = 100.376183 last_seq = 1017 current_ts = 100.393654 current_received_ts = 100.392876 current_seq = 1018 count = 17 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 132us (kms_flip:2517) DEBUG: name = flip last_ts = 100.393654 last_received_ts = 100.392876 last_seq = 1018 current_ts = 100.410324 current_received_ts = 100.409653 current_seq = 1019 count = 18 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 124us (kms_flip:2517) DEBUG: name = flip last_ts = 100.410324 last_received_ts = 100.409653 last_seq = 1019 current_ts = 100.426987 current_received_ts = 100.426170 current_seq = 1020 count = 19 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 42us (kms_flip:2517) DEBUG: name = flip last_ts = 100.426987 last_received_ts = 100.426170 last_seq = 1020 current_ts = 100.443642 current_received_ts = 100.442863 current_seq = 1021 count = 20 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 119us (kms_flip:2517) DEBUG: name = flip last_ts = 100.443642 last_received_ts = 100.442863 last_seq = 1021 current_ts = 100.460312 current_received_ts = 100.459770 current_seq = 1022 count = 21 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 30us (kms_flip:2517) DEBUG: name = flip last_ts = 100.460312 last_received_ts = 100.459770 last_seq = 1022 current_ts = 100.476967 current_received_ts = 100.476448 current_seq = 1023 count = 22 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 124us (kms_flip:2517) DEBUG: name = flip last_ts = 100.476967 last_received_ts = 100.476448 last_seq = 1023 current_ts = 100.493629 current_received_ts = 100.492958 current_seq = 1024 count = 23 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 52us (kms_flip:2517) DEBUG: name = flip last_ts = 100.493629 last_received_ts = 100.492958 last_seq = 1024 current_ts = 100.510292 current_received_ts = 100.509773 current_seq = 1025 count = 24 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 112us (kms_flip:2517) DEBUG: name = flip last_ts = 100.510292 last_received_ts = 100.509773 last_seq = 1025 current_ts = 100.526955 current_received_ts = 100.526260 current_seq = 1026 count = 25 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 29us (kms_flip:2517) DEBUG: name = flip last_ts = 100.526955 last_received_ts = 100.526260 last_seq = 1026 current_ts = 100.543617 current_received_ts = 100.543091 current_seq = 1027 count = 26 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 111us (kms_flip:2517) DEBUG: name = flip last_ts = 100.543617 last_received_ts = 100.543091 last_seq = 1027 current_ts = 100.560280 current_received_ts = 100.559753 current_seq = 1028 count = 27 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 118us (kms_flip:2517) DEBUG: name = flip last_ts = 100.560280 last_received_ts = 100.559753 last_seq = 1028 current_ts = 100.576942 current_received_ts = 100.576187 current_seq = 1029 count = 28 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 32us (kms_flip:2517) DEBUG: name = flip last_ts = 100.576942 last_received_ts = 100.576187 last_seq = 1029 current_ts = 100.593605 current_received_ts = 100.593079 current_seq = 1030 count = 29 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 51us (kms_flip:2517) DEBUG: name = flip last_ts = 100.593605 last_received_ts = 100.593079 last_seq = 1030 current_ts = 100.610268 current_received_ts = 100.609512 current_seq = 1031 count = 30 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 97us (kms_flip:2517) DEBUG: name = flip last_ts = 100.610268 last_received_ts = 100.609512 last_seq = 1031 current_ts = 100.626930 current_received_ts = 100.626183 current_seq = 1032 count = 31 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 115us (kms_flip:2517) DEBUG: name = flip last_ts = 100.626930 last_received_ts = 100.626183 last_seq = 1032 current_ts = 100.643593 current_received_ts = 100.642937 current_seq = 1033 count = 32 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 126us (kms_flip:2517) DEBUG: name = flip last_ts = 100.643593 last_received_ts = 100.642937 last_seq = 1033 current_ts = 100.660255 current_received_ts = 100.659485 current_seq = 1034 count = 33 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 115us (kms_flip:2517) DEBUG: name = flip last_ts = 100.660255 last_received_ts = 100.659485 last_seq = 1034 current_ts = 100.676918 current_received_ts = 100.676437 current_seq = 1035 count = 34 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 33us (kms_flip:2517) DEBUG: name = flip last_ts = 100.676918 last_received_ts = 100.676437 last_seq = 1035 current_ts = 100.693581 current_received_ts = 100.693062 current_seq = 1036 count = 35 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 29us (kms_flip:2517) DEBUG: name = flip last_ts = 100.693581 last_received_ts = 100.693062 last_seq = 1036 current_ts = 100.710236 current_received_ts = 100.709572 current_seq = 1037 count = 36 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 110us (kms_flip:2517) DEBUG: name = flip last_ts = 100.710236 last_received_ts = 100.709572 last_seq = 1037 current_ts = 100.726898 current_received_ts = 100.726395 current_seq = 1038 count = 37 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 111us (kms_flip:2517) DEBUG: name = flip last_ts = 100.726898 last_received_ts = 100.726395 last_seq = 1038 current_ts = 100.743561 current_received_ts = 100.743065 current_seq = 1039 count = 38 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 110us (kms_flip:2517) DEBUG: name = flip last_ts = 100.743561 last_received_ts = 100.743065 last_seq = 1039 current_ts = 100.760223 current_received_ts = 100.759735 current_seq = 1040 count = 39 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 122us (kms_flip:2517) DEBUG: name = flip last_ts = 100.760223 last_received_ts = 100.759735 last_seq = 1040 current_ts = 100.776886 current_received_ts = 100.776390 current_seq = 1041 count = 40 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 110us (kms_flip:2517) DEBUG: name = flip last_ts = 100.776886 last_received_ts = 100.776390 last_seq = 1041 current_ts = 100.793556 current_received_ts = 100.792900 current_seq = 1042 count = 41 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 153us (kms_flip:2517) DEBUG: name = flip last_ts = 100.793556 last_received_ts = 100.792900 last_seq = 1042 current_ts = 100.810211 current_received_ts = 100.809448 current_seq = 1043 count = 42 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 118us (kms_flip:2517) DEBUG: name = flip last_ts = 100.810211 last_received_ts = 100.809448 last_seq = 1043 current_ts = 100.826881 current_received_ts = 100.826218 current_seq = 1044 count = 43 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 30us (kms_flip:2517) DEBUG: name = flip last_ts = 100.826881 last_received_ts = 100.826218 last_seq = 1044 current_ts = 100.843536 current_received_ts = 100.843040 current_seq = 1045 count = 44 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 29us (kms_flip:2517) DEBUG: name = flip last_ts = 100.843536 last_received_ts = 100.843040 last_seq = 1045 current_ts = 100.860207 current_received_ts = 100.859520 current_seq = 1046 count = 45 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 42us (kms_flip:2517) DEBUG: name = flip last_ts = 100.860207 last_received_ts = 100.859520 last_seq = 1046 current_ts = 100.876862 current_received_ts = 100.876198 current_seq = 1047 count = 46 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 123us (kms_flip:2517) DEBUG: name = flip last_ts = 100.876862 last_received_ts = 100.876198 last_seq = 1047 current_ts = 100.893524 current_received_ts = 100.892883 current_seq = 1048 count = 47 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 129us (kms_flip:2517) DEBUG: name = flip last_ts = 100.893524 last_received_ts = 100.892883 last_seq = 1048 current_ts = 100.910187 current_received_ts = 100.909698 current_seq = 1049 count = 48 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 29us (kms_flip:2517) DEBUG: name = flip last_ts = 100.910187 last_received_ts = 100.909698 last_seq = 1049 current_ts = 100.926849 current_received_ts = 100.926224 current_seq = 1050 count = 49 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 111us (kms_flip:2517) DEBUG: name = flip last_ts = 100.926849 last_received_ts = 100.926224 last_seq = 1050 current_ts = 100.943512 current_received_ts = 100.942871 current_seq = 1051 count = 50 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 33us (kms_flip:2517) DEBUG: name = flip last_ts = 100.943512 last_received_ts = 100.942871 last_seq = 1051 current_ts = 100.960175 current_received_ts = 100.959671 current_seq = 1052 count = 51 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 106us (kms_flip:2517) DEBUG: name = flip last_ts = 100.960175 last_received_ts = 100.959671 last_seq = 1052 current_ts = 100.976837 current_received_ts = 100.976204 current_seq = 1053 count = 52 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 115us (kms_flip:2517) DEBUG: name = flip last_ts = 100.976837 last_received_ts = 100.976204 last_seq = 1053 current_ts = 100.993500 current_received_ts = 100.992844 current_seq = 1054 count = 53 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 139us (kms_flip:2517) DEBUG: name = flip last_ts = 100.993500 last_received_ts = 100.992844 last_seq = 1054 current_ts = 101.010162 current_received_ts = 101.009392 current_seq = 1055 count = 54 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 111us (kms_flip:2517) DEBUG: name = flip last_ts = 101.010162 last_received_ts = 101.009392 last_seq = 1055 current_ts = 101.026825 current_received_ts = 101.026367 current_seq = 1056 count = 55 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 112us (kms_flip:2517) DEBUG: name = flip last_ts = 101.026825 last_received_ts = 101.026367 last_seq = 1056 current_ts = 101.043488 current_received_ts = 101.042969 current_seq = 1057 count = 56 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 44us (kms_flip:2517) DEBUG: name = flip last_ts = 101.043488 last_received_ts = 101.042969 last_seq = 1057 current_ts = 101.060143 current_received_ts = 101.059372 current_seq = 1058 count = 57 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 117us (kms_flip:2517) DEBUG: name = flip last_ts = 101.060143 last_received_ts = 101.059372 last_seq = 1058 current_ts = 101.076805 current_received_ts = 101.076042 current_seq = 1059 count = 58 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 39us (kms_flip:2517) DEBUG: name = flip last_ts = 101.076805 last_received_ts = 101.076042 last_seq = 1059 current_ts = 101.093468 current_received_ts = 101.092812 current_seq = 1060 count = 59 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 105us (kms_flip:2517) DEBUG: name = flip last_ts = 101.093468 last_received_ts = 101.092812 last_seq = 1060 current_ts = 101.110130 current_received_ts = 101.109505 current_seq = 1061 count = 60 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 118us (kms_flip:2517) DEBUG: name = flip last_ts = 101.110130 last_received_ts = 101.109505 last_seq = 1061 current_ts = 101.126801 current_received_ts = 101.126152 current_seq = 1062 count = 61 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 117us (kms_flip:2517) DEBUG: name = flip last_ts = 101.126801 last_received_ts = 101.126152 last_seq = 1062 current_ts = 101.143456 current_received_ts = 101.142838 current_seq = 1063 count = 62 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 127us (kms_flip:2517) DEBUG: name = flip last_ts = 101.143456 last_received_ts = 101.142838 last_seq = 1063 current_ts = 101.160118 current_received_ts = 101.159485 current_seq = 1064 count = 63 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 117us (kms_flip:2517) DEBUG: name = flip last_ts = 101.160118 last_received_ts = 101.159485 last_seq = 1064 current_ts = 101.176781 current_received_ts = 101.176140 current_seq = 1065 count = 64 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 113us (kms_flip:2517) DEBUG: name = flip last_ts = 101.176781 last_received_ts = 101.176140 last_seq = 1065 current_ts = 101.193443 current_received_ts = 101.192970 current_seq = 1066 count = 65 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 132us (kms_flip:2517) DEBUG: name = flip last_ts = 101.193443 last_received_ts = 101.192970 last_seq = 1066 current_ts = 101.210106 current_received_ts = 101.209305 current_seq = 1067 count = 66 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 42us (kms_flip:2517) DEBUG: name = flip last_ts = 101.210106 last_received_ts = 101.209305 last_seq = 1067 current_ts = 101.226768 current_received_ts = 101.226265 current_seq = 1068 count = 67 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 29us (kms_flip:2517) DEBUG: name = flip last_ts = 101.226768 last_received_ts = 101.226265 last_seq = 1068 current_ts = 101.243431 current_received_ts = 101.242928 current_seq = 1069 count = 68 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 109us (kms_flip:2517) DEBUG: name = flip last_ts = 101.243431 last_received_ts = 101.242928 last_seq = 1069 current_ts = 101.260094 current_received_ts = 101.259285 current_seq = 1070 count = 69 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 40us (kms_flip:2517) DEBUG: name = flip last_ts = 101.260094 last_received_ts = 101.259285 last_seq = 1070 current_ts = 101.276756 current_received_ts = 101.276222 current_seq = 1071 count = 70 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 118us (kms_flip:2517) DEBUG: name = flip last_ts = 101.276756 last_received_ts = 101.276222 last_seq = 1071 current_ts = 101.293419 current_received_ts = 101.292786 current_seq = 1072 count = 71 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 40us (kms_flip:2517) DEBUG: name = flip last_ts = 101.293419 last_received_ts = 101.292786 last_seq = 1072 current_ts = 101.310081 current_received_ts = 101.309425 current_seq = 1073 count = 72 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 120us (kms_flip:2517) DEBUG: name = flip last_ts = 101.310081 last_received_ts = 101.309425 last_seq = 1073 current_ts = 101.326744 current_received_ts = 101.325974 current_seq = 1074 count = 73 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 121us (kms_flip:2517) DEBUG: name = flip last_ts = 101.326744 last_received_ts = 101.325974 last_seq = 1074 current_ts = 101.343407 current_received_ts = 101.342773 current_seq = 1075 count = 74 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 116us (kms_flip:2517) DEBUG: name = flip last_ts = 101.343407 last_received_ts = 101.342773 last_seq = 1075 current_ts = 101.360069 current_received_ts = 101.359413 current_seq = 1076 count = 75 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 120us (kms_flip:2517) DEBUG: name = flip last_ts = 101.360069 last_received_ts = 101.359413 last_seq = 1076 current_ts = 101.376732 current_received_ts = 101.376091 current_seq = 1077 count = 76 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 59us (kms_flip:2517) DEBUG: name = flip last_ts = 101.376732 last_received_ts = 101.376091 last_seq = 1077 current_ts = 101.393394 current_received_ts = 101.392929 current_seq = 1078 count = 77 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 120us (kms_flip:2517) DEBUG: name = flip last_ts = 101.393394 last_received_ts = 101.392929 last_seq = 1078 current_ts = 101.410057 current_received_ts = 101.409248 current_seq = 1079 count = 78 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 119us (kms_flip:2517) DEBUG: name = flip last_ts = 101.410057 last_received_ts = 101.409248 last_seq = 1079 current_ts = 101.426712 current_received_ts = 101.426056 current_seq = 1080 count = 79 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 33us (kms_flip:2517) DEBUG: name = flip last_ts = 101.426712 last_received_ts = 101.426056 last_seq = 1080 current_ts = 101.443375 current_received_ts = 101.442726 current_seq = 1081 count = 80 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 120us (kms_flip:2517) DEBUG: name = flip last_ts = 101.443375 last_received_ts = 101.442726 last_seq = 1081 current_ts = 101.460045 current_received_ts = 101.459244 current_seq = 1082 count = 81 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 41us (kms_flip:2517) DEBUG: name = flip last_ts = 101.460045 last_received_ts = 101.459244 last_seq = 1082 current_ts = 101.476700 current_received_ts = 101.476051 current_seq = 1083 count = 82 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 32us (kms_flip:2517) DEBUG: name = flip last_ts = 101.476700 last_received_ts = 101.476051 last_seq = 1083 current_ts = 101.493362 current_received_ts = 101.492714 current_seq = 1084 count = 83 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 122us (kms_flip:2517) DEBUG: name = flip last_ts = 101.493362 last_received_ts = 101.492714 last_seq = 1084 current_ts = 101.510033 current_received_ts = 101.509232 current_seq = 1085 count = 84 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 44us (kms_flip:2517) DEBUG: name = flip last_ts = 101.510033 last_received_ts = 101.509232 last_seq = 1085 current_ts = 101.526695 current_received_ts = 101.526047 current_seq = 1086 count = 85 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 41us (kms_flip:2517) DEBUG: name = flip last_ts = 101.526695 last_received_ts = 101.526047 last_seq = 1086 current_ts = 101.543350 current_received_ts = 101.542717 current_seq = 1087 count = 86 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 135us (kms_flip:2517) DEBUG: name = flip last_ts = 101.543350 last_received_ts = 101.542717 last_seq = 1087 current_ts = 101.560013 current_received_ts = 101.559380 current_seq = 1088 count = 87 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 115us (kms_flip:2517) DEBUG: name = flip last_ts = 101.560013 last_received_ts = 101.559380 last_seq = 1088 current_ts = 101.576683 current_received_ts = 101.576050 current_seq = 1089 count = 88 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 39us (kms_flip:2517) DEBUG: name = flip last_ts = 101.576683 last_received_ts = 101.576050 last_seq = 1089 current_ts = 101.593338 current_received_ts = 101.592850 current_seq = 1090 count = 89 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 96us (kms_flip:2517) DEBUG: name = flip last_ts = 101.593338 last_received_ts = 101.592850 last_seq = 1090 current_ts = 101.610008 current_received_ts = 101.609200 current_seq = 1091 count = 90 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 40us (kms_flip:2517) DEBUG: name = flip last_ts = 101.610008 last_received_ts = 101.609200 last_seq = 1091 current_ts = 101.626663 current_received_ts = 101.626060 current_seq = 1092 count = 91 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 35us (kms_flip:2517) DEBUG: name = flip last_ts = 101.626663 last_received_ts = 101.626060 last_seq = 1092 current_ts = 101.643326 current_received_ts = 101.642845 current_seq = 1093 count = 92 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 110us (kms_flip:2517) DEBUG: name = flip last_ts = 101.643326 last_received_ts = 101.642845 last_seq = 1093 current_ts = 101.659988 current_received_ts = 101.659348 current_seq = 1094 count = 93 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 47us (kms_flip:2517) DEBUG: name = flip last_ts = 101.659988 last_received_ts = 101.659348 last_seq = 1094 current_ts = 101.676659 current_received_ts = 101.676178 current_seq = 1095 count = 94 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 106us (kms_flip:2517) DEBUG: name = flip last_ts = 101.676659 last_received_ts = 101.676178 last_seq = 1095 current_ts = 101.693314 current_received_ts = 101.692680 current_seq = 1096 count = 95 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 112us (kms_flip:2517) DEBUG: name = flip last_ts = 101.693314 last_received_ts = 101.692680 last_seq = 1096 current_ts = 101.709976 current_received_ts = 101.709198 current_seq = 1097 count = 96 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 119us (kms_flip:2517) DEBUG: name = flip last_ts = 101.709976 last_received_ts = 101.709198 last_seq = 1097 current_ts = 101.726639 current_received_ts = 101.726051 current_seq = 1098 count = 97 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 112us (kms_flip:2517) DEBUG: name = flip last_ts = 101.726639 last_received_ts = 101.726051 last_seq = 1098 current_ts = 101.743309 current_received_ts = 101.742661 current_seq = 1099 count = 98 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 120us (kms_flip:2517) DEBUG: name = flip last_ts = 101.743309 last_received_ts = 101.742661 last_seq = 1099 current_ts = 101.759964 current_received_ts = 101.759323 current_seq = 1100 count = 99 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 30us (kms_flip:2517) DEBUG: name = flip last_ts = 101.759964 last_received_ts = 101.759323 last_seq = 1100 current_ts = 101.776627 current_received_ts = 101.775993 current_seq = 1101 count = 100 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 137us (kms_flip:2517) DEBUG: name = flip last_ts = 101.776627 last_received_ts = 101.775993 last_seq = 1101 current_ts = 101.793289 current_received_ts = 101.792778 current_seq = 1102 count = 101 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 34us (kms_flip:2517) DEBUG: name = flip last_ts = 101.793289 last_received_ts = 101.792778 last_seq = 1102 current_ts = 101.809952 current_received_ts = 101.809288 current_seq = 1103 count = 102 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 126us (kms_flip:2517) DEBUG: name = flip last_ts = 101.809952 last_received_ts = 101.809288 last_seq = 1103 current_ts = 101.826614 current_received_ts = 101.825974 current_seq = 1104 count = 103 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 61us (kms_flip:2517) DEBUG: name = flip last_ts = 101.826614 last_received_ts = 101.825974 last_seq = 1104 current_ts = 101.843269 current_received_ts = 101.842613 current_seq = 1105 count = 104 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 35us (kms_flip:2517) DEBUG: name = flip last_ts = 101.843269 last_received_ts = 101.842613 last_seq = 1105 current_ts = 101.859932 current_received_ts = 101.859444 current_seq = 1106 count = 105 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 118us (kms_flip:2517) DEBUG: name = flip last_ts = 101.859932 last_received_ts = 101.859444 last_seq = 1106 current_ts = 101.876602 current_received_ts = 101.875977 current_seq = 1107 count = 106 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 42us (kms_flip:2517) DEBUG: name = flip last_ts = 101.876602 last_received_ts = 101.875977 last_seq = 1107 current_ts = 101.893265 current_received_ts = 101.892632 current_seq = 1108 count = 107 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 143us (kms_flip:2517) DEBUG: name = flip last_ts = 101.893265 last_received_ts = 101.892632 last_seq = 1108 current_ts = 101.909927 current_received_ts = 101.909134 current_seq = 1109 count = 108 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 42us (kms_flip:2517) DEBUG: name = flip last_ts = 101.909927 last_received_ts = 101.909134 last_seq = 1109 current_ts = 101.926582 current_received_ts = 101.925995 current_seq = 1110 count = 109 seq_step = 1 (kms_flip:2517) DEBUG: Vblank took 749us (kms_flip:2517) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928: (kms_flip:2517) CRITICAL: Failed assertion: end - start < 500 (kms_flip:2517) igt_core-INFO: Stack trace: (kms_flip:2517) igt_core-INFO: #0 ../lib/igt_core.c:2075 __igt_fail_assert() (kms_flip:2517) igt_core-INFO: #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0() (kms_flip:2517) igt_core-INFO: #2 ../tests/kms_flip.c:1889 run_test() (kms_flip:2517) igt_core-INFO: #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045() (kms_flip:2517) igt_core-INFO: #4 ../tests/kms_flip.c:2045 main() (kms_flip:2517) igt_core-INFO: #5 [__libc_init_first+0x8a] (kms_flip:2517) igt_core-INFO: #6 [__libc_start_main+0x8b] (kms_flip:2517) igt_core-INFO: #7 [_start+0x25] END ** Dynamic subtest A-eDP1: FAIL (3.187s)
Dmesg	<6> [98.943677] Console: switching to colour dummy device 80x25 <6> [98.943762] [IGT] kms_flip: executing <7> [98.948969] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] <7> [98.948979] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:400:DP-1] <7> [98.949126] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [98.949215] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] disconnected <7> [98.949428] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] <7> [98.949430] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:412:DP-2] <7> [98.949543] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [98.949623] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] disconnected <7> [98.949844] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] <7> [98.949847] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:420:DP-3] <7> [98.949962] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (disconnected -> tbt-alt) pin assignment: - max lanes: 4 <7> [98.950044] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] disconnected <7> [98.950307] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:391:eDP-1] <7> [98.950310] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:391:eDP-1] <7> [98.950752] xe 0000:00:02.0: [drm:intel_dp_read_dsc_dpcd [xe]] DSC DPCD: 00 11 00 76 0b 01 01 80 00 01 06 66 08 00 00 00 <7> [98.951050] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] source rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 675000, 810000 <7> [98.951144] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] sink rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [98.951229] xe 0000:00:02.0: [drm:intel_dp_print_rates [xe]] common rates: 162000, 216000, 243000, 270000, 324000, 432000, 540000, 810000 <7> [98.951333] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] Supported Monitor Refresh rate range is 40 Hz - 120 Hz <5> [98.951337] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [98.951339] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [98.951340] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] DisplayID extension version 0x13, primary use 0x00 <7> [98.951342] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] Assigning EDID-1.4 digital sink color depth as 10 bpc. <5> [98.951343] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [98.951344] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] ELD monitor <5> [98.951346] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [98.951347] xe 0000:00:02.0: [drm:update_display_info.part.0] [CONNECTOR:391:eDP-1] ELD size 20, SAD count 0 <5> [98.951349] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [98.951358] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:391:eDP-1] VRR capable: yes <7> [98.951435] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:391:eDP-1] DFP max bpc 0, max dotclock 0, TMDS clock 0-0, PCON Max FRL BW 0Gbps <7> [98.951510] xe 0000:00:02.0: [drm:intel_dp_set_edid [xe]] [CONNECTOR:391:eDP-1] RGB->YcbCr conversion? no, YCbCr 4:2:0 allowed? yes, YCbCr 4:4:4->4:2:0 conversion? no <5> [98.952013] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [98.952015] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <5> [98.952017] [drm] DisplayID checksum invalid, remainder is 248 (ignoring) <7> [98.952074] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:391:eDP-1] probed modes: <7> [98.952078] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [98.952082] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] Probed mode: "2880x1800": 120 695310 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [98.952095] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] <7> [98.952098] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:400:DP-1] <7> [98.952227] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:400:DP-1] disconnected <7> [98.952238] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] <7> [98.952240] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:412:DP-2] <7> [98.952367] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:412:DP-2] disconnected <7> [98.952376] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] <7> [98.952379] xe 0000:00:02.0: [drm:intel_dp_detect [xe]] [CONNECTOR:420:DP-3] <7> [98.952504] xe 0000:00:02.0: [drm:drm_helper_probe_single_connector_modes] [CONNECTOR:420:DP-3] disconnected <6> [98.952696] [IGT] kms_flip: starting subtest flip-vs-expired-vblank <6> [98.954309] [IGT] kms_flip: starting dynamic subtest A-eDP1 <7> [98.965212] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428] <7> [98.965588] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:430] <7> [99.045078] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A] <7> [99.045241] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.enable (expected yes, found no) <7> [99.045493] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.active (expected yes, found no) <7> [99.045659] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in cpu_transcoder (expected 0, found -1) <7> [99.045843] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in lane_count (expected 4, found 0) <7> [99.045995] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in dp_m_n (expected tu 64 data 6329869/8388608 link 421991/524288, found tu 0, data 0/0 link 0/0) <7> [99.046143] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in output_types (expected 0x00000100, found 0x00000000) <7> [99.046287] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in framestart_delay (expected 1, found 0) <7> [99.046427] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 2880, found 0) <7> [99.046565] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 3040, found 0) <7> [99.046705] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 2880, found 0) <7> [99.046862] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 3040, found 0) <7> [99.046994] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 2928, found 0) <7> [99.047119] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 2960, found 0) <7> [99.047241] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 1800, found 0) <7> [99.047363] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 1800, found 0) <7> [99.047482] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 1803, found 0) <7> [99.047598] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 1809, found 0) <7> [99.047710] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 1906, found 0) <7> [99.047838] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 1906, found 0) <7> [99.047945] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 2880, found 0) <7> [99.048051] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 3040, found 0) <7> [99.048154] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 2880, found 0) <7> [99.048256] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 3040, found 0) <7> [99.048354] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 2928, found 0) <7> [99.048453] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 2960, found 0) <7> [99.048550] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 1800, found 0) <7> [99.048645] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 1800, found 0) <7> [99.048743] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 1803, found 0) <7> [99.048836] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 1809, found 0) <7> [99.048927] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 1906, found 0) <7> [99.049017] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 1906, found 0) <7> [99.049105] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pixel_multiplier (expected 1, found 0) <7> [99.049192] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 2, found 0) <7> [99.049280] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 8, found 0) <7> [99.049368] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pipe_bpp (expected 30, found 0) <7> [99.049455] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 347710, found 0) <7> [99.049541] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 347710, found 0) <7> [99.049624] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in port_clock (expected 432000, found 0) <7> [99.049708] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] fastset requirement not met, forcing full modeset <7> [99.049814] xe 0000:00:02.0: [drm:intel_dpll_crtc_put [xe]] [CRTC:149:pipe A] releasing DPLL 0 <7> [99.049949] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0xf -> 0x1 (total dbuf slices 0xf), mbus joined? yes->no <7> [99.050016] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:149:pipe A] dbuf slices 0xf -> 0x0, ddb (0 - 4096) -> (0 - 0), active pipes 0x1 -> 0x0 <7> [99.050105] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0 <7> [99.050174] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:143:cursor A] ddb (4051 - 4096) -> ( 0 - 0), size 45 -> 0 <7> [99.050243] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [99.050309] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [99.050374] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] blocks 24, 313, 313, 313, 313, 313, 0, 0, 38, 73, 87 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [99.050430] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] min_ddb 28, 346, 346, 346, 346, 346, 0, 0, 39, 82, 88 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 <7> [99.050505] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:149:pipe A] data rate 0 num active planes 0 <7> [99.050594] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 0 qgv_peak_bw: 38400 <7> [99.050679] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 0 qgv_peak_bw: 38400 <7> [99.050775] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [99.050861] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 0 qgv_peak_bw: 38400 <7> [99.050945] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 0 <7> [99.051030] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:149:pipe A] min cdclk: 173855 kHz -> 0 kHz <7> [99.051129] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 21732 kHz -> 0 kHz <7> [99.051215] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [99.051297] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 153600 kHz, actual 153600 kHz <7> [99.051373] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [99.051476] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:149:pipe A] enable: no [modeset] <7> [99.051554] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:33:plane 1A] fb: [NOFB], visible: no <7> [99.051632] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:63:plane 2A] fb: [NOFB], visible: no <7> [99.051709] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:93:plane 3A] fb: [NOFB], visible: no <7> [99.051806] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:123:plane 4A] fb: [NOFB], visible: no <7> [99.051892] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:133:plane 5A] fb: [NOFB], visible: no <7> [99.051975] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:143:cursor A] fb: [NOFB], visible: no <7> [99.052096] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling DC_off <7> [99.052814] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 02 to 00 <7> [99.052976] xe 0000:00:02.0: [drm:intel_psr_disable_locked [xe]] Disabling PSR2 <7> [99.053668] xe 0000:00:02.0: [drm:intel_alpm_disable [xe]] Disabling ALPM <7> [99.053780] xe 0000:00:02.0: [drm:intel_edp_backlight_off [xe]] <7> [99.259864] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 0 <7> [99.260452] xe 0000:00:02.0: [drm:intel_disable_transcoder [xe]] disabling pipe A <7> [99.271275] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power off <7> [99.271594] xe 0000:00:02.0: [drm:intel_pps_off_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power off time <7> [99.271970] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb0000000 value: 0x00000000 PP_STATUS: 0xa0000002 PP_CONTROL: 0x00000060 <7> [99.324092] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x00000009, pins 0x00000010, long 0x00000000 <7> [99.324523] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - short <7> [99.331930] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [99.332279] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disable DPLL 0 (active 0x1, on? 1) for [CRTC:149:pipe A] <7> [99.332313] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring short hpd on eDP [ENCODER:390:DDI A/PHY A] <7> [99.333535] xe 0000:00:02.0: [drm:intel_dpll_disable [xe]] disabling DPLL 0 <7> [99.334003] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling AUX_A <7> [99.334502] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:390:DDI A/PHY A] <7> [99.334872] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:399:DDI TC1/PHY TC1] <7> [99.335163] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DP-MST A] <7> [99.335457] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST B] <7> [99.335729] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST C] <7> [99.336083] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:411:DDI TC2/PHY TC2] <7> [99.336347] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DP-MST A] <7> [99.336589] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST B] <7> [99.336890] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST C] <7> [99.337123] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:419:DDI TC3/PHY TC3] <7> [99.337352] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DP-MST A] <7> [99.337575] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST B] <7> [99.337812] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST C] <7> [99.338038] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:391:eDP-1] <7> [99.338343] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [99.338584] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: yes -> no (pipe: ) <7> [99.338900] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0x1 <7> [99.339347] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling PW_A <7> [99.339801] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A] <7> [99.340153] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Post changing CDCLK to 153600 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [99.340518] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [99.340802] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=384 <7> [99.341584] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B] <7> [99.341966] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C] <7> [99.342266] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A] <7> [99.342326] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CONNECTOR:391:eDP-1] <7> [99.342494] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CONNECTOR:391:eDP-1] Limiting display bpp to 30 (EDID bpp 30, max requested bpp 36, max platform bpp 36) <7> [99.342863] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:390:DDI A/PHY A][CRTC:149:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000 <7> [99.343168] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 link rate required 1303913 available 1728000 <7> [99.343481] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0 <7> [99.343800] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:390:DDI A/PHY A] [CRTC:149:pipe A] <7> [99.344172] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.enable (expected no, found yes) <7> [99.344523] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.active (expected no, found yes) <7> [99.344830] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in cpu_transcoder (expected -1, found 0) <7> [99.345163] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in lane_count (expected 0, found 4) <7> [99.345444] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in dp_m_n (expected tu 0 data 0/0 link 0/0, found tu 64, data 6329869/8388608 link 421991/524288) <7> [99.345706] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in output_types (expected 0x00000000, found 0x00000100) <7> [99.345989] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in framestart_delay (expected 0, found 1) <7> [99.346262] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hdisplay (expected 0, found 2880) <7> [99.346497] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_htotal (expected 0, found 3040) <7> [99.346719] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_start (expected 0, found 2880) <7> [99.346967] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hblank_end (expected 0, found 3040) <7> [99.347219] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_start (expected 0, found 2928) <7> [99.347425] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_hsync_end (expected 0, found 2960) <7> [99.347618] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vdisplay (expected 0, found 1800) <7> [99.347815] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_start (expected 0, found 1800) <7> [99.348028] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_start (expected 0, found 1803) <7> [99.348223] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vsync_end (expected 0, found 1809) <7> [99.348425] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vtotal (expected 0, found 1906) <7> [99.348599] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_vblank_end (expected 0, found 1906) <7> [99.348772] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hdisplay (expected 0, found 2880) <7> [99.348932] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_htotal (expected 0, found 3040) <7> [99.349088] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_start (expected 0, found 2880) <7> [99.349237] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hblank_end (expected 0, found 3040) <7> [99.349383] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_start (expected 0, found 2928) <7> [99.349527] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_hsync_end (expected 0, found 2960) <7> [99.349672] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vdisplay (expected 0, found 1800) <7> [99.349828] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_start (expected 0, found 1800) <7> [99.349969] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_start (expected 0, found 1803) <7> [99.350112] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vsync_end (expected 0, found 1809) <7> [99.350244] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vtotal (expected 0, found 1906) <7> [99.350377] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_vblank_end (expected 0, found 1906) <7> [99.350508] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pixel_multiplier (expected 0, found 1) <7> [99.350638] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (2) (expected 0, found 2) <7> [99.350767] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.flags (8) (expected 0, found 8) <7> [99.350890] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in pipe_bpp (expected 0, found 30) <7> [99.351007] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.pipe_mode.crtc_clock (expected 0, found 347710) <7> [99.351123] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in hw.adjusted_mode.crtc_clock (expected 0, found 347710) <7> [99.351252] xe 0000:00:02.0: [drm:intel_pipe_config_compare [xe]] [CRTC:149:pipe A] fastset requirement not met in port_clock (expected 0, found 432000) <7> [99.351383] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] fastset requirement not met, forcing full modeset <7> [99.351545] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] Enabled dbuf slices 0x1 -> 0xf (total dbuf slices 0xf), mbus joined? no->yes <7> [99.351651] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [CRTC:149:pipe A] dbuf slices 0x0 -> 0xf, ddb (0 - 0) -> (0 - 4096), active pipes 0x0 -> 0x1 <7> [99.351788] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051 <7> [99.351883] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:143:cursor A] ddb ( 0 - 0) -> (4051 - 4096), size 0 -> 45 <7> [99.351959] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [99.352037] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0 <7> [99.352115] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197 <7> [99.352199] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198 <7> [99.352302] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] [CRTC:149:pipe A] data rate 1390840 num active planes 1 <7> [99.352435] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 0: max bw 23530 required 1461 qgv_peak_bw: 38400 <7> [99.352546] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 1: max bw 36260 required 1461 qgv_peak_bw: 38400 <7> [99.352652] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 2: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [99.352759] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] QGV point 3: max bw 38000 required 1461 qgv_peak_bw: 38400 <7> [99.352860] xe 0000:00:02.0: [drm:intel_bw_atomic_check [xe]] Matching peaks QGV bw: 38400 for required data rate: 1461 <7> [99.352956] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] [CRTC:149:pipe A] min cdclk: 0 kHz -> 173855 kHz <7> [99.353068] xe 0000:00:02.0: [drm:intel_cdclk_update_dbuf_bw_min_cdclk [xe]] dbuf bandwidth min cdclk: 0 kHz -> 21732 kHz <7> [99.353163] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] Can change cdclk via squashing <7> [99.353253] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New cdclk calculated to be logical 192000 kHz, actual 192000 kHz <7> [99.353340] xe 0000:00:02.0: [drm:intel_cdclk_atomic_check [xe]] New voltage level calculated to be logical 0, actual 0 <7> [99.353443] xe 0000:00:02.0: [drm:intel_find_dpll [xe]] [CRTC:149:pipe A] allocated DPLL 0 <7> [99.353537] xe 0000:00:02.0: [drm:intel_dpll_crtc_get [xe]] [CRTC:149:pipe A] reserving DPLL 0 <7> [99.353633] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [CRTC:149:pipe A] enable: yes [modeset] <7> [99.353733] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] active: yes, output_types: EDP (0x100), output format: RGB, sink format: RGB <7> [99.353878] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cpu_transcoder: A, pipe bpp: 30, dithering: 0 <7> [99.353968] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] MST master transcoder: <invalid> <7> [99.354049] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port sync: master transcoder: <invalid>, slave transcoder bitmask = 0x0 <7> [99.354128] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] joiner: no, pipes: 0x0 <7> [99.354205] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] splitter: disabled, link count 0, overlap 0 <7> [99.354281] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m_n: lanes: 4; data_m: 6329869, data_n: 8388608, link_m: 421991, link_n: 524288, tu: 64 <7> [99.354355] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0 <7> [99.354429] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled <7> [99.354505] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sdp split: disabled <7> [99.354578] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] psr: enabled, selective update: enabled, panel replay: disabled, selective fetch: enabled <7> [99.354655] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0 <7> [99.354732] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] audio: 0, infoframes: 0, infoframes enabled: 0x4 <7> [99.354821] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] DP SDP: VSC, revision 4, length 14 <7> [99.354899] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pixelformat: RGB <7> [99.354976] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] colorimetry: sRGB <7> [99.355051] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] bpc: 0 <7> [99.355121] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dynamic range: VESA range <7> [99.355190] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] content type: Not defined <7> [99.355261] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] scanline offset: 1 <7> [99.355329] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] framestart delay: 1, MSA timing delay: 0, set context latency: 0 <7> [99.355398] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: no, fixed rr: yes, vmin: 1906, vmax: 1906, flipline: 1906, pipeline full: 0, guardband: 104 vsync start: 103, vsync end: 97 <7> [99.355468] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: vmin vblank: 1802, vmax vblank: 1802, vmin vtotal: 1906, vmax vtotal: 1906 <7> [99.355537] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0 <7> [99.355606] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] requested mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [99.355676] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] adjusted mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa <7> [99.355745] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [99.355832] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe mode: "2880x1800": 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x40 0xa <7> [99.355917] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] crtc timings: clock=347710, hd=2880 hb=2880-3040 hs=2928-2960 ht=3040, vd=1800 vb=1800-1906 vs=1803-1809 vt=1906, flags=0xa <7> [99.355997] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855 <7> [99.356072] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] linetime: 70, ips linetime: 0 <7> [99.356139] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] num_scalers: 2, scaler_users: 0x0, scaler_id: -1, scaling_filter: 0 <7> [99.356207] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pch pfit: 0x0+0+0, disabled, force thru: no <7> [99.356275] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] ips: 0, double wide: 0, drrs: 0 <7> [99.356343] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] cx0pll_hw_state: lane_count: 4, ssc_enabled: no, use_c10: yes, tbt_mode: no <7> [99.356412] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: clock: 432000, fracen: no, <7> [99.356480] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] multiplier: 225, tx_clk_div: 1. <7> [99.356549] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_rawhw_state: <7> [99.356621] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] tx: 0x10, cmn: 0x21 <7> [99.356708] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1 <7> [99.356795] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[4] = 0x0, pll[5] = 0x0, pll[6] = 0x0, pll[7] = 0x0 <7> [99.356876] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[8] = 0x0, pll[9] = 0x1, pll[10] = 0x0, pll[11] = 0x0 <7> [99.356954] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[12] = 0x0, pll[13] = 0x0, pll[14] = 0x0, pll[15] = 0x1 <7> [99.357032] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23 <7> [99.357103] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] csc_mode: 0x0 gamma_mode: 0x0 gamma_enable: 0 csc_enable: 0 <7> [99.357174] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pre csc lut: 0 entries, post csc lut: 0 entries <7> [99.357244] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: pre offsets: 0x0000 0x0000 0x0000 <7> [99.357314] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [99.357384] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [99.357454] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: coefficients: 0x0000 0x0000 0x0000 <7> [99.357522] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] output csc: post offsets: 0x0000 0x0000 0x0000 <7> [99.357591] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: pre offsets: 0x0000 0x0000 0x0000 <7> [99.357660] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [99.357729] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [99.357814] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: coefficients: 0x0000 0x0000 0x0000 <7> [99.357900] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pipe csc: post offsets: 0x0000 0x0000 0x0000 <7> [99.357975] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] sharpness strength: 0, sharpness tap size: 0, sharpness enable: 0 <7> [99.358050] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:33:plane 1A] fb: [FB:428] 2880x1800 format = XR24 little-endian (0x34325258) modifier = 0x100000000000009, visible: yes <7> [99.358124] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] rotation: 0x1, scaler: -1, scaling_filter: 0 <7> [99.358196] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] src: 2880.000000x1800.000000+0.000000+0.000000 dst: 2880x1800+0+0 <7> [99.358271] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:63:plane 2A] fb: [NOFB], visible: no <7> [99.358345] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:93:plane 3A] fb: [NOFB], visible: no <7> [99.358420] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:123:plane 4A] fb: [NOFB], visible: no <7> [99.358495] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:133:plane 5A] fb: [NOFB], visible: no <7> [99.358564] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] [PLANE:143:cursor A] fb: [NOFB], visible: no <7> [99.358963] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling PW_A <7> [99.359127] xe 0000:00:02.0: [drm:intel_set_cdclk [xe]] Pre changing CDCLK to 192000 kHz, VCO 614400 kHz, ref 38400 kHz, bypass 19200 kHz, voltage level 0 <7> [99.359224] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 4 (mbus joined: no) <7> [99.359309] xe 0000:00:02.0: [drm:intel_audio_cdclk_change_post.part.0 [xe]] aud_ts_cdclk set to M=60, N=480 <7> [99.359390] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:390:DDI A/PHY A] <7> [99.359455] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:399:DDI TC1/PHY TC1] <7> [99.359518] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:401:DP-MST A] <7> [99.359583] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:402:DP-MST B] <7> [99.359644] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:403:DP-MST C] <7> [99.359703] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:411:DDI TC2/PHY TC2] <7> [99.359767] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:413:DP-MST A] <7> [99.359832] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:414:DP-MST B] <7> [99.359895] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:415:DP-MST C] <7> [99.359957] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:419:DDI TC3/PHY TC3] <7> [99.360019] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:421:DP-MST A] <7> [99.360078] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:422:DP-MST B] <7> [99.360133] xe 0000:00:02.0: [drm:intel_modeset_verify_disabled [xe]] [ENCODER:423:DP-MST C] <7> [99.360210] xe 0000:00:02.0: [drm:gen9_dbuf_slices_update [xe]] Updating dbuf slices to 0xf <7> [99.360367] xe 0000:00:02.0: [drm:intel_dbuf_mbus_join_update [xe]] Changing mbus joined: no -> yes (pipe: ) <7> [99.360435] xe 0000:00:02.0: [drm:intel_dbuf_mdclk_cdclk_ratio_update [xe]] Updating dbuf ratio to 8 (mbus joined: yes) <7> [99.360545] xe 0000:00:02.0: [drm:intel_power_well_enable [xe]] enabling AUX_A <7> [99.361791] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enable DPLL 0 (active 0x1, on? 0) for [CRTC:149:pipe A] <7> [99.361878] xe 0000:00:02.0: [drm:intel_dpll_enable [xe]] enabling DPLL 0 <7> [99.363397] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [99.363561] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long <7> [99.363663] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 10 <7> [99.363767] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turn panel power on <7> [99.363788] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A] <7> [99.363852] xe 0000:00:02.0: [drm:wait_panel_power_cycle [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power cycle (469 ms remaining) <7> [99.835945] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000 PP_STATUS: 0x08000001 PP_CONTROL: 0x00000060 <7> [99.907272] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [99.907613] xe 0000:00:02.0: [drm:intel_pps_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 wait for panel power on <7> [99.907935] xe 0000:00:02.0: [drm:wait_panel_status [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 mask: 0xb000000f value: 0x80000008 PP_STATUS: 0x9000000a PP_CONTROL: 0x00000063 <7> [99.944413] xe 0000:00:02.0: [drm:icp_irq_handler [xe]] hotplug event received, stat 0x00010000, dig 0x0000000a, pins 0x00000010, long 0x00000010 <7> [99.944914] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] digital hpd on [ENCODER:390:DDI A/PHY A] - long <7> [99.945285] xe 0000:00:02.0: [drm:intel_hpd_irq_handler [xe]] Received HPD interrupt on PIN 4 - cnt: 20 <7> [99.945877] xe 0000:00:02.0: [drm:intel_dp_hpd_pulse [xe]] ignoring long hpd on eDP [ENCODER:390:DDI A/PHY A] <7> [99.980111] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port F/TC#3: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [99.980237] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port E/TC#2: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [99.980361] xe 0000:00:02.0: [drm:intel_tc_port_reset_mode [xe]] Port D/TC#1: TC port mode reset (tbt-alt -> disconnected) pin assignment: - max lanes: 4 <7> [100.118169] xe 0000:00:02.0: [drm:wait_panel_status [xe]] Wait complete <7> [100.118542] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 turning VDD on <7> [100.118888] xe 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked [xe]] [ENCODER:390:DDI A/PHY A] PPS 0 PP_STATUS: 0x80000008 PP_CONTROL: 0x0000006b <7> [100.120953] xe 0000:00:02.0: [drm:drm_dp_read_dpcd_caps [drm_display_helper]] AUX A/DDI A/PHY A: DPCD: 14 1e 44 c1 00 00 01 c0 02 00 02 00 00 0b 80 <7> [100.122234] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Reloading eDP link rates <7> [100.123010] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05 <7> [100.124051] xe 0000:00:02.0: [drm:intel_dp_set_signal_levels [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] 8b/10b, lanes: 4, vswing levels: 0/0/0/0, pre-emphasis levels: 0/0/0/0 <7> [100.125116] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS1 <7> [100.126140] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Clock recovery OK <7> [100.126428] xe 0000:00:02.0: [drm:intel_dp_program_link_training_pattern [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using DP training pattern TPS4 <7> [100.127898] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Channel EQ done. DP Training successful <7> [100.128222] xe 0000:00:02.0: [drm:intel_dp_link_train_phy [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Link Training passed at link rate = 432000, lane count = 4 <7> [100.128922] xe 0000:00:02.0: [drm:intel_enable_transcoder [xe]] enabling pipe A <7> [100.129341] xe 0000:00:02.0: [drm:intel_edp_backlight_on [xe]] <7> [100.129630] xe 0000:00:02.0: [drm:intel_backlight_enable [xe]] pipe A <7> [100.129965] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 4518 <7> [100.146194] xe 0000:00:02.0: [drm:intel_psr_post_plane_update [xe]] Enabling PSR2 <7> [100.147743] xe 0000:00:02.0: [drm:verify_connector_state [xe]] [CONNECTOR:391:eDP-1] <7> [100.148079] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A] <7> [102.013226] xe 0000:00:02.0: [drm:intel_power_well_disable [xe]] disabling DC_off <7> [102.013754] xe 0000:00:02.0: [drm:skl_enable_dc6 [xe]] Enabling DC6 <7> [102.014240] xe 0000:00:02.0: [drm:gen9_set_dc_state.part.0 [xe]] Setting DC state from 00 to 02 <6> [102.141434] [IGT] kms_flip: finished subtest A-eDP1, FAIL

Detail

Value

Duration

3.19 seconds

Hostname

shard-lnl-7

Igt-Version

IGT-Version: 2.3-g0b67ab25f (x86_64) (Linux: 6.19.0-rc5-lgci-xe-xe-4375-0e1b1ce1c8adbc0a8+ x86_64)

Out

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

Err

Starting subtest: flip-vs-expired-vblank
Starting dynamic subtest: A-eDP1
(kms_flip:2517) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2517) CRITICAL: Failed assertion: end - start < 500
Dynamic subtest A-eDP1 failed.
**** DEBUG ****
(kms_flip:2517) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2517) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=11520)
(kms_flip:2517) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2517) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2880, height=1800, format=XR24(0x34325258), modifier=0x100000000000009, size=0)
(kms_flip:2517) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2517) drmtest-DEBUG: Test requirement passed: is_intel_device(fd)
(kms_flip:2517) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=2, pitch=11520)
(kms_flip:2517) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281d7490, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281d7490, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4590, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4590, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4470, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281e4470, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) intel_allocator_simple-DEBUG: Using simple allocator
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281da720, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) intel_allocator_simple-DEBUG: <ial: 0x5e10281da720, fd: 5> objects: 3, reserved_areas: 0
(kms_flip:2517) igt_kms-INFO:   2880x1800: 60 347710 2880 2928 2960 3040 1800 1803 1809 1906 0x48 0xa 
(kms_flip:2517) DEBUG: No stale events found
(kms_flip:2517) i915/intel_drrs-DEBUG: Manually disabling DRRS. 0
(kms_flip:2517) i915/intel_drrs-DEBUG: Test requirement passed: dir >= 0
(kms_flip:2517) DEBUG: name = flip
last_ts = 0.000000
last_received_ts = 0.000000
last_seq = 0
current_ts = 100.110405
current_received_ts = 100.109634
current_seq = 1001
count = 0
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 136us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.110405
last_received_ts = 100.109634
last_seq = 1001
current_ts = 100.127060
current_received_ts = 100.126358
current_seq = 1002
count = 1
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 45us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.127060
last_received_ts = 100.126358
last_seq = 1002
current_ts = 100.143723
current_received_ts = 100.143028
current_seq = 1003
count = 2
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 46us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.143723
last_received_ts = 100.143028
last_seq = 1003
current_ts = 100.160385
current_received_ts = 100.159653
current_seq = 1004
count = 3
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 34us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.160385
last_received_ts = 100.159653
last_seq = 1004
current_ts = 100.177055
current_received_ts = 100.176514
current_seq = 1005
count = 4
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 115us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.177055
last_received_ts = 100.176514
last_seq = 1005
current_ts = 100.193718
current_received_ts = 100.193169
current_seq = 1006
count = 5
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 32us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.193718
last_received_ts = 100.193169
last_seq = 1006
current_ts = 100.210373
current_received_ts = 100.209831
current_seq = 1007
count = 6
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 116us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.210373
last_received_ts = 100.209831
last_seq = 1007
current_ts = 100.227043
current_received_ts = 100.226524
current_seq = 1008
count = 7
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 125us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.227043
last_received_ts = 100.226524
last_seq = 1008
current_ts = 100.243698
current_received_ts = 100.243065
current_seq = 1009
count = 8
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 122us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.243698
last_received_ts = 100.243065
last_seq = 1009
current_ts = 100.260361
current_received_ts = 100.259583
current_seq = 1010
count = 9
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 120us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.260361
last_received_ts = 100.259583
last_seq = 1010
current_ts = 100.277023
current_received_ts = 100.276207
current_seq = 1011
count = 10
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 44us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.277023
last_received_ts = 100.276207
last_seq = 1011
current_ts = 100.293686
current_received_ts = 100.292908
current_seq = 1012
count = 11
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 118us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.293686
last_received_ts = 100.292908
last_seq = 1012
current_ts = 100.310349
current_received_ts = 100.309822
current_seq = 1013
count = 12
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 115us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.310349
last_received_ts = 100.309822
last_seq = 1013
current_ts = 100.327011
current_received_ts = 100.326202
current_seq = 1014
count = 13
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 44us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.327011
last_received_ts = 100.326202
last_seq = 1014
current_ts = 100.343674
current_received_ts = 100.343018
current_seq = 1015
count = 14
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 35us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.343674
last_received_ts = 100.343018
last_seq = 1015
current_ts = 100.360336
current_received_ts = 100.359634
current_seq = 1016
count = 15
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 131us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.360336
last_received_ts = 100.359634
last_seq = 1016
current_ts = 100.376991
current_received_ts = 100.376183
current_seq = 1017
count = 16
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 44us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.376991
last_received_ts = 100.376183
last_seq = 1017
current_ts = 100.393654
current_received_ts = 100.392876
current_seq = 1018
count = 17
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 132us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.393654
last_received_ts = 100.392876
last_seq = 1018
current_ts = 100.410324
current_received_ts = 100.409653
current_seq = 1019
count = 18
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 124us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.410324
last_received_ts = 100.409653
last_seq = 1019
current_ts = 100.426987
current_received_ts = 100.426170
current_seq = 1020
count = 19
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 42us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.426987
last_received_ts = 100.426170
last_seq = 1020
current_ts = 100.443642
current_received_ts = 100.442863
current_seq = 1021
count = 20
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 119us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.443642
last_received_ts = 100.442863
last_seq = 1021
current_ts = 100.460312
current_received_ts = 100.459770
current_seq = 1022
count = 21
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 30us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.460312
last_received_ts = 100.459770
last_seq = 1022
current_ts = 100.476967
current_received_ts = 100.476448
current_seq = 1023
count = 22
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 124us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.476967
last_received_ts = 100.476448
last_seq = 1023
current_ts = 100.493629
current_received_ts = 100.492958
current_seq = 1024
count = 23
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 52us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.493629
last_received_ts = 100.492958
last_seq = 1024
current_ts = 100.510292
current_received_ts = 100.509773
current_seq = 1025
count = 24
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 112us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.510292
last_received_ts = 100.509773
last_seq = 1025
current_ts = 100.526955
current_received_ts = 100.526260
current_seq = 1026
count = 25
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 29us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.526955
last_received_ts = 100.526260
last_seq = 1026
current_ts = 100.543617
current_received_ts = 100.543091
current_seq = 1027
count = 26
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 111us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.543617
last_received_ts = 100.543091
last_seq = 1027
current_ts = 100.560280
current_received_ts = 100.559753
current_seq = 1028
count = 27
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 118us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.560280
last_received_ts = 100.559753
last_seq = 1028
current_ts = 100.576942
current_received_ts = 100.576187
current_seq = 1029
count = 28
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 32us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.576942
last_received_ts = 100.576187
last_seq = 1029
current_ts = 100.593605
current_received_ts = 100.593079
current_seq = 1030
count = 29
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 51us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.593605
last_received_ts = 100.593079
last_seq = 1030
current_ts = 100.610268
current_received_ts = 100.609512
current_seq = 1031
count = 30
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 97us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.610268
last_received_ts = 100.609512
last_seq = 1031
current_ts = 100.626930
current_received_ts = 100.626183
current_seq = 1032
count = 31
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 115us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.626930
last_received_ts = 100.626183
last_seq = 1032
current_ts = 100.643593
current_received_ts = 100.642937
current_seq = 1033
count = 32
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 126us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.643593
last_received_ts = 100.642937
last_seq = 1033
current_ts = 100.660255
current_received_ts = 100.659485
current_seq = 1034
count = 33
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 115us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.660255
last_received_ts = 100.659485
last_seq = 1034
current_ts = 100.676918
current_received_ts = 100.676437
current_seq = 1035
count = 34
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 33us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.676918
last_received_ts = 100.676437
last_seq = 1035
current_ts = 100.693581
current_received_ts = 100.693062
current_seq = 1036
count = 35
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 29us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.693581
last_received_ts = 100.693062
last_seq = 1036
current_ts = 100.710236
current_received_ts = 100.709572
current_seq = 1037
count = 36
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 110us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.710236
last_received_ts = 100.709572
last_seq = 1037
current_ts = 100.726898
current_received_ts = 100.726395
current_seq = 1038
count = 37
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 111us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.726898
last_received_ts = 100.726395
last_seq = 1038
current_ts = 100.743561
current_received_ts = 100.743065
current_seq = 1039
count = 38
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 110us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.743561
last_received_ts = 100.743065
last_seq = 1039
current_ts = 100.760223
current_received_ts = 100.759735
current_seq = 1040
count = 39
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 122us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.760223
last_received_ts = 100.759735
last_seq = 1040
current_ts = 100.776886
current_received_ts = 100.776390
current_seq = 1041
count = 40
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 110us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.776886
last_received_ts = 100.776390
last_seq = 1041
current_ts = 100.793556
current_received_ts = 100.792900
current_seq = 1042
count = 41
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 153us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.793556
last_received_ts = 100.792900
last_seq = 1042
current_ts = 100.810211
current_received_ts = 100.809448
current_seq = 1043
count = 42
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 118us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.810211
last_received_ts = 100.809448
last_seq = 1043
current_ts = 100.826881
current_received_ts = 100.826218
current_seq = 1044
count = 43
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 30us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.826881
last_received_ts = 100.826218
last_seq = 1044
current_ts = 100.843536
current_received_ts = 100.843040
current_seq = 1045
count = 44
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 29us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.843536
last_received_ts = 100.843040
last_seq = 1045
current_ts = 100.860207
current_received_ts = 100.859520
current_seq = 1046
count = 45
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 42us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.860207
last_received_ts = 100.859520
last_seq = 1046
current_ts = 100.876862
current_received_ts = 100.876198
current_seq = 1047
count = 46
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 123us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.876862
last_received_ts = 100.876198
last_seq = 1047
current_ts = 100.893524
current_received_ts = 100.892883
current_seq = 1048
count = 47
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 129us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.893524
last_received_ts = 100.892883
last_seq = 1048
current_ts = 100.910187
current_received_ts = 100.909698
current_seq = 1049
count = 48
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 29us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.910187
last_received_ts = 100.909698
last_seq = 1049
current_ts = 100.926849
current_received_ts = 100.926224
current_seq = 1050
count = 49
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 111us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.926849
last_received_ts = 100.926224
last_seq = 1050
current_ts = 100.943512
current_received_ts = 100.942871
current_seq = 1051
count = 50
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 33us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.943512
last_received_ts = 100.942871
last_seq = 1051
current_ts = 100.960175
current_received_ts = 100.959671
current_seq = 1052
count = 51
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 106us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.960175
last_received_ts = 100.959671
last_seq = 1052
current_ts = 100.976837
current_received_ts = 100.976204
current_seq = 1053
count = 52
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 115us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.976837
last_received_ts = 100.976204
last_seq = 1053
current_ts = 100.993500
current_received_ts = 100.992844
current_seq = 1054
count = 53
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 139us
(kms_flip:2517) DEBUG: name = flip
last_ts = 100.993500
last_received_ts = 100.992844
last_seq = 1054
current_ts = 101.010162
current_received_ts = 101.009392
current_seq = 1055
count = 54
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 111us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.010162
last_received_ts = 101.009392
last_seq = 1055
current_ts = 101.026825
current_received_ts = 101.026367
current_seq = 1056
count = 55
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 112us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.026825
last_received_ts = 101.026367
last_seq = 1056
current_ts = 101.043488
current_received_ts = 101.042969
current_seq = 1057
count = 56
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 44us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.043488
last_received_ts = 101.042969
last_seq = 1057
current_ts = 101.060143
current_received_ts = 101.059372
current_seq = 1058
count = 57
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 117us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.060143
last_received_ts = 101.059372
last_seq = 1058
current_ts = 101.076805
current_received_ts = 101.076042
current_seq = 1059
count = 58
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 39us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.076805
last_received_ts = 101.076042
last_seq = 1059
current_ts = 101.093468
current_received_ts = 101.092812
current_seq = 1060
count = 59
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 105us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.093468
last_received_ts = 101.092812
last_seq = 1060
current_ts = 101.110130
current_received_ts = 101.109505
current_seq = 1061
count = 60
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 118us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.110130
last_received_ts = 101.109505
last_seq = 1061
current_ts = 101.126801
current_received_ts = 101.126152
current_seq = 1062
count = 61
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 117us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.126801
last_received_ts = 101.126152
last_seq = 1062
current_ts = 101.143456
current_received_ts = 101.142838
current_seq = 1063
count = 62
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 127us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.143456
last_received_ts = 101.142838
last_seq = 1063
current_ts = 101.160118
current_received_ts = 101.159485
current_seq = 1064
count = 63
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 117us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.160118
last_received_ts = 101.159485
last_seq = 1064
current_ts = 101.176781
current_received_ts = 101.176140
current_seq = 1065
count = 64
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 113us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.176781
last_received_ts = 101.176140
last_seq = 1065
current_ts = 101.193443
current_received_ts = 101.192970
current_seq = 1066
count = 65
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 132us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.193443
last_received_ts = 101.192970
last_seq = 1066
current_ts = 101.210106
current_received_ts = 101.209305
current_seq = 1067
count = 66
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 42us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.210106
last_received_ts = 101.209305
last_seq = 1067
current_ts = 101.226768
current_received_ts = 101.226265
current_seq = 1068
count = 67
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 29us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.226768
last_received_ts = 101.226265
last_seq = 1068
current_ts = 101.243431
current_received_ts = 101.242928
current_seq = 1069
count = 68
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 109us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.243431
last_received_ts = 101.242928
last_seq = 1069
current_ts = 101.260094
current_received_ts = 101.259285
current_seq = 1070
count = 69
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 40us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.260094
last_received_ts = 101.259285
last_seq = 1070
current_ts = 101.276756
current_received_ts = 101.276222
current_seq = 1071
count = 70
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 118us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.276756
last_received_ts = 101.276222
last_seq = 1071
current_ts = 101.293419
current_received_ts = 101.292786
current_seq = 1072
count = 71
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 40us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.293419
last_received_ts = 101.292786
last_seq = 1072
current_ts = 101.310081
current_received_ts = 101.309425
current_seq = 1073
count = 72
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 120us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.310081
last_received_ts = 101.309425
last_seq = 1073
current_ts = 101.326744
current_received_ts = 101.325974
current_seq = 1074
count = 73
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 121us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.326744
last_received_ts = 101.325974
last_seq = 1074
current_ts = 101.343407
current_received_ts = 101.342773
current_seq = 1075
count = 74
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 116us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.343407
last_received_ts = 101.342773
last_seq = 1075
current_ts = 101.360069
current_received_ts = 101.359413
current_seq = 1076
count = 75
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 120us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.360069
last_received_ts = 101.359413
last_seq = 1076
current_ts = 101.376732
current_received_ts = 101.376091
current_seq = 1077
count = 76
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 59us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.376732
last_received_ts = 101.376091
last_seq = 1077
current_ts = 101.393394
current_received_ts = 101.392929
current_seq = 1078
count = 77
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 120us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.393394
last_received_ts = 101.392929
last_seq = 1078
current_ts = 101.410057
current_received_ts = 101.409248
current_seq = 1079
count = 78
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 119us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.410057
last_received_ts = 101.409248
last_seq = 1079
current_ts = 101.426712
current_received_ts = 101.426056
current_seq = 1080
count = 79
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 33us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.426712
last_received_ts = 101.426056
last_seq = 1080
current_ts = 101.443375
current_received_ts = 101.442726
current_seq = 1081
count = 80
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 120us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.443375
last_received_ts = 101.442726
last_seq = 1081
current_ts = 101.460045
current_received_ts = 101.459244
current_seq = 1082
count = 81
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 41us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.460045
last_received_ts = 101.459244
last_seq = 1082
current_ts = 101.476700
current_received_ts = 101.476051
current_seq = 1083
count = 82
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 32us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.476700
last_received_ts = 101.476051
last_seq = 1083
current_ts = 101.493362
current_received_ts = 101.492714
current_seq = 1084
count = 83
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 122us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.493362
last_received_ts = 101.492714
last_seq = 1084
current_ts = 101.510033
current_received_ts = 101.509232
current_seq = 1085
count = 84
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 44us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.510033
last_received_ts = 101.509232
last_seq = 1085
current_ts = 101.526695
current_received_ts = 101.526047
current_seq = 1086
count = 85
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 41us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.526695
last_received_ts = 101.526047
last_seq = 1086
current_ts = 101.543350
current_received_ts = 101.542717
current_seq = 1087
count = 86
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 135us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.543350
last_received_ts = 101.542717
last_seq = 1087
current_ts = 101.560013
current_received_ts = 101.559380
current_seq = 1088
count = 87
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 115us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.560013
last_received_ts = 101.559380
last_seq = 1088
current_ts = 101.576683
current_received_ts = 101.576050
current_seq = 1089
count = 88
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 39us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.576683
last_received_ts = 101.576050
last_seq = 1089
current_ts = 101.593338
current_received_ts = 101.592850
current_seq = 1090
count = 89
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 96us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.593338
last_received_ts = 101.592850
last_seq = 1090
current_ts = 101.610008
current_received_ts = 101.609200
current_seq = 1091
count = 90
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 40us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.610008
last_received_ts = 101.609200
last_seq = 1091
current_ts = 101.626663
current_received_ts = 101.626060
current_seq = 1092
count = 91
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 35us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.626663
last_received_ts = 101.626060
last_seq = 1092
current_ts = 101.643326
current_received_ts = 101.642845
current_seq = 1093
count = 92
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 110us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.643326
last_received_ts = 101.642845
last_seq = 1093
current_ts = 101.659988
current_received_ts = 101.659348
current_seq = 1094
count = 93
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 47us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.659988
last_received_ts = 101.659348
last_seq = 1094
current_ts = 101.676659
current_received_ts = 101.676178
current_seq = 1095
count = 94
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 106us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.676659
last_received_ts = 101.676178
last_seq = 1095
current_ts = 101.693314
current_received_ts = 101.692680
current_seq = 1096
count = 95
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 112us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.693314
last_received_ts = 101.692680
last_seq = 1096
current_ts = 101.709976
current_received_ts = 101.709198
current_seq = 1097
count = 96
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 119us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.709976
last_received_ts = 101.709198
last_seq = 1097
current_ts = 101.726639
current_received_ts = 101.726051
current_seq = 1098
count = 97
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 112us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.726639
last_received_ts = 101.726051
last_seq = 1098
current_ts = 101.743309
current_received_ts = 101.742661
current_seq = 1099
count = 98
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 120us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.743309
last_received_ts = 101.742661
last_seq = 1099
current_ts = 101.759964
current_received_ts = 101.759323
current_seq = 1100
count = 99
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 30us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.759964
last_received_ts = 101.759323
last_seq = 1100
current_ts = 101.776627
current_received_ts = 101.775993
current_seq = 1101
count = 100
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 137us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.776627
last_received_ts = 101.775993
last_seq = 1101
current_ts = 101.793289
current_received_ts = 101.792778
current_seq = 1102
count = 101
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 34us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.793289
last_received_ts = 101.792778
last_seq = 1102
current_ts = 101.809952
current_received_ts = 101.809288
current_seq = 1103
count = 102
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 126us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.809952
last_received_ts = 101.809288
last_seq = 1103
current_ts = 101.826614
current_received_ts = 101.825974
current_seq = 1104
count = 103
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 61us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.826614
last_received_ts = 101.825974
last_seq = 1104
current_ts = 101.843269
current_received_ts = 101.842613
current_seq = 1105
count = 104
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 35us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.843269
last_received_ts = 101.842613
last_seq = 1105
current_ts = 101.859932
current_received_ts = 101.859444
current_seq = 1106
count = 105
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 118us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.859932
last_received_ts = 101.859444
last_seq = 1106
current_ts = 101.876602
current_received_ts = 101.875977
current_seq = 1107
count = 106
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 42us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.876602
last_received_ts = 101.875977
last_seq = 1107
current_ts = 101.893265
current_received_ts = 101.892632
current_seq = 1108
count = 107
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 143us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.893265
last_received_ts = 101.892632
last_seq = 1108
current_ts = 101.909927
current_received_ts = 101.909134
current_seq = 1109
count = 108
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 42us
(kms_flip:2517) DEBUG: name = flip
last_ts = 101.909927
last_received_ts = 101.909134
last_seq = 1109
current_ts = 101.926582
current_received_ts = 101.925995
current_seq = 1110
count = 109
seq_step = 1
(kms_flip:2517) DEBUG: Vblank took 749us
(kms_flip:2517) CRITICAL: Test assertion failure function run_test_step, file ../tests/kms_flip.c:928:
(kms_flip:2517) CRITICAL: Failed assertion: end - start < 500
(kms_flip:2517) igt_core-INFO: Stack trace:
(kms_flip:2517) igt_core-INFO:   #0 ../lib/igt_core.c:2075 __igt_fail_assert()
(kms_flip:2517) igt_core-INFO:   #1 ../tests/kms_flip.c:923 run_test_on_crtc_set.constprop.0()
(kms_flip:2517) igt_core-INFO:   #2 ../tests/kms_flip.c:1889 run_test()
(kms_flip:2517) igt_core-INFO:   #3 ../tests/kms_flip.c:2122 __igt_unique____real_main2045()
(kms_flip:2517) igt_core-INFO:   #4 ../tests/kms_flip.c:2045 main()
(kms_flip:2517) igt_core-INFO:   #5 [__libc_init_first+0x8a]
(kms_flip:2517) igt_core-INFO:   #6 [__libc_start_main+0x8b]
(kms_flip:2517) igt_core-INFO:   #7 [_start+0x25]
****  END  ****
Dynamic subtest A-eDP1: FAIL (3.187s)

Dmesg

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [98.965212] xe 0000:00:02.0: [drm:drm_mode_addfb2] [FB:428]

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

<7> [99.045078] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [99.050105] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 4051) -> ( 0 - 0), size 4051 -> 0

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

<7> [99.050243] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [99.050309] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 1, 13, 13, 13, 13, 13, 0, 0, 0, 3, 0 -> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [99.339801] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A]

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

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

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

<7> [99.341584] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:268:pipe B]

<7> [99.341966] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:387:pipe C]

<7> [99.342266] xe 0000:00:02.0: [drm:drm_mode_setcrtc] [CRTC:149:pipe A]

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

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

<7> [99.342863] xe 0000:00:02.0: [drm:intel_dp_compute_config_limits [xe]] [ENCODER:390:DDI A/PHY A][CRTC:149:pipe A] DP link limits: pixel clock 347710 kHz DSC off max lanes 4 max rate 810000 max pipe_bpp 30 min link_bpp 18.0000 max link_bpp 30.0000

<7> [99.343168] xe 0000:00:02.0: [drm:intel_dp_compute_link_config [xe]] DP lane count 4 clock 432000 bpp input 30 compressed 0.0000 link rate required 1303913 available 1728000

<7> [99.343481] xe 0000:00:02.0: [drm:intel_atomic_check [xe]] [CRTC:149:pipe A] hw max bpp: 30, pipe bpp: 30, dithering: 0

<7> [99.343800] xe 0000:00:02.0: [drm:intel_ddi_compute_config_late [xe]] [ENCODER:390:DDI A/PHY A] [CRTC:149:pipe A]

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [99.351788] xe 0000:00:02.0: [drm:skl_compute_wm [xe]] [PLANE:33:plane 1A] ddb ( 0 - 0) -> ( 0 - 4051), size 0 -> 4051

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

<7> [99.351959] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33: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> [99.352037] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] lines 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 4, 13, 13, 13, 13, 13, 0, 0, 0, 4, 0

<7> [99.352115] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] blocks 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 92, 297, 297, 297, 297, 297, 0, 0, 197, 92, 197

<7> [99.352199] xe 0000:00:02.0: [drm:skl_print_plane_changes [xe]] [PLANE:33:plane 1A] min_ddb 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 -> 183, 456, 456, 456, 456, 456, 0, 0, 198, 183, 198

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [99.354355] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] dp m2_n2: lanes: 4; data_m: 0, data_n: 0, link_m: 0, link_n: 0, tu: 0

<7> [99.354429] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] fec: disabled, enhanced framing: disabled

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

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

<7> [99.354655] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] minimum HBlank: 0

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

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

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

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

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

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

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

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

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

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

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

<7> [99.355537] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] vrr: dc balance: no, vmin: 0 vmax: 0 guardband: 0, slope: 0 max increase: 0 max decrease: 0 vblank target: 0

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

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

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

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

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

<7> [99.355997] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] port clock: 432000, pipe src: 2880x1800+0+0, pixel rate 347710, min cdclk 173855

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

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

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

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

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

<7> [99.356412] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] c10pll_hw_state: clock: 432000, fracen: no,

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

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

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

<7> [99.356708] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[0] = 0x4, pll[1] = 0x0, pll[2] = 0xa2, pll[3] = 0x1

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

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

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

<7> [99.357032] xe 0000:00:02.0: [drm:intel_crtc_state_dump [xe]] pll[16] = 0x85, pll[17] = 0xf, pll[18] = 0xe6, pll[19] = 0x23

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

<7> [100.123010] xe 0000:00:02.0: [drm:intel_dp_start_link_train [xe]] [CONNECTOR:391:eDP-1][ENCODER:390:DDI A/PHY A][DPRX] Using LINK_RATE_SET value 05

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

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

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

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

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

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

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

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

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

<7> [100.129965] xe 0000:00:02.0: [drm:intel_backlight_set_pwm_level [xe]] [CONNECTOR:391:eDP-1] set backlight PWM = 4518

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

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

<7> [100.148079] xe 0000:00:02.0: [drm:intel_modeset_verify_crtc [xe]] [CRTC:149:pipe A]

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

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

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

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

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