| Message ID | 20200828170052.1.Id02b2f451b3eed71ddd580f4b8b44b3e33e84970@changeid (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | iio: sx9310: Prefer async probe | expand |
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,
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, >
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, > >
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
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?
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
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
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,
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(+)