[igt-dev] [PATCH i-g-t] tests/chamelium: Add test for hotplug workaround

[Souza, Jose]

On Fri, 2019-03-15 at 04:46 +0200, Imre Deak wrote:
> On Fri, Mar 15, 2019 at 03:27:08AM +0200, Imre Deak wrote:
> > On Fri, Mar 15, 2019 at 02:00:41AM +0200, Souza, Jose wrote:
> > [...]
> > > > > > > +
> > > > > > > +	/*
> > > > > > > +	 * Give some time to kernel try to process hotplug but
> > > > > > > it
> > > > > > > should fail
> > > > > > > +	 */
> > > > > > > +	igt_hotplug_detected(mon, FAST_HOTPLUG_SEC_TIMEOUT);
> > > > > > > +	status = connector_status_get(data, port);
> > > > > > > +	igt_assert(status == DRM_MODE_DISCONNECTED);
> > > > > > 
> > > > > > Hm, how does a second disconnect event get signaled here?
> > > > > > After
> > > > > > the
> > > > > > previous hotplug event above where the state was
> > > > > > disconnected
> > > > > > already
> > > > > > there
> > > > > > shouldn't have been any change to the state, hence there
> > > > > > shouldn't be
> > > > > > any event sent by the driver.
> > > > > 
> > > > > It is not signaled, that I why there is not igt_assert() on
> > > > > this
> > > > > igt_hotplug_detected() but call it will poll/sleep for the
> > > > > time we
> > > > > want.
> > > > 
> > > > But then I don't see how it will work. The sequence is:
> > > > 
> > > > <connector is in disconnected state, corresponding event
> > > > delivered>
> > > > 1. disable DDC
> > > > 2. generate a plug event
> > > > 3. wait for the plug event delivery with 1 sec timeout
> > > > 4. re-enable DDC
> > > > 5. wait for the plug event delivery (that should be triggered
> > > > by the
> > > > new
> > > >    retry logic in the driver)
> > > > 
> > > > Since after 2. DDC is disabled the driver hotplug handler will
> > > > conclude
> > > > that the connector is still disconnected and hence doesn't
> > > > generate
> > > > any
> > > > hotplug event. B/c of this 3. will time out after 1 sec.
> > > > 
> > > > So in 4. we'll re-enable DDC only after 1 sec after the plug
> > > > event
> > > > (interrupt) generated in 2. Since the retry in the driver
> > > > happens
> > > > after
> > > > 1 sec from the plug interrupt as well the retry processing
> > > > could
> > > > easily
> > > > race with the DDC re-enabling in 4. and thus the detection
> > > > could
> > > > fail.
> > > 
> > > You are not taking in the account the time that kernel will take
> > > to
> > > process that, I measured just the time spend in the hotplug()
> > > hook on
> > > my ICL.
> > > 
> > > [185950.212037] [drm:intel_encoder_hotplug [i915]]
> > > [CONNECTOR:196:DP-1] 
> > > status updated from connected to disconnected
> > > [185950.212109] [drm:i915_hotplug_work_func [i915]]     hotplug()
> > > took=673123725 nsec(673 msec) ret=1
> > > 
> > > [185950.956536] [drm:intel_encoder_hotplug [i915]]
> > > [CONNECTOR:196:DP-1] 
> > > status updated from disconnected to connected
> > > [185950.957068] [drm:i915_hotplug_work_func [i915]]     hotplug()
> > > took=60222955 nsec(60 msec) ret=1
> > > 
> > > 
> > > [185953.480877] [drm:drm_dp_dpcd_access] Too many retries, giving
> > > up.
> > > First error: -110
> > > [185953.480969] [drm:intel_encoder_hotplug [i915]]
> > > [CONNECTOR:196:DP-1] 
> > > status updated from connected to disconnected
> > > [185953.481038] [drm:i915_hotplug_work_func [i915]]     hotplug()
> > > took=672309486 nsec(672 msec) ret=1
> > > 	
> > > More than half of a second retrying until it gives up and
> > > change/keep
> > > the status to disconnected.
> > 
> > 670msec for detection to fail sounds strange, where is that coming
> > from?
> > AUX reads should time out much earlier even with all the retries.
> 
> Ah, could be the 4msec (max) AUX HW timeout on ICL. That with retries
> adds up to 5*32*4ms = 640msec about what you have measured.
> 
> But up to SKL the AUX HW timeout is only 1.6msec giving a 256msec
> delay,
> so the hotplug retry could happen as soon as ~1.3sec after the plug
> event.
> 
> So I guess a 1 sec delay/poll at step 3. is ok along with some
> explanation about the duration like the above calculation. I think it
> could still be possible for this 1 sec delay/poll to last longer than
> 1.3sec (due to scheduling) in which case the detection would fail on
> some platforms. So I'd still add the time measurement between step 2.
> and 4. as described below and rerun the test if it was > 1.2sec and
> detection failed.

Yeah sound good measure time between 2 and 4 and retry, I will also the
comments that you requested.

Thanks for the reviews :D

> 
> > > So in my rough estimation:
> > > t 0s = IGT disables DDC and do the hotplug(1 and 2 from your
> > > sequence)
> > > t 0.7s = kernel gives up and keep connector as disconnected
> > > t 1s = IGT read connector as disconnected and enables DCC(3 and 4
> > > from
> > > your sequence)
> > > t 1.7 = kernel try to probe again
> > > t 1.8 = kernel probe and mark connector as connected
> > > t 2s = IGT read connector as connected(5 from your sequence)
> > > 
> > > Maybe to avoid test failures the second timeout should be bigger
> > > 
> > > > Since I don't see a good way to ensure that we re-enable DDC
> > > > after
> > > > the
> > > > first detection cycle ran (but not too late missing the retry
> > > > cycle)
> > > > I
> > > > would rather suggest a simple wait at 3., let's say 500msec.
> > > > With
> > > > that
> > > > things should always work. We may not always exercise the
> > > > driver's
> > > > retry
> > > > path if there was a long scheduling delay, but that's unlikely.
> > > > 
> > > > However a scheduling delay after 2. and before 4. could cause a
> > > > detection failure. To avoid that I'd also check the elapsed
> > > > time
> > > > starting from right before 2. until right after 4. and run the
> > > > sequence
> > > > again if the elapsed time was too close to 1sec (and hence
> > > > detection
> > > > possibly failed because of the race described above).
> > > > 
> > > > > > > +
> > > > > > > +	/*
> > > > > > > +	 * Enable the DDC line and the kernel workaround should
> > > > > > > reprobe
> > > > > > > and
> > > > > > > +	 * report as connected
> > > > > > > +	 */
> > > > > > > +	chamelium_port_set_ddc_state(data->chamelium, port,
> > > > > > > true);
> > > > > > > +	igt_assert(chamelium_port_get_ddc_state(data-
> > > > > > > > chamelium,
> > > > > > > port));
> > > > > > > +	igt_assert(igt_hotplug_detected(mon,
> > > > > > > FAST_HOTPLUG_SEC_TIMEOUT));
> > > > > > > +	status = connector_status_get(data, port);
> > > > > > > +	igt_assert(status == DRM_MODE_CONNECTED);
> > > > > > > +}
> > > > > > > +
> > > > > > >  static void
> > > > > > >  test_edid_read(data_t *data, struct chamelium_port
> > > > > > > *port,
> > > > > > >  	       int edid_id, const unsigned char *edid)
> > > > > > > @@ -1308,6 +1375,9 @@ igt_main
> > > > > > >  
> > > > > > >  		connector_subtest("dp-frame-dump", DisplayPort)
> > > > > > >  			test_display_frame_dump(&data, port);
> > > > > > > +
> > > > > > > +		connector_subtest("dp-late-aux-wa",
> > > > > > > DisplayPort)
> > > > > > > +			test_late_aux_wa(&data, port);
> > > > 
> > > > This also needs the retry logic to be added for DP ports on old
> > > > platforms (intel_dp_hotplug() in the driver).
> > > > 
> > > > > > >  	}
> > > > > > >  
> > > > > > >  	igt_subtest_group {
> > > > > > > -- 
> > > > > > > 2.21.0
> > > > > > > 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 488 bytes
Desc: This is a digitally signed message part
URL: <https://lists.freedesktop.org/archives/igt-dev/attachments/20190315/ddad78fe/attachment-0001.sig>