[PATCH i-g-t] tests/kms_sysfs_edid_timing: Skip the first detect
Almahallawy, Khaled
khaled.almahallawy at intel.com
Wed May 22 23:40:46 UTC 2024
On Wed, 2024-05-22 at 18:16 +0200, Kamil Konieczny wrote:
> Hi Khaled,
> On 2024-05-17 at 17:33:45 -0700, Khaled Almahallawy wrote:
> > It is observed in some chrome devices that the first detect take a
> > long time due to PPS. In another device it was found the eDP panel
> > misbehaving and keep sending multiple long HPD during PPS which
> > trigger HPD storm warning. This first detect will always exceeds
> > the
> > THRESHOLD_PER_CONNECTOR and will cause the test to fail.
> >
> > Avoid that by skipping the measurement for the first detect.
> > Also adding more debug logs in the test and kernel to be able to
> > correlate the results.
> >
> > Fixes: VLK-52052, VLK-56861
>
> Please do not write this in description.
OK
>
> Also look into CI report and reply to it, in replay cut it after
> 'Known' report begins.
Ok, will send V2 and reply if errors still reported
>
>
> > Cc: Swati Sharma <swati2.sharma at intel.com>
> > Cc: Mark Yacoub <markyacoub at chromium.org>
> > Cc: Shawn Lee <shawn.c.lee at intel.com>
> > Cc: Kamil Konieczny <kamil.konieczny at linux.intel.com>
> > Signed-off-by: Khaled Almahallawy <khaled.almahallawy at intel.com>
> > ---
> > tests/kms_sysfs_edid_timing.c | 16 +++++++++++++---
> > 1 file changed, 13 insertions(+), 3 deletions(-)
> >
> > diff --git a/tests/kms_sysfs_edid_timing.c
> > b/tests/kms_sysfs_edid_timing.c
> > index dbc66c876..b7832dd83 100644
> > --- a/tests/kms_sysfs_edid_timing.c
> > +++ b/tests/kms_sysfs_edid_timing.c
> > @@ -50,7 +50,7 @@
> > #define THRESHOLD_PER_CONNECTOR 150
> > #define THRESHOLD_PER_CONNECTOR_MEAN 140
> > #define THRESHOLD_ALL_CONNECTORS_MEAN 100
> > -#define CHECK_TIMES 15
> > +#define CHECK_TIMES 16
> >
> > IGT_TEST_DESCRIPTION("This test checks the time it takes to
> > reprobe each "
> > "connector and fails if either the time it
> > takes for "
> > @@ -89,15 +89,25 @@ igt_simple_main
> > for (i = 0; i < CHECK_TIMES; i++) {
> > struct timespec ts = {};
> > int fd;
> > + uint64_t current;
> >
> > if ((fd = open(path, O_WRONLY)) < 0)
> > continue;
> >
> > + igt_kmsg(KMSG_DEBUG "%s: start detect\n",
> > path);
> ------------^^^^^^^^
> Why not igt_debug?
I already added igt_debug below to print current,max,min for each loop.
The point here is to add logs in kernel dmesg to understand what is
going on for each loop during the detect from kernel perspective. For
example we found in one Chrome SKU, the first detect do the following
only for the first detect. This is an unusual behavior for eDP panel:
[ 5837.552989] [IGT] /sys/class/drm/card0-eDP-1/status: start detect
...
[ 5837.554446] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked]
[ENCODER:235:DDI A/PHY A] PPS 0 turning VDD on
[ 5837.554469] i915 0000:00:02.0: [drm:wait_panel_power_cycle]
[ENCODER:235:DDI A/PHY A] PPS 0 wait for panel power cycle
[ 5837.554518] i915 0000:00:02.0: [drm:wait_panel_status]
[ENCODER:235:DDI A/PHY A] PPS 0 mask: 0xb800000f value: 0x00000000
PP_STATUS: 0x00000000 PP_CONTROL: 0x00000060
[ 5837.554542] i915 0000:00:02.0: [drm:wait_panel_status] Wait complete
[ 5837.554596] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked]
[ENCODER:235:DDI A/PHY A] PPS 0 PP_STATUS: 0x00000000 PP_CONTROL:
0x00000068
[ 5837.554619] i915 0000:00:02.0: [drm:intel_pps_vdd_on_unlocked]
[ENCODER:235:DDI A/PHY A] PPS 0 panel power wasn't enabled
[ 5837.561367] i915 0000:00:02.0: [drm:intel_hpd_irq_handler] Received
HPD interrupt on PIN 4 - cnt: 10
[ 5837.561497] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse] ignoring
long hpd on eDP [ENCODER:235:DDI A/PHY A]
[ 5837.564412] i915 0000:00:02.0: [drm:intel_hpd_irq_handler] Received
HPD interrupt on PIN 4 - cnt: 20
[ 5837.564518] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse] ignoring
long hpd on eDP [ENCODER:235:DDI A/PHY A]
[ 5837.625025] i915 0000:00:02.0: [drm:intel_hpd_irq_handler] Received
HPD interrupt on PIN 4 - cnt: 30
[ 5837.625183] i915 0000:00:02.0: [drm:intel_dp_hpd_pulse] ignoring
long hpd on eDP [ENCODER:235:DDI A/PHY A]
...
[ 5837.760507] [IGT] /sys/class/drm/card0-eDP-1/status: end detect
From igt-debug added below we will be able to correlate/confirm the
kernel (5837.760507 - 5837.552989 = 0.207518 = 207ms):
(kms_sysfs_edid_timing:29688) INFO: path=card0-eDP-1 i=0
current=207.168422dms mean.max= 207.168422ms mean.min= 207.168422ms
After we ignore long_hpd in subsequent iterations, subsequent probs
only take 2-3 ms. Here is the second iteration ~3 msec
[ 5837.760900] [IGT] /sys/class/drm/card0-eDP-1/status: start detect
...
[ 5837.764277] [IGT] /sys/class/drm/card0-eDP-1/status: end detect
(kms_sysfs_edid_timing:29688) INFO: path=card0-eDP-1 i=1
current=3.105989dms mean.max= 207.168422ms mean.min= 3.105989ms
So having kernel logs will help to debug/explain why the test fails or
take long time
>
> > igt_nsec_elapsed(&ts);
> > igt_ignore_warn(write(fd, "detect\n", 7));
> > - igt_mean_add(&mean, igt_nsec_elapsed(&ts));
> > -
> > + current = igt_nsec_elapsed(&ts);
> > + igt_kmsg(KMSG_DEBUG "%s: end detect\n",
> > path);
> ------------^^^^^^^^
> Same here, why not igt_debug?
>
> > close(fd);
> > +
> > + /* Skip first detect */
> > + if(i == 0)
> --------------^
> Add space after 'if', so it will be:
> if (i == 0)
>
> You could use checkpatch.pl from Linux kernel to catch similar
> problems.
Note, thank you for suggestion. Will fix in V2
Thanks
Khaled
>
> Regards,
> Kamil
>
> > + continue;
> > +
> > + igt_mean_add(&mean, current);
> > + igt_debug("%s: i=%d current=%02fdms
> > mean.max=%02fms mean.min=%02fms\n",
> > + de->d_name, i, current/1e6,
> > mean.max/1e6, mean.min/1e6);
> > }
> >
> > igt_debug("%s: mean.max %.2fns, %.2fus, %.2fms, "
> > --
> > 2.34.1
> >
More information about the igt-dev
mailing list