Bug 104688

======================================
Platform configuration
======================================

======================================
             Software
======================================
kernel version              : 4.15.0-rc7-drm-intel-qa-ww2-commit-353fa2d+
hostname                    : CNL-2
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 114.4
bios release date           : 11/30/2017
ksc                         : 1.33
hardware acceleration       : disabled
swap partition              : enabled on (/dev/nvme0n1p3)

======================================
        Graphic drivers
======================================
grep: /opt/X11R7/var/log/Xorg.0.log: No such file or directory
libdrm                      : 2.4.89
cairo                       : 1.15.11
intel-gpu-tools (tag)       : intel-gpu-tools-1.20-277-gb64c093
intel-gpu-tools (commit)    : b64c093

======================================
             Hardware
======================================
motherboard model          : CannonLakeClientPlatform
motherboard id             : CannonLakeYLPDDR4RVP
form factor                : Laptop
manufacturer               : IntelCorporation
cpu family                 : Other
cpu family id              : 6
cpu information            : 1.00GHz
gpu card                   : Intel Corporation Device 5a49 (rev 03) (prog-if 00 [VGA controller])
memory ram                 : 7.61 GB
max memory ram             : 8 GB
cpu thread                 : 4
cpu core                   : 2
cpu model                  : 102
cpu stepping               : 2
socket                     : Other
current cd clock frequency : 168000 kHz
maximum cd clock frequency : 528000 kHz
displays connected         : eDP-1 HDMI-A-1

======================================
             Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.7
guc fw loaded             : fetch NONE, load NONE
guc version wanted        : wanted 0.0, found 0.0
guc version found         : wanted 0.0, found 0.0

Armando, the dmesg does not contain specified warning, please recheck attachments. Thanks.

Hi Eli, this Warning appears on test execution output and not in dmesg

==================================
Test output
==================================
(02:36 PM) [gfx@CNL-1] [tests]$ : sudo -E ./kms_sysfs_edid_timing --d
IGT-Version: 1.21-g94bd67c (x86_64) (Linux: 4.15.0-rc8-drm-intel-qa-ww3-commit-6a58f7b+ x86_64)
(kms_sysfs_edid_timing:2275) DEBUG: card0-DP-2: mean.max 371875.00ns, 371.88us, 0.37ms, mean.avg 321144.60ns, 321.14us, 0.32ms
(kms_sysfs_edid_timing:2275) DEBUG: card0-eDP-1: mean.max 1980154.00ns, 1980.15us, 1.98ms, mean.avg 1545621.67ns, 1545.62us, 1.55ms
(kms_sysfs_edid_timing:2275) DEBUG: card0-DP-1: mean.max 247716.00ns, 247.72us, 0.25ms, mean.avg 222247.67ns, 222.25us, 0.22ms
(kms_sysfs_edid_timing:2275) DEBUG: card0-HDMI-A-1: mean.max 13513471.00ns, 13513.47us, 13.51ms, mean.avg 13426824.93ns, 13426.82us, 13.43ms
(kms_sysfs_edid_timing:2275) WARNING: card0-HDMI-A-1: probe time exceed 10ms, max=13.51ms, avg=13.43ms
(kms_sysfs_edid_timing:2275) igt-core-DEBUG: Exiting with status code 0

Created attachment 136857 [details]
dmesg log

Thanks for the clarification.

the following test is falling on KBL 

Test 
==================================
igt@kms_sysfs_edid_timing

**** DEBUG ****
(kms_sysfs_edid_timing:8097) igt-core-INFO: IGT-Version: 1.21-g37bd27f (x86_64)                                                                                                              (Linux: 4.15.0-drm-intel-qa-ww6-commit-078873d+ x86_64)
(kms_sysfs_edid_timing:8097) DEBUG: card0-DP-2: mean.max 34424967.00ns, 34424.97                                                                                                             us, 34.42ms, mean.avg 33137548.20ns, 33137.55us, 33.14ms
(kms_sysfs_edid_timing:8097) WARNING: card0-DP-2: probe time exceed 10ms, max=34                                                                                                             .42ms, avg=33.14ms
(kms_sysfs_edid_timing:8097) DEBUG: card0-DP-1: mean.max 49308875.00ns, 49308.88                                                                                                             us, 49.31ms, mean.avg 48870427.87ns, 48870.43us, 48.87ms
(kms_sysfs_edid_timing:8097) WARNING: card0-DP-1: probe time exceed 10ms, max=49                                                                                                             .31ms, avg=48.87ms
(kms_sysfs_edid_timing:8097) DEBUG: card0-HDMI-A-1: mean.max 133577037.00ns, 133                                                                                                             577.04us, 133.58ms, mean.avg 127050477.33ns, 127050.48us, 127.05ms
(kms_sysfs_edid_timing:8097) WARNING: card0-HDMI-A-1: probe time exceed 10ms, ma                                                                                                             x=133.58ms, avg=127.05ms
(kms_sysfs_edid_timing:8097) CRITICAL: Test assertion failure function __real_ma                                                                                                             in40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:8097) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_                                                                                                             TOTAL * 1e6)
(kms_sysfs_edid_timing:8097) CRITICAL: card0-HDMI-A-1: average probe time exceed                                                                                                             ed 50ms, max=133.58ms, avg=127.05ms

First of all. Sorry about spam.
This is mass update for our bugs. 

Sorry if you feel this annoying but with this trying to understand if bug still valid or not.
If bug investigation still in progress, please ignore this and I apologize!

If you think this is not anymore valid, please comment to the bug that can be closed.
If you haven't tested with our latest pre-upstream tree(drm-tip), can you do that also to see if issue is valid there still and if you cannot see issue there, please comment to the bug.

When running this test all platforms get this warn:

(kms_sysfs_edid_timing:9108) WARNING: card0-VGA-1: probe time exceed 10ms, max=13.84ms, avg=13.63ms

And IVB, BYT, BSW, KBL and CFL, has a failure assertion additional to the warn:

Results for igt@kms_sysfs_edid_timing
Result: fail

Out	
IGT-Version: 1.21-ge3a0ed9 (x86_64) (Linux: 4.16.0-rc7-drm-intel-qa-ww14-commit-c46052c+ x86_64)
Stack trace:
  #0 [__igt_fail_assert+0x101]
  #1 [__real_main40+0x232]
  #2 [main+0x23]
  #3 [__libc_start_main+0xf1]
  #4 [_start+0x29]
  #5 [<unknown>+0x29]
FAIL (1.274s)
Err	
(kms_sysfs_edid_timing:3578) WARNING: card0-DP-1: probe time exceed 10ms, max=92.25ms, avg=84.29ms
(kms_sysfs_edid_timing:3578) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:3578) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:3578) CRITICAL: card0-DP-1: average probe time exceeded 50ms, max=92.25ms, avg=84.29ms
Test kms_sysfs_edid_timing failed.
**** DEBUG ****
(kms_sysfs_edid_timing:3578) igt-core-INFO: IGT-Version: 1.21-ge3a0ed9 (x86_64) (Linux: 4.16.0-rc7-drm-intel-qa-ww14-commit-c46052c+ x86_64)
(kms_sysfs_edid_timing:3578) DEBUG: card0-DP-1: mean.max 92251369.00ns, 92251.37us, 92.25ms, mean.avg 84293253.07ns, 84293.25us, 84.29ms
(kms_sysfs_edid_timing:3578) WARNING: card0-DP-1: probe time exceed 10ms, max=92.25ms, avg=84.29ms
(kms_sysfs_edid_timing:3578) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:3578) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:3578) CRITICAL: card0-DP-1: average probe time exceeded 50ms, max=92.25ms, avg=84.29ms
(kms_sysfs_edid_timing:3578) igt-core-INFO: Stack trace:
(kms_sysfs_edid_timing:3578) igt-core-INFO:   #0 [__igt_fail_assert+0x101]
(kms_sysfs_edid_timing:3578) igt-core-INFO:   #1 [__real_main40+0x232]
(kms_sysfs_edid_timing:3578) igt-core-INFO:   #2 [main+0x23]
(kms_sysfs_edid_timing:3578) igt-core-INFO:   #3 [__libc_start_main+0xf1]
(kms_sysfs_edid_timing:3578) igt-core-INFO:   #4 [_start+0x29]
(kms_sysfs_edid_timing:3578) igt-core-INFO:   #5 [<unknown>+0x29]
****  END  ****

*** This bug has been marked as a duplicate of bug 100047 ***