[PATCH] iio: sx9310: Prefer async probe

[PATCH] iio: sx9310: Prefer async probe

[Douglas Anderson]

On one board I found that:
  probe of 5-0028 returned 1 after 259547 usecs

There's no reason to block probe of all other devices on our probe.
Turn on async probe.

Signed-off-by: Douglas Anderson <dianders@chromium.org>
---
NOTE: I haven't done any analysis of the driver to see _why_ it's so
slow, only that I have measured it to be slow.  Someone could
certainly take the time to profile / optimize it, but in any case it
still won't hurt to be async.

This is a very safe flag to turn on since:

1. It's not like our probe order was defined by anything anyway.  When
we probe is at the whim of when our i2c controller probes and that can
be any time.

2. If some other driver needs us then they have to handle the fact
that we might not have probed yet anyway.

3. There may be other drivers probing at the same time as us anyway
because _they_ used async probe.

While I won't say that it's impossible to tickle a bug by turning on
async probe, I would assert that in almost all cases the bug was
already there and needed to be fixed anyway.

ALSO NOTE: measurement / testing was done on the downstream Chrome OS
5.4 tree.  I confirmed compiling on mainline.

 drivers/iio/proximity/sx9310.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/drivers/iio/proximity/sx9310.c b/drivers/iio/proximity/sx9310.c
index dc2e11b43431..444cafc53408 100644
--- a/drivers/iio/proximity/sx9310.c
+++ b/drivers/iio/proximity/sx9310.c
@@ -1054,6 +1054,7 @@ static struct i2c_driver sx9310_driver = {
 		.acpi_match_table = ACPI_PTR(sx9310_acpi_match),
 		.of_match_table = of_match_ptr(sx9310_of_match),
 		.pm = &sx9310_pm_ops,
+		.probe_type = PROBE_PREFER_ASYNCHRONOUS,
 	},
 	.probe		= sx9310_probe,
 	.id_table	= sx9310_id,
-- 
2.28.0.402.g5ffc5be6b7-goog

Re: [PATCH] iio: sx9310: Prefer async probe

[Jonathan Cameron]

On Fri, 28 Aug 2020 17:01:18 -0700
Douglas Anderson <dianders@chromium.org> wrote:

> On one board I found that:
>   probe of 5-0028 returned 1 after 259547 usecs
> 
> There's no reason to block probe of all other devices on our probe.
> Turn on async probe.
> 
> Signed-off-by: Douglas Anderson <dianders@chromium.org>
> ---
> NOTE: I haven't done any analysis of the driver to see _why_ it's so
> slow, only that I have measured it to be slow.  Someone could
> certainly take the time to profile / optimize it, but in any case it
> still won't hurt to be async.

Hmm. It is vanishingly rare to use that flag so I'm not particularly
keen on starting to deploy it when we don't know why a particular
driver is taking so long.  I agree it should be safe but I don't
like oddities I don't understand!

There are some sleeps in there but they are all of the order of a few
msecs.

Could it be there is a regulator that is coming up very slowly?

Any other ideas?

Jonathan

> 
> This is a very safe flag to turn on since:
> 
> 1. It's not like our probe order was defined by anything anyway.  When
> we probe is at the whim of when our i2c controller probes and that can
> be any time.
> 
> 2. If some other driver needs us then they have to handle the fact
> that we might not have probed yet anyway.
> 
> 3. There may be other drivers probing at the same time as us anyway
> because _they_ used async probe.
> 
> While I won't say that it's impossible to tickle a bug by turning on
> async probe, I would assert that in almost all cases the bug was
> already there and needed to be fixed anyway.
> 
> ALSO NOTE: measurement / testing was done on the downstream Chrome OS
> 5.4 tree.  I confirmed compiling on mainline.
> 
>  drivers/iio/proximity/sx9310.c | 1 +
>  1 file changed, 1 insertion(+)
> 
> diff --git a/drivers/iio/proximity/sx9310.c b/drivers/iio/proximity/sx9310.c
> index dc2e11b43431..444cafc53408 100644
> --- a/drivers/iio/proximity/sx9310.c
> +++ b/drivers/iio/proximity/sx9310.c
> @@ -1054,6 +1054,7 @@ static struct i2c_driver sx9310_driver = {
>  		.acpi_match_table = ACPI_PTR(sx9310_acpi_match),
>  		.of_match_table = of_match_ptr(sx9310_of_match),
>  		.pm = &sx9310_pm_ops,
> +		.probe_type = PROBE_PREFER_ASYNCHRONOUS,
>  	},
>  	.probe		= sx9310_probe,
>  	.id_table	= sx9310_id,

Re: [PATCH] iio: sx9310: Prefer async probe

[Doug Anderson]

Hi,

On Sat, Aug 29, 2020 at 8:12 AM Jonathan Cameron <jic23@kernel.org> wrote:
>
> On Fri, 28 Aug 2020 17:01:18 -0700
> Douglas Anderson <dianders@chromium.org> wrote:
>
> > On one board I found that:
> >   probe of 5-0028 returned 1 after 259547 usecs
> >
> > There's no reason to block probe of all other devices on our probe.
> > Turn on async probe.
> >
> > Signed-off-by: Douglas Anderson <dianders@chromium.org>
> > ---
> > NOTE: I haven't done any analysis of the driver to see _why_ it's so
> > slow, only that I have measured it to be slow.  Someone could
> > certainly take the time to profile / optimize it, but in any case it
> > still won't hurt to be async.
>
> Hmm. It is vanishingly rare to use that flag

My guess is that people just haven't been spending as much time
optimizing boot performance recently.  I've been trying to do this and
finding that there are quite a few drivers that could benefit from
this flag.

In theory this flag should probably be on by default and it looks like
that was Dmitry's original intention but the state of the world 5
years ago was that it wasn't quite ready for this.  I think, in
particular, drivers that are more core to the system (IOMMUs, clocks,
regulators, etc) may not have been ready, but misc peripherals should
be no problem.


> so I'm not particularly
> keen on starting to deploy it when we don't know why a particular
> driver is taking so long.  I agree it should be safe but I don't
> like oddities I don't understand!
>
> There are some sleeps in there but they are all of the order of a few
> msecs.
>
> Could it be there is a regulator that is coming up very slowly?
>
> Any other ideas?

I can do a little bit of profiling next week, but even if we get this
down from 250 ms to 10 ms I'd still like to see async probe turned on.
There's no reason for it to be off and every little bit counts.


> Jonathan
>
> >
> > This is a very safe flag to turn on since:
> >
> > 1. It's not like our probe order was defined by anything anyway.  When
> > we probe is at the whim of when our i2c controller probes and that can
> > be any time.
> >
> > 2. If some other driver needs us then they have to handle the fact
> > that we might not have probed yet anyway.
> >
> > 3. There may be other drivers probing at the same time as us anyway
> > because _they_ used async probe.
> >
> > While I won't say that it's impossible to tickle a bug by turning on
> > async probe, I would assert that in almost all cases the bug was
> > already there and needed to be fixed anyway.
> >
> > ALSO NOTE: measurement / testing was done on the downstream Chrome OS
> > 5.4 tree.  I confirmed compiling on mainline.
> >
> >  drivers/iio/proximity/sx9310.c | 1 +
> >  1 file changed, 1 insertion(+)
> >
> > diff --git a/drivers/iio/proximity/sx9310.c b/drivers/iio/proximity/sx9310.c
> > index dc2e11b43431..444cafc53408 100644
> > --- a/drivers/iio/proximity/sx9310.c
> > +++ b/drivers/iio/proximity/sx9310.c
> > @@ -1054,6 +1054,7 @@ static struct i2c_driver sx9310_driver = {
> >               .acpi_match_table = ACPI_PTR(sx9310_acpi_match),
> >               .of_match_table = of_match_ptr(sx9310_of_match),
> >               .pm = &sx9310_pm_ops,
> > +             .probe_type = PROBE_PREFER_ASYNCHRONOUS,
> >       },
> >       .probe          = sx9310_probe,
> >       .id_table       = sx9310_id,
>

Re: [PATCH] iio: sx9310: Prefer async probe

[Jonathan Cameron]

On Sat, 29 Aug 2020 09:56:41 -0700
Doug Anderson <dianders@chromium.org> wrote:

> Hi,
> 
> On Sat, Aug 29, 2020 at 8:12 AM Jonathan Cameron <jic23@kernel.org> wrote:
> >
> > On Fri, 28 Aug 2020 17:01:18 -0700
> > Douglas Anderson <dianders@chromium.org> wrote:
> >  
> > > On one board I found that:
> > >   probe of 5-0028 returned 1 after 259547 usecs
> > >
> > > There's no reason to block probe of all other devices on our probe.
> > > Turn on async probe.
> > >
> > > Signed-off-by: Douglas Anderson <dianders@chromium.org>
> > > ---
> > > NOTE: I haven't done any analysis of the driver to see _why_ it's so
> > > slow, only that I have measured it to be slow.  Someone could
> > > certainly take the time to profile / optimize it, but in any case it
> > > still won't hurt to be async.  
> >
> > Hmm. It is vanishingly rare to use that flag  
> 
> My guess is that people just haven't been spending as much time
> optimizing boot performance recently.  I've been trying to do this and
> finding that there are quite a few drivers that could benefit from
> this flag.
> 
> In theory this flag should probably be on by default and it looks like
> that was Dmitry's original intention but the state of the world 5
> years ago was that it wasn't quite ready for this.  I think, in
> particular, drivers that are more core to the system (IOMMUs, clocks,
> regulators, etc) may not have been ready, but misc peripherals should
> be no problem.

That fits with my understanding.  Would be great to have it on
by default though I guess it could make for some really hard to debug
race conditions.


> 
> 
> > so I'm not particularly
> > keen on starting to deploy it when we don't know why a particular
> > driver is taking so long.  I agree it should be safe but I don't
> > like oddities I don't understand!
> >
> > There are some sleeps in there but they are all of the order of a few
> > msecs.
> >
> > Could it be there is a regulator that is coming up very slowly?
> >
> > Any other ideas?  
> 
> I can do a little bit of profiling next week, but even if we get this
> down from 250 ms to 10 ms I'd still like to see async probe turned on.
> There's no reason for it to be off and every little bit counts.
Agreed. However, I'd like a comment next to the place we turn it on
saying what delays we are trying to mitigate by enabling it in this
driver.

Jonathan

> 
> 
> > Jonathan
> >  
> > >
> > > This is a very safe flag to turn on since:
> > >
> > > 1. It's not like our probe order was defined by anything anyway.  When
> > > we probe is at the whim of when our i2c controller probes and that can
> > > be any time.
> > >
> > > 2. If some other driver needs us then they have to handle the fact
> > > that we might not have probed yet anyway.
> > >
> > > 3. There may be other drivers probing at the same time as us anyway
> > > because _they_ used async probe.
> > >
> > > While I won't say that it's impossible to tickle a bug by turning on
> > > async probe, I would assert that in almost all cases the bug was
> > > already there and needed to be fixed anyway.
> > >
> > > ALSO NOTE: measurement / testing was done on the downstream Chrome OS
> > > 5.4 tree.  I confirmed compiling on mainline.
> > >
> > >  drivers/iio/proximity/sx9310.c | 1 +
> > >  1 file changed, 1 insertion(+)
> > >
> > > diff --git a/drivers/iio/proximity/sx9310.c b/drivers/iio/proximity/sx9310.c
> > > index dc2e11b43431..444cafc53408 100644
> > > --- a/drivers/iio/proximity/sx9310.c
> > > +++ b/drivers/iio/proximity/sx9310.c
> > > @@ -1054,6 +1054,7 @@ static struct i2c_driver sx9310_driver = {
> > >               .acpi_match_table = ACPI_PTR(sx9310_acpi_match),
> > >               .of_match_table = of_match_ptr(sx9310_of_match),
> > >               .pm = &sx9310_pm_ops,
> > > +             .probe_type = PROBE_PREFER_ASYNCHRONOUS,
> > >       },
> > >       .probe          = sx9310_probe,
> > >       .id_table       = sx9310_id,  
> >  

Re: [PATCH] iio: sx9310: Prefer async probe

[Doug Anderson]

Hi,

On Sat, Aug 29, 2020 at 10:18 AM Jonathan Cameron <jic23@kernel.org> wrote:
>
> On Sat, 29 Aug 2020 09:56:41 -0700
> Doug Anderson <dianders@chromium.org> wrote:
>
> > Hi,
> >
> > On Sat, Aug 29, 2020 at 8:12 AM Jonathan Cameron <jic23@kernel.org> wrote:
> > >
> > > On Fri, 28 Aug 2020 17:01:18 -0700
> > > Douglas Anderson <dianders@chromium.org> wrote:
> > >
> > > > On one board I found that:
> > > >   probe of 5-0028 returned 1 after 259547 usecs
> > > >
> > > > There's no reason to block probe of all other devices on our probe.
> > > > Turn on async probe.
> > > >
> > > > Signed-off-by: Douglas Anderson <dianders@chromium.org>
> > > > ---
> > > > NOTE: I haven't done any analysis of the driver to see _why_ it's so
> > > > slow, only that I have measured it to be slow.  Someone could
> > > > certainly take the time to profile / optimize it, but in any case it
> > > > still won't hurt to be async.
> > >
> > > Hmm. It is vanishingly rare to use that flag
> >
> > My guess is that people just haven't been spending as much time
> > optimizing boot performance recently.  I've been trying to do this and
> > finding that there are quite a few drivers that could benefit from
> > this flag.
> >
> > In theory this flag should probably be on by default and it looks like
> > that was Dmitry's original intention but the state of the world 5
> > years ago was that it wasn't quite ready for this.  I think, in
> > particular, drivers that are more core to the system (IOMMUs, clocks,
> > regulators, etc) may not have been ready, but misc peripherals should
> > be no problem.
>
> That fits with my understanding.  Would be great to have it on
> by default though I guess it could make for some really hard to debug
> race conditions.

One other note that I should have mentioned: anything that's buildable
as a module is essentially already testing this path.  Modules are
probed asynchronously and in parallel.  Possibly the solution for my
boot speed woes in this case is to just build this as a module since I
don't see any immediate need why it has to be builtin (so with that
realization I may not actually need this patch).  That being said, it
still seems nice to enable async probe in case someone has a reason to
build this in.


> > > so I'm not particularly
> > > keen on starting to deploy it when we don't know why a particular
> > > driver is taking so long.  I agree it should be safe but I don't
> > > like oddities I don't understand!
> > >
> > > There are some sleeps in there but they are all of the order of a few
> > > msecs.
> > >
> > > Could it be there is a regulator that is coming up very slowly?
> > >
> > > Any other ideas?
> >
> > I can do a little bit of profiling next week, but even if we get this
> > down from 250 ms to 10 ms I'd still like to see async probe turned on.
> > There's no reason for it to be off and every little bit counts.
> Agreed. However, I'd like a comment next to the place we turn it on
> saying what delays we are trying to mitigate by enabling it in this
> driver.

OK, I used function graph to get a trace.  Some of the time is simply
i2c transfers, which we do A LOT of during initialization (and i2c
transfers aren't known for being instant).  However, that's not the
big problem.  Check out the regmap_read_poll_timeout() in
sx9310_init_compensation().  20 ms per sleep with a 2 second timeout.
This seems to eat over around 220 ms of the time on my system.

So how do you want to do this?  Do you want me to re-post the patch
and mention the regmap_read_poll_timeout() in the commit message?  Do
you want to just add that to the commit message yourself?

Thanks!

-Doug

Re: [PATCH] iio: sx9310: Prefer async probe

[Stephen Boyd]

Quoting Doug Anderson (2020-08-31 11:59:37)
> On Sat, Aug 29, 2020 at 10:18 AM Jonathan Cameron <jic23@kernel.org> wrote:
> > Agreed. However, I'd like a comment next to the place we turn it on
> > saying what delays we are trying to mitigate by enabling it in this
> > driver.
> 
> OK, I used function graph to get a trace.  Some of the time is simply
> i2c transfers, which we do A LOT of during initialization (and i2c
> transfers aren't known for being instant).  However, that's not the
> big problem.  Check out the regmap_read_poll_timeout() in
> sx9310_init_compensation().  20 ms per sleep with a 2 second timeout.
> This seems to eat over around 220 ms of the time on my system.
> 
> So how do you want to do this?  Do you want me to re-post the patch
> and mention the regmap_read_poll_timeout() in the commit message?  Do
> you want to just add that to the commit message yourself?
> 

I think the suggestion is to put a comment next to the
PROBE_PREFER_ASYNCHRONOUS flag indicating that
sx9310_init_compensation() can take a while. Should the compensation be
delayed even further though to some time when userspace opens the device
node?

Re: [PATCH] iio: sx9310: Prefer async probe

[Jonathan Cameron]

On Tue, 1 Sep 2020 00:03:55 -0700
Stephen Boyd <swboyd@chromium.org> wrote:

> Quoting Doug Anderson (2020-08-31 11:59:37)
> > On Sat, Aug 29, 2020 at 10:18 AM Jonathan Cameron <jic23@kernel.org> wrote:  
> > > Agreed. However, I'd like a comment next to the place we turn it on
> > > saying what delays we are trying to mitigate by enabling it in this
> > > driver.  
> > 
> > OK, I used function graph to get a trace.  Some of the time is simply
> > i2c transfers, which we do A LOT of during initialization (and i2c
> > transfers aren't known for being instant).  However, that's not the
> > big problem.  Check out the regmap_read_poll_timeout() in
> > sx9310_init_compensation().  20 ms per sleep with a 2 second timeout.
> > This seems to eat over around 220 ms of the time on my system.
> > 
> > So how do you want to do this?  Do you want me to re-post the patch
> > and mention the regmap_read_poll_timeout() in the commit message?  Do
> > you want to just add that to the commit message yourself?
> >   
> 
> I think the suggestion is to put a comment next to the
> PROBE_PREFER_ASYNCHRONOUS flag indicating that
> sx9310_init_compensation() can take a while. 

Yup. That's what I meant. Sorry for lack of clarity.
A comment in the code stops others copying it without making sure they
understand whether it is relevant in their case.  No one is going
to look in commit messages.

> Should the compensation be
> delayed even further though to some time when userspace opens the device
> node?

It's tricky because we may hit it on an individual sysfs read.
We could spin off a thread to do it I suppose, though that would be
more or less the same as allowing async probe.

Jonathan

Re: [PATCH] iio: sx9310: Prefer async probe

[Doug Anderson]

Hi,

On Tue, Sep 1, 2020 at 6:47 AM Jonathan Cameron
<Jonathan.Cameron@huawei.com> wrote:
>
> On Tue, 1 Sep 2020 00:03:55 -0700
> Stephen Boyd <swboyd@chromium.org> wrote:
>
> > Quoting Doug Anderson (2020-08-31 11:59:37)
> > > On Sat, Aug 29, 2020 at 10:18 AM Jonathan Cameron <jic23@kernel.org> wrote:
> > > > Agreed. However, I'd like a comment next to the place we turn it on
> > > > saying what delays we are trying to mitigate by enabling it in this
> > > > driver.
> > >
> > > OK, I used function graph to get a trace.  Some of the time is simply
> > > i2c transfers, which we do A LOT of during initialization (and i2c
> > > transfers aren't known for being instant).  However, that's not the
> > > big problem.  Check out the regmap_read_poll_timeout() in
> > > sx9310_init_compensation().  20 ms per sleep with a 2 second timeout.
> > > This seems to eat over around 220 ms of the time on my system.
> > >
> > > So how do you want to do this?  Do you want me to re-post the patch
> > > and mention the regmap_read_poll_timeout() in the commit message?  Do
> > > you want to just add that to the commit message yourself?
> > >
> >
> > I think the suggestion is to put a comment next to the
> > PROBE_PREFER_ASYNCHRONOUS flag indicating that
> > sx9310_init_compensation() can take a while.
>
> Yup. That's what I meant. Sorry for lack of clarity.
> A comment in the code stops others copying it without making sure they
> understand whether it is relevant in their case.  No one is going
> to look in commit messages.

OK, posted.  I expect it'll show up soon at:

https://lore.kernel.org/r/20200901081920.v2.1.Id02b2f451b3eed71ddd580f4b8b44b3e33e84970@changeid


> > Should the compensation be
> > delayed even further though to some time when userspace opens the device
> > node?
>
> It's tricky because we may hit it on an individual sysfs read.
> We could spin off a thread to do it I suppose, though that would be
> more or less the same as allowing async probe.

Also: even if we delayed the compensation further we'd still end up
with a somewhat slow probe just due to the metric buttload of i2c
transfers we do at probe time.


-Doug