Bug 100047

Summary: [IGT][CI] kms_sysfs_edid_timing test Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
Product: DRI Reporter: Rami <ramix.ben.hassine>
Component: DRM/IntelAssignee: Petri Latvala <petri.latvala>
Status: ASSIGNED --- QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: normal    
Priority: low CC: armando.antoniox.mora.reos, intel-gfx-bugs
Version: unspecified   
Hardware: x86-64 (AMD64)   
OS: Linux (All)   
Whiteboard: ReadyForDev
i915 platform: BDW, BSW/CHT, BXT, BYT, CFL, CNL, GLK, HSW, IVB, KBL, SKL, SNB i915 features: display/DP
Attachments:
Description Flags
dmesg
none
kms_sysfs.log
none
Scope trace showing 1ms gap between each 8 byte read
none
CFL-Kern-Log none

Description Rami 2017-03-03 11:24:59 UTC
Created attachment 130041 [details]
dmesg

This test is fail on SKL whith last setup:

setup:
=========
SKLS1:
------
Platform SKL Gigabyte
CPU: Intel(R) Core(TM) i5-6600 CPU @ 3.30GHz (family 6, model 94, stepping 3)
GPU: Intel® HD Graphics 530 - Intel Corporation Sky Lake Integrated Graphics
(rev 06)
Motherboard version: H170N-WIFI-CF
Memory: 2x 4GB Kingston 9905622-055.A00G

Software
===========
Bios: F3
Linux distribution: Ubuntu 16.04 64 bits
DMC 1.26 from https://01.org/sites/default/files/downloads/intelr-graphics-linux/skldmcver126.tar_1.bz2
GUC 6.1 from https://01.org/sites/default/files/downloads/intelr-graphics-linux/sklgucver61.tar.bz2
kernel:drm-tip: 2017y-03m-01d-22h-54m-20s UTC integration manifest
  commit: ae99ea2cc4782d18a2ffc8ef01367f5fa8d350f2
  author: Daniel Vetter <daniel.vetter@ffwll.ch>
  authored_date: Wed Mar 01 22:55:22 2017 +0000
intel-gpu-tool:intel-gpu-tools-1.17-261-g8f3164f
drm:libdrm-2.4.75-10-gf6499b1
cairo:1.15.4
xserver:xorg-server-1.19.0-125-g7d7788e
xf86-video-intel:2.99.917-758-g860c366
libva:libva-1.7.3.pre1-84-ge613327
vaapi-intel-driver:1.7.3-325-g03a86fc

Steps
=======
Run igt test:
./kms_sysfs_edid_timing

Actual results:
===============
IGT-Version: 1.17-g8f3164f (x86_64) (Linux: 4.10.0-tip-201703020159+ x86_64)
(kms_sysfs_edid_timing:4917) WARNING: card0-DP-2: probe time exceed 10ms, max=267.44ms, avg=267.26ms
(kms_sysfs_edid_timing:4917) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:4917) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:4917) CRITICAL: card0-DP-2: average probe time exceeded 50ms, max=267.44ms, avg=267.26ms
Stack trace:
  #0 [__igt_fail_assert+0xf1]
  #1 [__real_main40+0x233]
  #2 [main+0x35]
  #3 [__libc_start_main+0xf0]
  #4 [_start+0x29]
  #5 [<unknown>+0x29]
Test kms_sysfs_edid_timing failed.
**** DEBUG ****
(kms_sysfs_edid_timing:4917) DEBUG: card0-DP-2: mean.max 267439202.00ns, 267439.20us, 267.44ms, mean.avg 267257649.20ns, 267257.65us, 267.26ms
(kms_sysfs_edid_timing:4917) WARNING: card0-DP-2: probe time exceed 10ms, max=267.44ms, avg=267.26ms
(kms_sysfs_edid_timing:4917) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:4917) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:4917) CRITICAL: card0-DP-2: average probe time exceeded 50ms, max=267.44ms, avg=267.26ms
****  END  ****
FAIL (4.010s)
Comment 1 Rami 2017-03-22 15:20:41 UTC
Reproduced on SKL with last setup:

setup:
=========
Platform SKL Gigabyte
CPU: Intel(R) Core(TM) i5-6600 CPU @ 3.30GHz (family 6, model 94, stepping 3)
GPU: Intel® HD Graphics 530 - Intel Corporation Sky Lake Integrated Graphics
(rev 06)
Motherboard version: H170N-WIFI-CF
Memory: 2x 4GB Kingston 9905622-055.A00G

Software
===========
Bios: F3
Linux distribution: Ubuntu 16.04 64 bits
DMC 1.26 from https://01.org/sites/default/files/downloads/intelr-graphics-linux/skldmcver126.tar_1.bz2
GUC 6.1 from https://01.org/sites/default/files/downloads/intelr-graphics-linux/sklgucver61.tar.bz2
kernel:drm-tip: 2017y-03m-15d-21h-47m-56s UTC integration manifest
  commit: d7cb114e1327b50c609ee6e67122cc0293ea515f
  author: Chris Wilson <chris@chris-wilson.co.uk>
  authored_date: Wed Mar 15 21:48:18 2017 +0000
drm:libdrm-2.4.75-14-g19c4cfc from  git://git.freedesktop.org/git/mesa/drm=
mesa:mesa-17.0.0 from git://git.freedesktop.org/git/mesa/mesa
cairo:1.15.4 from  git://anongit.freedesktop.org/cairo
xorg-server-macros:util-macros-1.19.1-2-g39f07f7 from   git://git.freedesktop.org/git/xorg/util/macros
xserver:xorg-server-1.19.0-133-g386fbbe from git://git.freedesktop.org/git/xorg/xserver
xf86-video-intel: 2.99.917-766-gbe913a3 from git://git.freedesktop.org/git/xorg/driver/xf86-video-intel
libva: libva-1.7.3.pre1-85-gefc164d
vaapi-intel-driver:1.7.3-343-gef83d40 
waffle:debian/1.5.2-3-202-g03d5566
intel-gpu-tool:intel-gpu-tools-1.17-291-g90c883c
Comment 2 maria guadalupe 2017-04-17 19:04:19 UTC
The issue is present over GLK with the following configuration :

Steps
=======
Run igt test:
./kms_sysfs_edid_timing

 Software
======================================
kernel version              : 4.11.0-rc6-drm-tip-ww16-commit-6184edc+
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 41.51
bios release date           : 03/31/2017
ksc                         : 1.25

======================================
        Graphic drivers
======================================
xorg-xserver                : 1.18.4
libdrm                      : 2.4.79
cairo                       : 1.15.5
xserver                     : X.Org X Server 1.18.4
intel-gpu-tools (tag)       : intel-gpu-tools-1.18-73-gd8b83aa
intel-gpu-tools (commit)    : d8b83aa

======================================
             Hardware
======================================
platform                  : Geminilake
motherboard id             : GLKRVP1DDR4(05)
cpu family id              : 6
cpu information            : Genuine Intel(R) CPU @ 1.10GHz
gpu card                   : Intel Corporation Device 3184 (rev 01) (prog-if 00 [VGA controller])
memory ram                 : 7.64 GB
max memory ram             : 16 GB
cpu thread                 : 4
cpu core                   : 4
cpu model                  : 122
hard drive                 : 223GiB (240GB)
current cd clock frequency : 316800 kHz
maximum cd clock frequency : 316800 kHz

======================================
             Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.4

output
======================================
**** DEBUG ****
(kms_sysfs_edid_timing:2497) DEBUG: card0-HDMI-A-2: mean.max 85525654.00ns, 85525.65us, 85.53ms, mean.avg 83889216.27ns, 83889.22us, 83.89ms
(kms_sysfs_edid_timing:2497) WARNING: card0-HDMI-A-2: probe time exceed 10ms, max=85.53ms, avg=83.89ms
(kms_sysfs_edid_timing:2497) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:2497) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:2497) CRITICAL: card0-HDMI-A-2: average probe time exceeded 50ms, max=85.53ms, avg=83.89ms
****  END  ****
Comment 3 Ander Conselvan de Oliveira 2017-04-20 14:22:39 UTC
I did some quick testing in GLK, about 80ms is spent in gmbus_xfer().
Comment 4 maria guadalupe 2017-04-20 19:41:14 UTC
Created attachment 130951 [details]
kms_sysfs.log
Comment 5 cprigent 2017-04-26 08:31:15 UTC
On GLK, the bug is reproduced with only HDMI monitor connected. The test is Pass with eDP + DP.
Comment 6 Humberto Israel Perez Rodriguez 2017-05-18 00:03:37 UTC
issue still present on latest configuration for APL

======================================
             Software
======================================
kernel version              : 4.12.0-rc1-drm-tip-ww20-commit-713f8ec+
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 5.6
bios release date           : 03/10/2017
ksc                         : 16.0

======================================
        Graphic drivers
======================================
Component: drm
    tag: libdrm-2.4.80-11-ga2fa2e0
    commit: a2fa2e08692483cf9f4d06caa6e0f0add59e3343

Component: cairo
    tag: 1.15.4-21-g9d44136
    commit: 9d44136ef8e2a1ad2c6631beb4bbdaeed7a2dad8

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.18-173-g93215b0
    commit: 93215b00db06ba568c34a6cad194f4749bbfbc9d

Component: piglit
    tag: piglit-v1
    commit: 7352f4a98a23eae1201bfc4a0121d9c3a969d23f

======================================
             Hardware
======================================
motherboard model          : NUC6CAYS
motherboard id             : NUC6CAYB
form factor                : Desktop
manufacturer               : Intelcorporation
cpu family                 : Celeron
cpu family id              : 6
cpu information            : Intel(R) Celeron(R) CPU J3455 @ 1.50GHz
gpu card                   : Intel Corporation Device 5a85 (rev 0b) (prog-if 00 [VGA controller])
memory ram                 : 15.54 GB
cpu thread                 : 4
cpu core                   : 4
cpu model                  : 92
cpu stepping               : 9
signature                  : Type 0, Family 6, Model 92, Stepping 9
current cd clock frequency : 384000 kHz
maximum cd clock frequency : 624000 kHz
displays connected         : DP-1 DP-2

======================================
             Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.7
guc fw loaded             : NONE
guc version wanted        : 0.0
guc version found         : 0.0
Add Comment
Comment 7 Humberto Israel Perez Rodriguez 2017-06-01 00:21:55 UTC
same issue on BSW with latest configuration

kms_sysfs_edid_timing

Component: drm
    tag: libdrm-2.4.80-18-gce9e3ba
    commit: ce9e3ba6e2cc65e1e9e6e05a5f326c4dd25ab2c4

Component: cairo
    tag: 1.15.4-22-g0fd0fd0
    commit: 0fd0fd0ae9ad8cfb177bb844091de98c0235917e

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.18-211-g00ce341
    commit: 00ce341b95c718611689ded8ccec45086186c5b7

Component: piglit
    tag: piglit-v1
    commit: ebbb9c5dcc6a637884d54e06eb430a8c14993413

kernel
===================================================
commit 4aa1d46d3b24bbe545cdf7cbd407c18f5cd5e43d
Author:     Daniel Vetter <daniel.vetter@ffwll.ch>
AuthorDate: Wed May 31 10:59:05 2017 +0200
Commit:     Daniel Vetter <daniel.vetter@ffwll.ch>
CommitDate: Wed May 31 10:59:05 2017 +0200

    drm-tip: 2017y-05m-31d-08h-58m-36s UTC integration manifest
Comment 8 Clinton Taylor 2017-06-08 21:07:02 UTC
There appears to be a 5ms gap between each 8 byte read of the EDID. Clock is low during this time so it appears as a clock stretch by the sink.
Comment 9 Clinton Taylor 2017-06-08 21:10:10 UTC
Created attachment 131818 [details]
Scope trace showing 1ms gap between each 8 byte read
Comment 10 Clinton Taylor 2017-06-08 21:14:34 UTC
comment #8 should read 1ms between 8 byte reads as seen in the scope shot attached.

DDC operates at 100 Khz clock rate and AUX at 1 Mhz. eDP also only reads 128 bytes total compared to HDMI/DP reads of 256 or 512 bytes. 

Are we sure 50ms is a valid test for DDC traffic?
Comment 11 Elizabeth 2017-06-27 20:12:46 UTC
Hello, 
It looks like this bug is going to need more time to get resolved, I'm changing the status to NEEDINFO. If there is any new advance on this case, please share and change to REOPEN. Thank you.
Comment 12 Marta Löfstedt 2017-06-28 11:51:14 UTC
I can reproduce this on BDW NUCi5, HDMI, drm-tip 4.12.0-rc7+:
(kms_sysfs_edid_timing:2081) DEBUG: card0-HDMI-A-2: mean.max 49731407.00ns, 49731.41us, 49.73ms, mean.avg 49258199.73ns, 49258.20us, 49.26ms
(kms_sysfs_edid_timing:2081) WARNING: card0-HDMI-A-2: probe time exceed 10ms, max=49.73ms, avg=49.26ms
(kms_sysfs_edid_timing:2081) DEBUG: card0-DP-1: mean.max 78682600.00ns, 78682.60us, 78.68ms, mean.avg 78413307.60ns, 78413.31us, 78.41ms
(kms_sysfs_edid_timing:2081) WARNING: card0-DP-1: probe time exceed 10ms, max=78.68ms, avg=78.41ms
(kms_sysfs_edid_timing:2081) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:2081) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:2081) CRITICAL: card0-DP-1: average probe time exceeded 50ms, max=78.68ms, avg=78.41ms

Also, if I increase THRESHOLD_TOTAL to 100ms the test pass.
The only reasoning behind the 50ms THRESHOLD_TOTAL in the test, is in the test description ""So let's just check for some reasonable timing here"

Clinto if you can argue for a longer THRESHOLD_TOTAL please send up a patch and discuss on the list.
Comment 13 Armando Antonio 2017-07-06 14:49:32 UTC
The following test fail on IVB with latest configuration

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


====================================================
Graphic Stack
====================================================
Component: drm
    tag: libdrm-2.4.81-24-g3095cc8
    commit: 3095cc8eaba1aa87ad38c04ae2b1eabe30f7e16c
Component: cairo
    tag: 1.15.6-2-g57b4050
    commit: 57b40507dda3f58dfc8635548d606b86dc7bcf51
Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-57-g6fcc8e8
    commit: 6fcc8e8b247661c7950b998e0b95141ffbd6b833
Component: piglit
    tag: piglit-v1
    commit: c8f4fd9eeb298a2ef0855927f22634f794ef3eff
======================================
             Hardware
======================================
platform                   : Ivy Bridge
motherboard model          : Inspiron660
motherboard id             : 0XR1GT
form factor                : Desktop
manufacturer               : DellInc.
cpu family                 : Core i5
cpu family id              : 6
cpu information            : Intel(R) Core(TM) i5-3330 CPU @ 3.00GHz
gpu card                   : Intel Corporation Xeon E3-1200 v2/3rd Gen Core processor Graphics Controller (rev 09) (prog-if 00 [VGA controller])
memory ram                 : 7.7 GB
max memory ram             : 8 GB
cpu thread                 : 4
cpu core                   : 4
cpu model                  : 58
cpu stepping               : 9
socket                     : Socket BGA1155
signature                  : Type 0, Family 6, Model 58, Stepping 9
hard drive                 : 74GiB (80GB)
current cd clock frequency : 400000 kHz
maximum cd clock frequency : 400000 kHz
displays connected         : VGA-1 HDMI-A-1
Comment 14 Ricardo Madrigal 2017-07-10 15:02:35 UTC
The following test fail on KBL  with latest configuration

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

====================================================
Graphic Stack
====================================================
Component: drm
    tag: libdrm-2.4.81-24-g3095cc8
    commit: 3095cc8eaba1aa87ad38c04ae2b1eabe30f7e16c
Component: cairo
    tag: 1.15.6-2-g57b4050
    commit: 57b40507dda3f58dfc8635548d606b86dc7bcf51
Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-57-g6fcc8e8
    commit: 6fcc8e8b247661c7950b998e0b95141ffbd6b833
Component: piglit
    tag: piglit-v1
    commit: c8f4fd9eeb298a2ef0855927f22634f794ef3eff

======================================
             Hardware
======================================
motherboard id             : NUC7i5BNB
form factor                : Desktop
cpu family                 : Core i5
cpu family id              : 6
cpu information            : Intel(R) Core(TM) i5-7260U CPU @ 2.20GHz
gpu card                   : Intel Corporation Device 5926 (rev 06) (prog-if 00 [VGA controller])
memory ram                 : 15.58 GB
max memory ram             : 32 GB
cpu thread                 : 4
cpu core                   : 2
cpu model                  : 142
cpu stepping               : 9
socket                     : Other
signature                  : Type 0, Family 6, Model 142, Stepping 9
hard drive                 : 111GiB (120GB)
current cd clock frequency : 337500 kHz
maximum cd clock frequency : 675000 kHz
displays connected         : DP-1
Comment 15 Ricardo Madrigal 2017-07-20 19:07:52 UTC
The following tests fail on BYT with latest configuration

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

====================================================
Graphic Stack
====================================================
Component: drm
     tag: libdrm-2.4.81-31-g23e234a
     commit: 23e234a3503f51b9d9c585123d33b936f522808d
Component: cairo
    tag: 1.15.6-2-g57b4050
    commit: 57b40507dda3f58dfc8635548d606b86dc7bcf51
Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-96-gfb1ddc4
    commit: fb1ddc47003ad6a683db79beeb81b6cbab1feb7c
Component: piglit
    tag: piglit-v1
    commit: 56e7e5583cd4a3ca15a8cda154d46d168959dd25

======================================
             Hardware
======================================
motherboard model          : .................................
motherboard id             : DN2820FYK
form factor                : Desktop
manufacturer               : .................................
cpu family                 : Celeron
cpu family id              : 6
cpu information            : Intel(R) Celeron(R) CPU  N2830  @ 2.16GHz
gpu card                   : Intel Corporation Atom Processor Z36xxx/Z37xxx Series Graphics & Display (rev 0e) (prog-if 00 [VGA controller])
memory ram                 : 7.66 GB
max memory ram             : 8 GB
cpu thread                 : 2
cpu core                   : 2
cpu model                  : 55
cpu stepping               : 8
socket                     : <OUT OF SPEC>
signature                  : Type 0, Family 6, Model 55, Stepping 8
hard drive                 : 111GiB (120GB)
current cd clock frequency : 266667 kHz
maximum cd clock frequency : 400000 kHz
displays connected         : HDMI-A-1
Comment 16 Hector Velazquez 2017-07-26 19:53:53 UTC
The following test FAIL on IVB with this commit

Tests List:

igt@kms_sysfs_edid_timing



This is my configuration:

====================================================
Graphic Stack
====================================================
Component: drm
    tag: libdrm-2.4.81-33-g3876bc2
    commit: 3876bc246a07070a6043159cd7623d4def9bbd4c

Component: cairo
    tag: 1.15.6-2-g57b4050
    commit: 57b40507dda3f58dfc8635548d606b86dc7bcf51

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-112-g493151b
    commit: 493151b0768aa4ca535cef49cb7efa174a9c3a77

Component: piglit
    tag: piglit-v1
    commit: 973892687cf5c2f8e2dbe1d22998b82736643787
Comment 17 Hector Velazquez 2017-07-31 20:26:52 UTC
The following tests FAIL on BSW with this configuration

Tests List:

igt@kms_sysfs_edid_timing



This is my configuration:

**************************************************************
* * * * * * * * HARDWARE SPECIFICATIONS * * * * * * * * * * * 
**************************************************************

==============================================================
Essentials
==============================================================
Processor Number			N3700
Status					Launched
Launch Date				Q1'15
Lithography				14 nm


==============================================================
Performance
==============================================================
# of Cores				4
# of Threads				4
Processor Base Frequency		1.60 GHz
Burst Frequency				2.40 GHz
Cache					2 MB L2
TDP					6 W
Scenario Design Power (SDP)		4 W

==============================================================
Memory Specifications
==============================================================
Max Memory Size 			8 GB
Memory Types				DDR3L-1600
Max # of Memory Channels		2
ECC Memory Supported  			No

==============================================================
Graphics Specifications
==============================================================
Processor Graphics 			Intel® HD Graphics
Graphics Base Frequency			400.00 MHz
Graphics Burst Frequency		700.00 MHz
Graphics Video Max Memory		8 GB
Graphics Output				eDP/DP/HDMI
Execution Units				16
DirectX* Support			Yes
OpenGL* Support				Yes
Intel® Quick Sync Video 		Yes
Intel® InTru™ 3D Technology		No
Intel® Clear Video HD Technology	Yes
Intel® Clear Video Technology		Yes
Intel® Wireless Display 		Yes
# of Displays Supported 		3


====================================================
Graphic Stack
====================================================

Component: drm
    tag: libdrm-2.4.81-33-g3876bc2
    commit: 3876bc246a07070a6043159cd7623d4def9bbd4c

Component: cairo
    tag: 1.15.6-2-g57b4050
    commit: 57b40507dda3f58dfc8635548d606b86dc7bcf51

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-112-g493151b
    commit: 493151b0768aa4ca535cef49cb7efa174a9c3a77

Component: piglit
    tag: piglit-v1
    commit: 973892687cf5c2f8e2dbe1d22998b82736643787
Comment 18 Marta Löfstedt 2017-08-04 09:15:25 UTC
(In reply to Clinton Taylor from comment #10)
> comment #8 should read 1ms between 8 byte reads as seen in the scope shot
> attached.
> 
> DDC operates at 100 Khz clock rate and AUX at 1 Mhz. eDP also only reads 128
> bytes total compared to HDMI/DP reads of 256 or 512 bytes. 
> 
> Are we sure 50ms is a valid test for DDC traffic?

Clinton, I tested OK with 100ms instead of 50ms on BDW/HDMI, since this was based on your reasoning, could you send up an patch fixing the test.
Comment 19 Clinton Taylor 2017-08-04 18:01:10 UTC
Theoretical maximum speed of an HDMI 2 block edid read is about 40ms. The current WARNING threshold of 10ms per probe is absolutely incorrect since the tool doesn't separate disconnected connectors from ones that actually have EDID. 

The 50ms Max Threshold as stated in the tests is really close to the required per connector of an HDMI 2 block EDID read. Any large excursions like the original bug post of 267ms should actually be flagged as a failure. 

I plan on submitting a patch for 95ms which is a little (~10%) above the maximum measured on SKL for a 4 block EDID read using LSPCON. This should be a valid margin of error.

Measured on a scope and my SKL NUC using LSPCON HDMI port:

DVI EDID 1 block 21.5ms tool reports 27.25 max

HDMI EDID 2 block 41ms tool reports 46.85 max

HDMI EDID 4 Block 82ms tools reports 87.69 max
Comment 20 Maarten Lankhorst 2017-08-07 11:10:56 UTC
So perhaps change the timeout to scale with edid blocks? Allow 40 ms per block?
Comment 21 Marta Löfstedt 2017-08-10 06:38:10 UTC
with the v3 of Clintons patch: 
https://patchwork.freedesktop.org/series/28399/

I fail the test again:

IGT-Version: 1.19-gb0dcd0dc (x86_64) (Linux: 4.13.0-rc4+ x86_64)
(kms_sysfs_edid_timing:31931) CRITICAL: Test assertion failure function main, file kms_sysfs_edid_timing.c:140:
(kms_sysfs_edid_timing:31931) CRITICAL: Failed assertion: mean.mean < (threshold * 1e6)
(kms_sysfs_edid_timing:31931) CRITICAL: card0-HDMI-A-2: average probe time exceeded 5ms, max=50,23ms, avg=49,77ms
Stack trace:
  #0 [__igt_fail_assert+0x101]
  #1 [main+0x38e]
  #2 [__libc_start_main+0xf1]
  #3 [_start+0x2a]
  #4 [<unknown>+0x2a]
Test kms_sysfs_edid_timing failed.
**** DEBUG ****
(kms_sysfs_edid_timing:31931) igt-core-DEBUG: Test requirement passed: !igt_run_in_simulation()
(kms_sysfs_edid_timing:31931) DEBUG: card0-HDMI-A-2: mean.max 50231990,00ns, 50231,99us, 50,23ms, mean.avg 49768666,60ns, 49768,67us, 49,77ms, edid_size 128, threshold 5
(kms_sysfs_edid_timing:31931) CRITICAL: Test assertion failure function main, file kms_sysfs_edid_timing.c:140:
(kms_sysfs_edid_timing:31931) CRITICAL: Failed assertion: mean.mean < (threshold * 1e6)
(kms_sysfs_edid_timing:31931) CRITICAL: card0-HDMI-A-2: average probe time exceeded 5ms, max=50,23ms, avg=49,77ms
****  END  ****
FAIL (0,500s)
Comment 22 Marta Löfstedt 2017-08-10 06:58:35 UTC
with Clintons V3 and:


--- a/tests/kms_sysfs_edid_timing.c
+++ b/tests/kms_sysfs_edid_timing.c
@@ -99,7 +99,7 @@ int main(int argc, char **argv)
 
                edid_size = read(fd_edid, edid, 512);
                threshold = THRESHOLD_PER_EDID_BLOCK * (edid_size / 128);
-               if (lspcon_present || (edid_size > 128 &&
+               if (lspcon_present || (edid_size >= 128 &&
                    !strncmp(de->d_name, "card0-HDMI", 10))) {
                        threshold *= HDMI_THRESHOLD_MULTIPLIER;
                }


the test pass
Comment 24 Elizabeth 2017-08-23 16:38:48 UTC
./kms_sysfs_edid_timing

Still failing on GLK with:

commit ad6ab9f96437f0cb1f4d8a7840fd9eeb894eb12e
Author:     Gustavo Padovan <gustavo.padovan@collabora.com>
AuthorDate: Fri Aug 18 15:26:42 2017 -0300
Commit:     Gustavo Padovan <gustavo.padovan@collabora.com>
CommitDate: Fri Aug 18 15:26:42 2017 -0300

    drm-tip: 2017y-08m-18d-18h-21m-46s UTC integration manifest

No patches applied.
Comment 25 Elizabeth 2017-08-23 20:25:00 UTC
(In reply to Elizabeth from comment #24)
> ./kms_sysfs_edid_timing
> 
> Still failing on GLK with:
> 
> commit ad6ab9f96437f0cb1f4d8a7840fd9eeb894eb12e
> Author:     Gustavo Padovan <gustavo.padovan@collabora.com>
> AuthorDate: Fri Aug 18 15:26:42 2017 -0300
> Commit:     Gustavo Padovan <gustavo.padovan@collabora.com>
> CommitDate: Fri Aug 18 15:26:42 2017 -0300
> 
>     drm-tip: 2017y-08m-18d-18h-21m-46s UTC integration manifest
> 
> No patches applied.
Also SKL, same commit, no patches.
Comment 26 Hector Velazquez 2017-09-06 16:31:14 UTC
The following tests PASS on SKL 

Tests List:

igt@kms_sysfs_edid_timing

======================================
        Output
======================================

IGT-Version: 1.19-g490b386 (x86_64) (Linux: 4.13.0-drm-tip-ww36-commit-9dd459e+ x86_64)
(kms_sysfs_edid_timing:2001) DEBUG: card0-DP-2: mean.max 96951.00ns, 96.95us, 0.10ms, mean.avg 55862.13ns, 55.86us, 0.06ms
(kms_sysfs_edid_timing:2001) DEBUG: card0-HDMI-A-2: mean.max 8218906.00ns, 8218.91us, 8.22ms, mean.avg 7884490.40ns, 7884.49us, 7.88ms
(kms_sysfs_edid_timing:2001) DEBUG: card0-DP-3: mean.max 14881491.00ns, 14881.49us, 14.88ms, mean.avg 12545055.60ns, 12545.06us, 12.55ms
(kms_sysfs_edid_timing:2001) WARNING: card0-DP-3: probe time exceed 10ms, max=14.88ms, avg=12.55ms
(kms_sysfs_edid_timing:2001) DEBUG: card0-DP-1: mean.max 50492588.00ns, 50492.59us, 50.49ms, mean.avg 49787913.20ns, 49787.91us, 49.79ms
(kms_sysfs_edid_timing:2001) WARNING: card0-DP-1: probe time exceed 10ms, max=50.49ms, avg=49.79ms
(kms_sysfs_edid_timing:2001) DEBUG: card0-HDMI-A-1: mean.max 7955567.00ns, 7955.57us, 7.96ms, mean.avg 7894139.60ns, 7894.14us, 7.89ms
(kms_sysfs_edid_timing:2001) igt-core-DEBUG: Exiting with status code 0
SUCCESS (1.178s)


This is my configuration:

======================================
        Graphic stack
======================================

Component: drm
    tag: libdrm-2.4.81-52-g05a830d
    commit: 05a830d382382905d87b55af90aa109fb76e4c16

Component: cairo
    tag: 1.15.6-30-gc29db4f
    commit: c29db4f0de52727406a8b62f4da9a382084b5a79

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-234-g490b386
    commit: 490b386ae36d393cdea514882a2437c6e964c13f

Component: piglit
    tag: piglit-v1
    commit: dab15137044c34023b1a843e72e781b03b17548b

======================================
	     Software
======================================
kernel version              : 4.13.0-drm-tip-ww36-commit-9dd459e+
hostname                    : gfx-desktop
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 5.6
bios release date           : 09/29/2016
hardware acceleration       : only available on X
swap partition              : enabled on (/dev/sda3)

======================================
	Graphic drivers
======================================
libdrm                      : 2.4.83
cairo                       : 1.15.9
intel-gpu-tools (tag)       : intel-gpu-tools-1.19-234-g490b386
intel-gpu-tools (commit)    : 490b386

======================================
	     Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.26
guc fw loaded             : SUCCESS
guc version wanted        : 6.1
guc version found         : 6.1
huc fw loaded             : yes

======================================
	     kernel parameters
======================================
quiet splash drm.debug=0x1e i915.enable_guc_submission=2 i915.enable_guc_loading=2 i915.alpha_support=1

======================================
	     Hardware
======================================
platform                   : Skylake Canyon
motherboard id             : NUC6i7KYB
form factor                : Desktop
cpu family                 : Core i7
cpu family id              : 6
cpu information            : Intel(R) Core(TM) i7-6770HQ CPU @ 2.60GHz
gpu card                   : Intel Corporation Iris Pro Graphics 580 (rev 09) (prog-if 00 [VGA controller])
memory ram                 : 31.31 GB
max memory ram             : 32 GB
cpu thread                 : 8
cpu core                   : 4
cpu model                  : 94
cpu stepping               : 3
socket                     : Other
signature                  : Type 0, Family 6, Model 94, Stepping 3
hard drive                 : 223GiB (240GB)
current cd clock frequency : 337500 kHz
maximum cd clock frequency : 675000 kHz
displays connected         : DP-1 DP-3



Since the test is PASS, will removed the SKL from this list....
Comment 27 Marta Löfstedt 2017-09-07 06:10:18 UTC
(In reply to Hector Velazquez from comment #26)
> The following tests PASS on SKL 
> 
> Tests List:
> 
> igt@kms_sysfs_edid_timing
> 
> ======================================
>         Output
> ======================================
> 
> IGT-Version: 1.19-g490b386 (x86_64) (Linux:
> 4.13.0-drm-tip-ww36-commit-9dd459e+ x86_64)
> (kms_sysfs_edid_timing:2001) DEBUG: card0-DP-2: mean.max 96951.00ns,
> 96.95us, 0.10ms, mean.avg 55862.13ns, 55.86us, 0.06ms
> (kms_sysfs_edid_timing:2001) DEBUG: card0-HDMI-A-2: mean.max 8218906.00ns,
> 8218.91us, 8.22ms, mean.avg 7884490.40ns, 7884.49us, 7.88ms
> (kms_sysfs_edid_timing:2001) DEBUG: card0-DP-3: mean.max 14881491.00ns,
> 14881.49us, 14.88ms, mean.avg 12545055.60ns, 12545.06us, 12.55ms
> (kms_sysfs_edid_timing:2001) WARNING: card0-DP-3: probe time exceed 10ms,
> max=14.88ms, avg=12.55ms
> (kms_sysfs_edid_timing:2001) DEBUG: card0-DP-1: mean.max 50492588.00ns,
> 50492.59us, 50.49ms, mean.avg 49787913.20ns, 49787.91us, 49.79ms
> (kms_sysfs_edid_timing:2001) WARNING: card0-DP-1: probe time exceed 10ms,
> max=50.49ms, avg=49.79ms
> (kms_sysfs_edid_timing:2001) DEBUG: card0-HDMI-A-1: mean.max 7955567.00ns,
> 7955.57us, 7.96ms, mean.avg 7894139.60ns, 7894.14us, 7.89ms
> (kms_sysfs_edid_timing:2001) igt-core-DEBUG: Exiting with status code 0
> SUCCESS (1.178s)
> 
> 
> This is my configuration:
> 
> ======================================
>         Graphic stack
> ======================================
> 
> Component: drm
>     tag: libdrm-2.4.81-52-g05a830d
>     commit: 05a830d382382905d87b55af90aa109fb76e4c16
> 
> Component: cairo
>     tag: 1.15.6-30-gc29db4f
>     commit: c29db4f0de52727406a8b62f4da9a382084b5a79
> 
> Component: intel-gpu-tools
>     tag: intel-gpu-tools-1.19-234-g490b386
>     commit: 490b386ae36d393cdea514882a2437c6e964c13f
> 
> Component: piglit
>     tag: piglit-v1
>     commit: dab15137044c34023b1a843e72e781b03b17548b
> 
> ======================================
> 	     Software
> ======================================
> kernel version              : 4.13.0-drm-tip-ww36-commit-9dd459e+
> hostname                    : gfx-desktop
> architecture                : x86_64
> os version                  : Ubuntu 16.10
> os codename                 : yakkety
> kernel driver               : i915
> bios revision               : 5.6
> bios release date           : 09/29/2016
> hardware acceleration       : only available on X
> swap partition              : enabled on (/dev/sda3)
> 
> ======================================
> 	Graphic drivers
> ======================================
> libdrm                      : 2.4.83
> cairo                       : 1.15.9
> intel-gpu-tools (tag)       : intel-gpu-tools-1.19-234-g490b386
> intel-gpu-tools (commit)    : 490b386
> 
> ======================================
> 	     Firmware
> ======================================
> dmc fw loaded             : yes
> dmc version               : 1.26
> guc fw loaded             : SUCCESS
> guc version wanted        : 6.1
> guc version found         : 6.1
> huc fw loaded             : yes
> 
> ======================================
> 	     kernel parameters
> ======================================
> quiet splash drm.debug=0x1e i915.enable_guc_submission=2
> i915.enable_guc_loading=2 i915.alpha_support=1
> 
> ======================================
> 	     Hardware
> ======================================
> platform                   : Skylake Canyon
> motherboard id             : NUC6i7KYB
> form factor                : Desktop
> cpu family                 : Core i7
> cpu family id              : 6
> cpu information            : Intel(R) Core(TM) i7-6770HQ CPU @ 2.60GHz
> gpu card                   : Intel Corporation Iris Pro Graphics 580 (rev
> 09) (prog-if 00 [VGA controller])
> memory ram                 : 31.31 GB
> max memory ram             : 32 GB
> cpu thread                 : 8
> cpu core                   : 4
> cpu model                  : 94
> cpu stepping               : 3
> socket                     : Other
> signature                  : Type 0, Family 6, Model 94, Stepping 3
> hard drive                 : 223GiB (240GB)
> current cd clock frequency : 337500 kHz
> maximum cd clock frequency : 675000 kHz
> displays connected         : DP-1 DP-3
> 
> 
> 
> Since the test is PASS, will removed the SKL from this list....

How many times did you run this?
Comment 28 Elizabeth 2017-09-13 19:36:03 UTC
(In reply to Marta Löfstedt from comment #27)
> (In reply to Hector Velazquez from comment #26)
> > ...
> How many times did you run this?
Hello Marta, 
Seems like in the last run we did, it kept failing. So answer is one, I saw that the patch is on revision 5 but still no upstream. If this info is useful I ran it ten times and all of them failed.
Comment 29 Marta Löfstedt 2017-09-14 05:49:13 UTC
(In reply to Elizabeth from comment #28)
> (In reply to Marta Löfstedt from comment #27)
> > (In reply to Hector Velazquez from comment #26)
> > > ...
> > How many times did you run this?
> Hello Marta, 
> Seems like in the last run we did, it kept failing. So answer is one, I saw
> that the patch is on revision 5 but still no upstream. If this info is
> useful I ran it ten times and all of them failed.

There is no reason to put in extra effort to reproduce this issue, we have it under control. The reason no fix has been merged, is because that the discussion on how to fix it got stalled, probably due to vacation.
Comment 30 Armando Antonio 2017-09-19 22:24:08 UTC
The following test cases are failing on CFL with latest configuration

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


======================================
             Software
======================================
kernel version              : 4.14.0-rc1-drm-tip-ww38-commit-099f750+
hostname                    : CFL-CNP
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 95.4
bios release date           : 07/24/2017
ksc                         : 1.5
hardware acceleration       : disabled
swap partition              : enabled on (/dev/sda3)

======================================
        Graphic drivers
======================================
grep: /opt/X11R7/var/log/Xorg.0.log: No such file or directory
libdrm                      : 2.4.83
cairo                       : 1.15.9
intel-gpu-tools (tag)       : intel-gpu-tools-1.19-304-g93f72b2
intel-gpu-tools (commit)    : 93f72b2

======================================
             Hardware
======================================
motherboard model          : CoffeeLakeClientPlatform
motherboard id             : CoffeeLakeSUDIMMRVP
form factor                : Desktop
manufacturer               : IntelCorporation
cpu family                 : Other
cpu family id              : 6
cpu information            : Genuine Intel(R) CPU 0000 @ 3.60GHz
gpu card                   : Intel Corporation Device 3e92 (prog-if 00 [VGA controller])
memory ram                 : 15.58 GB
max memory ram             : 32 GB
cpu thread                 : 12
cpu core                   : 6
cpu model                  : 158
cpu stepping               : 10
socket                     : Other
hard drive                 : 111GiB (120GB)
current cd clock frequency : 337500 kHz
maximum cd clock frequency : 675000 kHz
displays connected         : eDP-1 DP-1 DP-2

======================================
             Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.1
guc fw loaded             : SUCCESS
guc version wanted        : 9.14
guc version found         : 9.14
huc fw loaded             : yes

======================================
             kernel parameters
======================================
quiet drm.debug=0x1e pci=pcie_bus_safe intel_iommu=igfx_off auto panic=1 nmi_watchdog=panic i915.alpha_support=1 i915.enable_guc_loading=2 i915.enable_guc_submission=2 resume=/dev/sda3 fastboot

======================================
Output summary
======================================
(kms_sysfs_edid_timing:1977) WARNING: card0-HDMI-A-2: probe time exceed 10ms, max=90.88ms, avg=89.05ms
(kms_sysfs_edid_timing:1977) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:1977) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:1977) CRITICAL: card0-HDMI-A-2: average probe time exceeded 50ms, max=90.88ms, avg=89.05ms
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]
Test kms_sysfs_edid_timing failed.
**** DEBUG ****
Comment 31 Hector Velazquez 2017-09-20 16:46:27 UTC
This test still fail on GLK QA

igt@kms_sysfs_edid_timing

====================================================
Output
====================================================
. . .
**** DEBUG ****
(kms_sysfs_edid_timing:1448) igt-core-INFO: IGT-Version: 1.19-gda197b5 (x86_64) (Linux: 4.14.0-rc1-drm-tip-ww38-commit-ab2e3a0+ x86_64)
(kms_sysfs_edid_timing:1448) DEBUG: card0-HDMI-A-2: mean.max 91173151.00ns, 91173.15us, 91.17ms, mean.avg 88022074.47ns, 88022.07us, 88.02ms
(kms_sysfs_edid_timing:1448) WARNING: card0-HDMI-A-2: probe time exceed 10ms, max=91.17ms, avg=88.02ms
(kms_sysfs_edid_timing:1448) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:1448) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:1448) CRITICAL: card0-HDMI-A-2: average probe time exceeded 50ms, max=91.17ms, avg=88.02ms
(kms_sysfs_edid_timing:1448) igt-core-INFO: Stack trace:
(kms_sysfs_edid_timing:1448) igt-core-INFO:   #0 [__igt_fail_assert+0x101]
(kms_sysfs_edid_timing:1448) igt-core-INFO:   #1 [__real_main40+0x232]
(kms_sysfs_edid_timing:1448) igt-core-INFO:   #2 [main+0x23]
(kms_sysfs_edid_timing:1448) igt-core-INFO:   #3 [__libc_start_main+0xf1]
(kms_sysfs_edid_timing:1448) igt-core-INFO:   #4 [_start+0x29]
(kms_sysfs_edid_timing:1448) igt-core-INFO:   #5 [<unknown>+0x29]
****  END  ****
. . .

This is my configuration:

====================================================
Graphic Stack
====================================================
Component: drm
    tag: libdrm-2.4.81-55-g76418c2
    commit: 76418c244d4c52a8dd20809e3e8b4e70501fc76f

Component: cairo
    tag: 1.15.6-38-g1220e3c
    commit: 1220e3c6b8f94a00ac7afee15f21e6782655d97c

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-312-gda197b5
    commit: da197b5f3cb516aaaea72d0d60b0f5c1c81081dd

Component: piglit
    tag: piglit-v1
    commit: 2753955998d7deb90f681cf4cb1253c4519dfd1d


======================================
             Software
======================================
kernel version              : 4.14.0-rc1-drm-tip-ww38-commit-ab2e3a0+
hostname                    : gfx-desktop
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 62.30
bios release date           : 08/22/2017
ksc                         : 1.48
hardware acceleration       : disabled
swap partition              : enabled on (/dev/sda3)

======================================
        Graphic drivers
======================================
grep: /opt/X11R7/var/log/Xorg.0.log: No such file or directory
libdrm                      : 2.4.83
cairo                       : 1.15.9
intel-gpu-tools (tag)       : intel-gpu-tools-1.19-312-gda197b5
intel-gpu-tools (commit)    : da197b5

======================================
             Hardware
======================================
. . .
======================================
             Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.4
guc fw loaded             : SUCCESS
guc version wanted        : 10.56
guc version found         : 10.56
huc fw loaded             : yes

======================================
             kernel parameters
======================================
quiet splash drm.debug=0xe i915.enable_guc_submission=2 i915.enable_guc_loading=2 i915.alpha_support=1 resume=/dev/sda3
Comment 32 Hector Velazquez 2017-09-28 12:50:53 UTC
This test is still failing on GLK QA

Tests List:

igt@kms_sysfs_edid_timing


====================================================
Output
====================================================
. . .


This is my configuration:

======================================
        Graphic stack
======================================
Component: drm
    tag: libdrm-2.4.81-56-g7c71188
    commit: 7c71188610b4ceba0339c2bc884320bcb749adee

Component: cairo
    tag: 1.15.6-42-gdccbed7
    commit: dccbed7d78d32bd3b912e8810379451dd94e6a1f

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-332-g0a91a5e
    commit: 0a91a5e9624d41d23b79e2540eda111cb56d42d9

Component: piglit
    tag: piglit-v1
    commit: 95e2f51a28b6cf7ff77d84e1234121c98f10ef64
	
======================================
             Software
======================================
kernel version              : 4.14.0-rc2-drm-tip-ww39-commit-d76cbbc+
hostname                    : GLK-2-GLKRVP1DDR405
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 62.30
bios release date           : 08/22/2017
ksc                         : 1.41
hardware acceleration       : disabled
swap partition              : enabled on (/dev/sda3)

======================================
        Graphic drivers
======================================
grep: /opt/X11R7/var/log/Xorg.0.log: No such file or directory
libdrm                      : 2.4.83
cairo                       : 1.15.9
intel-gpu-tools (tag)       : intel-gpu-tools-1.19-332-g0a91a5e
intel-gpu-tools (commit)    : 0a91a5e

======================================
             Hardware
======================================
. . .

======================================
             Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.4
guc fw loaded             : SUCCESS
guc version wanted        : 10.56
guc version found         : 10.56
huc fw loaded             : yes

======================================
             kernel parameters
======================================
quiet drm.debug=0xe pci=pcie_bus_safe i915.alpha_support=1 i915.enable_guc_loading=2 i915.enable_guc_submission=2 intel_iommu=igfx_off auto panic=1 nmi_watchdog=panic resume=/dev/sda3 fastboot
Comment 33 Hector Velazquez 2017-09-29 21:25:30 UTC
This test are failing on CFL-S-1 QA

Tests List:

igt@kms_sysfs_edid_timing


====================================================
Output Sample
====================================================
. . .
**** DEBUG ****
(kms_sysfs_edid_timing:3834) igt-core-INFO: IGT-Version: 1.19-g2885b10 (x86_64) (Linux: 4.14.0-rc2-drm-tip-ww39-commit-85932e1+ x86_64)
(kms_sysfs_edid_timing:3834) DEBUG: card0-DP-2: mean.max 60122.00ns, 60.12us, 0.06ms, mean.avg 37764.07ns, 37.76us, 0.04ms
(kms_sysfs_edid_timing:3834) DEBUG: card0-HDMI-A-2: mean.max 516754648.00ns, 516754.65us, 516.75ms, mean.avg 173775464.93ns, 173775.46us, 173.78ms
(kms_sysfs_edid_timing:3834) WARNING: card0-HDMI-A-2: probe time exceed 10ms, max=516.75ms, avg=173.78ms
(kms_sysfs_edid_timing:3834) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:3834) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:3834) CRITICAL: card0-HDMI-A-2: average probe time exceeded 50ms, max=516.75ms, avg=173.78ms
(kms_sysfs_edid_timing:3834) igt-core-INFO: Stack trace:
(kms_sysfs_edid_timing:3834) igt-core-INFO:   #0 [__igt_fail_assert+0x101]
(kms_sysfs_edid_timing:3834) igt-core-INFO:   #1 [__real_main40+0x232]
(kms_sysfs_edid_timing:3834) igt-core-INFO:   #2 [main+0x23]
(kms_sysfs_edid_timing:3834) igt-core-INFO:   #3 [__libc_start_main+0xf1]
(kms_sysfs_edid_timing:3834) igt-core-INFO:   #4 [_start+0x29]
(kms_sysfs_edid_timing:3834) igt-core-INFO:   #5 [<unknown>+0x29]
****  END  ****
. . .


This is my configuration:

======================================
        Graphic stack
======================================
Component: drm
    tag: libdrm-2.4.81-56-g7c71188
    commit: 7c71188610b4ceba0339c2bc884320bcb749adee

Component: cairo
    tag: 1.15.6-42-gdccbed7
    commit: dccbed7d78d32bd3b912e8810379451dd94e6a1f

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-334-g2885b10
    commit: 2885b10f99b4beeb046e75af8b8488c229f629d3

Component: piglit
    tag: piglit-v1
    commit: e1f66fb2fb8ad781ca755831983b6662c4c440d4
	
======================================
	     Software
======================================
kernel version              : 4.14.0-rc2-drm-tip-ww39-commit-85932e1+
hostname                    : CFL-S-1
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 104.3
bios release date           : 09/14/2017
ksc                         : 1.5
hardware acceleration       : disabled
swap partition              : enabled on (/dev/sda3
/dev/nvme0n1p3)

======================================
	Graphic drivers
======================================
libdrm                      : 2.4.83
cairo                       : 1.15.9
intel-gpu-tools (tag)       : intel-gpu-tools-1.19-334-g2885b10
intel-gpu-tools (commit)    : 2885b10

======================================
	     Hardware
======================================
motherboard model          : CoffeeLakeClientPlatform
motherboard id             : CoffeeLakeSUDIMMRVP
form factor                : Desktop
manufacturer               : IntelCorporation
cpu family                 : Other
cpu family id              : 6
cpu information            : Genuine Intel(R) CPU 0000 @ 3.60GHz
gpu card                   : Intel Corporation Device 3e92 (prog-if 00 [VGA controller])
memory ram                 : 15.58 GB
max memory ram             : 32 GB
cpu thread                 : 12
cpu core                   : 6
cpu model                  : 158
cpu stepping               : 10
socket                     : Other
hard drive                 : 111GiB (120GB)
current cd clock frequency : 337500 kHz
maximum cd clock frequency : 675000 kHz
displays connected         : eDP-1 DP-1

======================================
	     Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.1
guc fw loaded             : SUCCESS
guc version wanted        : 9.14
guc version found         : 9.14

======================================
	     kernel parameters
======================================
quiet drm.debug=0xe pci=pcie_bus_safe intel_iommu=igfx_off auto panic=1 nmi_watchdog=panic i915.alpha_support=1 i915.enable_guc_loading=2 i915.enable_guc_submission=2 resume=/dev/sda3 fastboot
Comment 34 Hector Velazquez 2017-10-03 15:41:57 UTC
This test still failing on GLK QA

Tests List:

igt@kms_sysfs_edid_timing


====================================================
Output 
====================================================
. . .


This is my configuration:

======================================
        Graphic stack
======================================
Component: drm
    tag: libdrm-2.4.81-57-g1dd84e0
    commit: 1dd84e01a972b1759839a7326009be24ab3e6de2

Component: cairo
    tag: 1.15.6-42-gdccbed7
    commit: dccbed7d78d32bd3b912e8810379451dd94e6a1f

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-357-g1e99f8b
    commit: 1e99f8b8d2563d7f5c4e82932bab15abc5eacaef

Component: piglit
    tag: piglit-v1
    commit: 5aa6eea37f44f818632a3dad4c1a7478085bd56d

	
======================================
	     Software
======================================
kernel version              : 4.14.0-rc3-drm-tip-ww40-commit-2f14e31+
hostname                    : GLK-1-GLKRVP1DDR405
architecture                : x86_64
os version                  : Ubuntu 16.10
os codename                 : yakkety
kernel driver               : i915
bios revision               : 62.30
bios release date           : 08/22/2017
ksc                         : 1.41
hardware acceleration       : disabled
swap partition              : enabled on (/dev/sda3)

======================================
	Graphic drivers
======================================
libdrm                      : 2.4.83
cairo                       : 1.15.9
intel-gpu-tools (tag)       : intel-gpu-tools-1.19-357-g1e99f8b
intel-gpu-tools (commit)    : 1e99f8b

======================================
	     Hardware
======================================
. . .

======================================
	     Firmware
======================================
dmc fw loaded             : yes
dmc version               : 1.4
guc fw loaded             : SUCCESS
guc version wanted        : 10.56
guc version found         : 10.56

======================================
	     kernel parameters
======================================
quiet drm.debug=0x1e pci=pcie_bus_safe intel_iommu=igfx_off auto panic=1 nmi_watchdog=panic i915.alpha_support=1 i915.enable_guc_loading=2 i915.enable_guc_submission=2 resume=/dev/sda3 fastboot
Comment 35 Hector Velazquez 2017-11-17 21:53:15 UTC
This tests continue failing on GLK QA

igt@kms_sysfs_edid_timing

IGT-Version: 1.20-g88d6550 (x86_64) (Linux: 4.14.0-drm-tip-ww46-commit-1fc4fe8+ x86_64)
fastfeedback-nov-ww46-thursday-07-03-33-code-179785857

Component: drm
    tag: libdrm-2.4.81-107-g18ffe48
    commit: 18ffe485cdfa41d48b6f2d3080cb990d28c27d57

Component: cairo
    tag: 1.15.6-83-g0c8070f
    commit: 0c8070f5bc74c124e6393b433a61807a8e4bee5d

Component: intel-gpu-tools
    tag: intel-gpu-tools-1.19-483-g88d6550
    commit: 88d6550795fad3974d77e4db2f563c5e2e8872e1

Component: piglit
    tag: piglit-v1
    commit: b6aee208234287380d2e55c17dc2d236931284fa
Comment 36 Marta Löfstedt 2017-12-14 06:48:54 UTC
I change cables on my BDW NUCi5, and now the result changed from the usual assert to only a WARN on probe time exceed 10ms.

About the fix I still believe that the V! Clinton sent up is the proper solution, see comments around #20
Comment 37 Marta Löfstedt 2017-12-14 15:31:27 UTC
Last occurrences on CI
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3515/shard-apl5/igt@kms_sysfs_edid_timing.html

(kms_sysfs_edid_timing:1442) WARNING: card0-DP-1: probe time exceed 10ms, max=12.49ms, avg=9.57ms

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3516/shard-kbl7/igt@kms_sysfs_edid_timing.html

(kms_sysfs_edid_timing:1430) WARNING: card0-DP-1: probe time exceed 10ms, max=42.66ms, avg=37.82ms
(kms_sysfs_edid_timing:1430) WARNING: card0-HDMI-A-1: probe time exceed 10ms, max=115.11ms, avg=113.15ms
(kms_sysfs_edid_timing:1430) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:1430) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:1430) CRITICAL: card0-HDMI-A-1: average probe time exceeded 50ms, max=115.11ms, avg=113.15ms
Test kms_sysfs_edid_timing failed.
Comment 38 Marta Löfstedt 2017-12-14 15:44:45 UTC
I now realize that the THRESHOLD_PER_CONNECTOR also needed to be updated, while previous discussion only touched on increasing the THRESHOLD_TOTAL

I sent up a patch for this:
https://patchwork.freedesktop.org/series/35365/
Comment 39 Marta Löfstedt 2017-12-15 08:25:39 UTC
My patchwork didn't pass on KBL-shards:

https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_670/shard-kbl3/igt@kms_sysfs_edid_timing.html

(kms_sysfs_edid_timing:1520) WARNING: card0-DP-1: probe time exceed 10ms, max=47.69ms, avg=40.72ms
(kms_sysfs_edid_timing:1520) WARNING: card0-HDMI-A-1: probe time exceed 10ms, max=115.46ms, avg=113.03ms
(kms_sysfs_edid_timing:1520) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:1520) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:1520) CRITICAL: card0-HDMI-A-1: average probe time exceeded 50ms, max=115.46ms, avg=113.03ms
Test kms_sysfs_edid_timing failed.

So, I discussed with Tomi and decided to try to come up with a really obscure connection chain:
miniDP -> hdmi, connected to hdmi -> DVI, connected to DVI -> DP, connected to DP port of display:

IGT-Version: 1.20-g103af72 (x86_64) (Linux: 4.15.0-rc3-CI-CI_DRM_3501+ x86_64)
card0-HDMI-A-2: mean.max 3776602,00ns, 3776,60us, 3,78ms, mean.avg 3418194,47ns, 3418,19us, 3,42ms
card0-DP-1: mean.max 78248,00ns, 78,25us, 0,08ms, mean.avg 20597,13ns, 20,60us, 0,02ms
card0-HDMI-A-1: mean.max 875873,00ns, 875,87us, 0,88ms, mean.avg 785897,07ns, 785,90us, 0,79ms
SUCCESS (0,068s)

So, removing DVI -> DP gives:
miniDP -> hdmi, connected to hdmi -> DVI, connected to DVI port of display:

IGT-Version: 1.20-g103af72 (x86_64) (Linux: 4.15.0-rc3-CI-CI_DRM_3501+ x86_64)
card0-HDMI-A-2: mean.max 17301077,00ns, 17301,08us, 17,30ms, mean.avg 16955431,60ns, 16955,43us, 16,96ms
(kms_sysfs_edid_timing:1251) WARNING: card0-HDMI-A-2: probe time exceed 10ms, max=17,30ms, avg=16,96ms
card0-DP-1: mean.max 114544542,00ns, 114544,54us, 114,54ms, mean.avg 114311060,40ns, 114311,06us, 114,31ms
(kms_sysfs_edid_timing:1251) WARNING: card0-DP-1: probe time exceed 10ms, max=114,54ms, avg=114,31ms
(kms_sysfs_edid_timing:1251) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:1251) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:1251) CRITICAL: card0-DP-1: average probe time exceeded 50ms, max=114,54ms, avg=114,31ms

I will send up a V2 and also include hack to get the test run on BAT
Comment 40 Marta Löfstedt 2017-12-18 10:48:47 UTC
Did a new patch and also added hack to fastfeedback.testlist so that I could get results from all BAT machines.
https://patchwork.freedesktop.org/series/35404/

https://intel-gfx-ci.01.org/tree/drm-tip/IGTPW_679/all.html

The majority of the machines hits the WARN.
This is the worst:
WARNING: card0-HDMI-A-2: probe time exceed 20ms, max=140.92ms, avg=137.94ms

So, I would need to set a 15 times longer threshold for all the BAT machines to pass this tests. 

My suggestion is to delete this test. However, I assign this to Jani to find a KMS developer that could vouch for what a reasonable threashold should be for this testcase.
Comment 41 Ricardo Perez 2018-01-29 21:54:58 UTC
In CoffeeLake S UDIMM RVP QA system, the following test is failing:

igt@kms_sysfs_edid_timing

Running:

	
IGT-Version: 1.21-g37bd27f (x86_64) (Linux: 4.15.0-rc9-drm-intel-qa-ww4-commit-59275f1+ x86_64)

----------------------------------------------------------------------------


**** DEBUG ****
(kms_sysfs_edid_timing:12265) igt-core-INFO: IGT-Version: 1.21-g37bd27f (x86_64) (Linux: 4.15.0-rc9-drm-intel-qa-ww4-commit-59275f1+ x86_64)
(kms_sysfs_edid_timing:12265) DEBUG: card0-DP-2: mean.max 12036760.00ns, 12036.76us, 12.04ms, mean.avg 11654630.93ns, 11654.63us, 11.65ms
(kms_sysfs_edid_timing:12265) WARNING: card0-DP-2: probe time exceed 10ms, max=12.04ms, avg=11.65ms
(kms_sysfs_edid_timing:12265) DEBUG: card0-HDMI-A-2: mean.max 505570809.00ns, 505570.81us, 505.57ms, mean.avg 173154597.47ns, 173154.60us, 173.15ms
(kms_sysfs_edid_timing:12265) WARNING: card0-HDMI-A-2: probe time exceed 10ms, max=505.57ms, avg=173.15ms
(kms_sysfs_edid_timing:12265) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:12265) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:12265) CRITICAL: card0-HDMI-A-2: average probe time exceeded 50ms, max=505.57ms, avg=173.15ms
(kms_sysfs_edid_timing:12265) igt-core-INFO: Stack trace:
(kms_sysfs_edid_timing:12265) igt-core-INFO:   #0 [__igt_fail_assert+0x101]
(kms_sysfs_edid_timing:12265) igt-core-INFO:   #1 [__real_main40+0x249]
(kms_sysfs_edid_timing:12265) igt-core-INFO:   #2 [main+0x27]
(kms_sysfs_edid_timing:12265) igt-core-INFO:   #3 [__libc_start_main+0xf1]
(kms_sysfs_edid_timing:12265) igt-core-INFO:   #4 [_start+0x2a]
(kms_sysfs_edid_timing:12265) igt-core-INFO:   #5 [<unknown>+0x2a]
****  END  ****
Comment 42 Ricardo Perez 2018-01-29 21:57:38 UTC
Created attachment 137040 [details]
CFL-Kern-Log

CoffeeLake S UDIMM RVP Kernel Log File
Comment 43 Marta Löfstedt 2018-02-14 07:46:43 UTC
And now also on GLK for the first time:

https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_3762/shard-glkb3/igt@kms_sysfs_edid_timing.html

it however only hit the warn:
(kms_sysfs_edid_timing:4349) WARNING: card0-eDP-1: probe time exceed 10ms, max=24.50ms, avg=4.29ms
Comment 44 Hector Velazquez 2018-02-28 21:38:54 UTC
This tests has a warn on SNB/HSW/BDW/SKL/BXT/GLK/CNL QA 
Tests List:
igt@kms_sysfs_edid_timing

output:
Out	
IGT-Version: 1.21-g1fb30f1 (x86_64) (Linux: 4.16.0-rc2-drm-intel-qa-ww8-commit-562dc33+ x86_64)
SUCCESS (0.329s)
Err	
(kms_sysfs_edid_timing:10236) WARNING: card0-VGA-1: probe time exceed 10ms, max=13.71ms, avg=13.41ms


This tests continue failing on IVB/BYT/BSW/KBL/CFL QA 
Tests List:
igt@kms_sysfs_edid_timing

output sample:
(kms_sysfs_edid_timing:15671) WARNING: card0-VGA-1: probe time exceed 10ms, max=124.19ms, avg=123.79ms
(kms_sysfs_edid_timing:15671) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:15671) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:15671) CRITICAL: card0-VGA-1: average probe time exceeded 50ms, max=124.19ms, avg=123.79ms
Test kms_sysfs_edid_timing failed.
. . .
(kms_sysfs_edid_timing:2651) WARNING: card0-DP-1: probe time exceed 10ms, max=99.55ms, avg=91.58ms
(kms_sysfs_edid_timing:2651) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:2651) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:2651) CRITICAL: card0-DP-1: average probe time exceeded 50ms, max=99.55ms, avg=91.58ms
Test kms_sysfs_edid_timing failed.
. . .
(kms_sysfs_edid_timing:24203) WARNING: card0-DP-2: probe time exceed 10ms, max=33.05ms, avg=32.10ms
(kms_sysfs_edid_timing:24203) WARNING: card0-DP-1: probe time exceed 10ms, max=47.81ms, avg=47.40ms
(kms_sysfs_edid_timing:24203) WARNING: card0-HDMI-A-1: probe time exceed 10ms, max=127.36ms, avg=125.82ms
(kms_sysfs_edid_timing:24203) CRITICAL: Test assertion failure function __real_main40, file kms_sysfs_edid_timing.c:92:
(kms_sysfs_edid_timing:24203) CRITICAL: Failed assertion: mean.mean < (THRESHOLD_TOTAL * 1e6)
(kms_sysfs_edid_timing:24203) CRITICAL: card0-HDMI-A-1: average probe time exceeded 50ms, max=127.36ms, avg=125.82ms
Test kms_sysfs_edid_timing failed.


software:
IGT-Version: 1.21-g1fb30f1 (x86_64) (Linux: 4.16.0-rc2-drm-intel-qa-ww8-commit-562dc33+ x86_64)
Comment 49 Jani Saarinen 2018-03-29 07:11:44 UTC
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.
Comment 51 Marta Löfstedt 2018-04-11 09:03:19 UTC
There was a discussion on the CI meeting that this should be assigned to Petri and moved to performance tests.
Comment 52 Jani Saarinen 2018-04-24 06:50:31 UTC
*** Bug 104688 has been marked as a duplicate of this bug. ***

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.