diff mbox series

[2/8] i2c: i2c-qcom-geni: Signify successful driver probe

Message ID 20190604104455.8877-2-lee.jones@linaro.org (mailing list archive)
State Superseded
Headers show
Series [1/8] i2c: i2c-qcom-geni: Provide support for ACPI | expand

Commit Message

Lee Jones June 4, 2019, 10:44 a.m. UTC
The Qualcomm Geni I2C driver currently probes silently which can be
confusing when debugging potential issues.  Add a low level (INFO)
print when each I2C controller is successfully initially set-up.

Signed-off-by: Lee Jones <lee.jones@linaro.org>
---
 drivers/i2c/busses/i2c-qcom-geni.c | 2 ++
 1 file changed, 2 insertions(+)

Comments

Bjorn Andersson June 5, 2019, 6:20 a.m. UTC | #1
On Tue 04 Jun 03:44 PDT 2019, Lee Jones wrote:

> The Qualcomm Geni I2C driver currently probes silently which can be
> confusing when debugging potential issues.  Add a low level (INFO)
> print when each I2C controller is successfully initially set-up.
> 
> Signed-off-by: Lee Jones <lee.jones@linaro.org>
> ---
>  drivers/i2c/busses/i2c-qcom-geni.c | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/drivers/i2c/busses/i2c-qcom-geni.c b/drivers/i2c/busses/i2c-qcom-geni.c
> index 0fa93b448e8d..e27466d77767 100644
> --- a/drivers/i2c/busses/i2c-qcom-geni.c
> +++ b/drivers/i2c/busses/i2c-qcom-geni.c
> @@ -598,6 +598,8 @@ static int geni_i2c_probe(struct platform_device *pdev)
>  		return ret;
>  	}
>  
> +	dev_info(&pdev->dev, "Geni-I2C adaptor successfully added\n");
> +

I would prefer that we do not add such prints, as it would be to accept
the downstream behaviour of spamming the log to the point where no one
will ever look through it.

Regards,
Bjorn

>  	return 0;
>  }
>  
> -- 
> 2.17.1
>
Lee Jones June 5, 2019, 7:16 a.m. UTC | #2
On Tue, 04 Jun 2019, Bjorn Andersson wrote:

> On Tue 04 Jun 03:44 PDT 2019, Lee Jones wrote:
> 
> > The Qualcomm Geni I2C driver currently probes silently which can be
> > confusing when debugging potential issues.  Add a low level (INFO)
> > print when each I2C controller is successfully initially set-up.
> > 
> > Signed-off-by: Lee Jones <lee.jones@linaro.org>
> > ---
> >  drivers/i2c/busses/i2c-qcom-geni.c | 2 ++
> >  1 file changed, 2 insertions(+)
> > 
> > diff --git a/drivers/i2c/busses/i2c-qcom-geni.c b/drivers/i2c/busses/i2c-qcom-geni.c
> > index 0fa93b448e8d..e27466d77767 100644
> > --- a/drivers/i2c/busses/i2c-qcom-geni.c
> > +++ b/drivers/i2c/busses/i2c-qcom-geni.c
> > @@ -598,6 +598,8 @@ static int geni_i2c_probe(struct platform_device *pdev)
> >  		return ret;
> >  	}
> >  
> > +	dev_info(&pdev->dev, "Geni-I2C adaptor successfully added\n");
> > +
> 
> I would prefer that we do not add such prints, as it would be to accept
> the downstream behaviour of spamming the log to the point where no one
> will ever look through it.

We should be able to find a middle ground.  Spamming the log with all
sorts of device specific information/debug is obviously not
constructive, but a single liner to advertise that an important
device/controller has been successfully initialised is more helpful
than it is hinderous.

This print was added due to the silent initialisation costing me
several hours of debugging ACPI device/driver code (albeit learning a
lot about ACPI as I go) just to find out that it was already doing the
right thing - just very quietly.
Ard Biesheuvel June 5, 2019, 7:22 a.m. UTC | #3
On Wed, 5 Jun 2019 at 09:16, Lee Jones <lee.jones@linaro.org> wrote:
>
> On Tue, 04 Jun 2019, Bjorn Andersson wrote:
>
> > On Tue 04 Jun 03:44 PDT 2019, Lee Jones wrote:
> >
> > > The Qualcomm Geni I2C driver currently probes silently which can be
> > > confusing when debugging potential issues.  Add a low level (INFO)
> > > print when each I2C controller is successfully initially set-up.
> > >
> > > Signed-off-by: Lee Jones <lee.jones@linaro.org>
> > > ---
> > >  drivers/i2c/busses/i2c-qcom-geni.c | 2 ++
> > >  1 file changed, 2 insertions(+)
> > >
> > > diff --git a/drivers/i2c/busses/i2c-qcom-geni.c b/drivers/i2c/busses/i2c-qcom-geni.c
> > > index 0fa93b448e8d..e27466d77767 100644
> > > --- a/drivers/i2c/busses/i2c-qcom-geni.c
> > > +++ b/drivers/i2c/busses/i2c-qcom-geni.c
> > > @@ -598,6 +598,8 @@ static int geni_i2c_probe(struct platform_device *pdev)
> > >             return ret;
> > >     }
> > >
> > > +   dev_info(&pdev->dev, "Geni-I2C adaptor successfully added\n");
> > > +
> >
> > I would prefer that we do not add such prints, as it would be to accept
> > the downstream behaviour of spamming the log to the point where no one
> > will ever look through it.
>
> We should be able to find a middle ground.  Spamming the log with all
> sorts of device specific information/debug is obviously not
> constructive, but a single liner to advertise that an important
> device/controller has been successfully initialised is more helpful
> than it is hinderous.
>
> This print was added due to the silent initialisation costing me
> several hours of debugging ACPI device/driver code (albeit learning a
> lot about ACPI as I go) just to find out that it was already doing the
> right thing - just very quietly.
>

I agree.

There are numerous EHCI drivers IIRC which, if compiled in,
unconditionally print some blurb, whether you have the hardware or
not, which is pretty annoying.

In this case, however, having a single line per successfully probed
device (containing the dev_name and perhaps the MMIO base address or
some other identifying feature) is pretty useful, and shouldn't be
regarded as log spamming imo. dev_info() honours the 'quiet' kernel
command line parameter, and so you will only see the message if you
actually look at the log.
Johan Hovold June 5, 2019, 7:56 a.m. UTC | #4
On Wed, Jun 05, 2019 at 08:16:25AM +0100, Lee Jones wrote:
> On Tue, 04 Jun 2019, Bjorn Andersson wrote:
> 
> > On Tue 04 Jun 03:44 PDT 2019, Lee Jones wrote:
> > 
> > > The Qualcomm Geni I2C driver currently probes silently which can be
> > > confusing when debugging potential issues.  Add a low level (INFO)
> > > print when each I2C controller is successfully initially set-up.
> > > 
> > > Signed-off-by: Lee Jones <lee.jones@linaro.org>
> > > ---
> > >  drivers/i2c/busses/i2c-qcom-geni.c | 2 ++
> > >  1 file changed, 2 insertions(+)
> > > 
> > > diff --git a/drivers/i2c/busses/i2c-qcom-geni.c b/drivers/i2c/busses/i2c-qcom-geni.c
> > > index 0fa93b448e8d..e27466d77767 100644
> > > --- a/drivers/i2c/busses/i2c-qcom-geni.c
> > > +++ b/drivers/i2c/busses/i2c-qcom-geni.c
> > > @@ -598,6 +598,8 @@ static int geni_i2c_probe(struct platform_device *pdev)
> > >  		return ret;
> > >  	}
> > >  
> > > +	dev_info(&pdev->dev, "Geni-I2C adaptor successfully added\n");
> > > +
> > 
> > I would prefer that we do not add such prints, as it would be to accept
> > the downstream behaviour of spamming the log to the point where no one
> > will ever look through it.
> 
> We should be able to find a middle ground.  Spamming the log with all
> sorts of device specific information/debug is obviously not
> constructive, but a single liner to advertise that an important
> device/controller has been successfully initialised is more helpful
> than it is hinderous.
> 
> This print was added due to the silent initialisation costing me
> several hours of debugging ACPI device/driver code (albeit learning a
> lot about ACPI as I go) just to find out that it was already doing the
> right thing - just very quietly.

No, we don't add noise like this to the logs just because it may be
useful while debugging. Even one-liners add up.

There are plenty of options for debugging already ranging from adding a
temporary dev_info() to the probe function in question to using dynamic
debugging to have driver core log every successful probe.

And in this case you say the driver was in fact already bound; that can
easily be verified through sysfs too in case things aren't behaving the
way you expect.

Johan
Lee Jones June 5, 2019, 8:20 a.m. UTC | #5
On Wed, 05 Jun 2019, Johan Hovold wrote:

> On Wed, Jun 05, 2019 at 08:16:25AM +0100, Lee Jones wrote:
> > On Tue, 04 Jun 2019, Bjorn Andersson wrote:
> > 
> > > On Tue 04 Jun 03:44 PDT 2019, Lee Jones wrote:
> > > 
> > > > The Qualcomm Geni I2C driver currently probes silently which can be
> > > > confusing when debugging potential issues.  Add a low level (INFO)
> > > > print when each I2C controller is successfully initially set-up.
> > > > 
> > > > Signed-off-by: Lee Jones <lee.jones@linaro.org>
> > > > ---
> > > >  drivers/i2c/busses/i2c-qcom-geni.c | 2 ++
> > > >  1 file changed, 2 insertions(+)
> > > > 
> > > > diff --git a/drivers/i2c/busses/i2c-qcom-geni.c b/drivers/i2c/busses/i2c-qcom-geni.c
> > > > index 0fa93b448e8d..e27466d77767 100644
> > > > --- a/drivers/i2c/busses/i2c-qcom-geni.c
> > > > +++ b/drivers/i2c/busses/i2c-qcom-geni.c
> > > > @@ -598,6 +598,8 @@ static int geni_i2c_probe(struct platform_device *pdev)
> > > >  		return ret;
> > > >  	}
> > > >  
> > > > +	dev_info(&pdev->dev, "Geni-I2C adaptor successfully added\n");
> > > > +
> > > 
> > > I would prefer that we do not add such prints, as it would be to accept
> > > the downstream behaviour of spamming the log to the point where no one
> > > will ever look through it.
> > 
> > We should be able to find a middle ground.  Spamming the log with all
> > sorts of device specific information/debug is obviously not
> > constructive, but a single liner to advertise that an important
> > device/controller has been successfully initialised is more helpful
> > than it is hinderous.
> > 
> > This print was added due to the silent initialisation costing me
> > several hours of debugging ACPI device/driver code (albeit learning a
> > lot about ACPI as I go) just to find out that it was already doing the
> > right thing - just very quietly.
> 
> No, we don't add noise like this to the logs just because it may be
> useful while debugging. Even one-liners add up.

One line per device is should not cause an issue.

Problems occur when developers try to print all kinds of device
specifics to the boot log.  A simple, single line for such an
important device/controller has more benefits than drawbacks.

> There are plenty of options for debugging already ranging from adding a
> temporary dev_info() to the probe function in question to using dynamic
> debugging to have driver core log every successful probe.

This is what I ended up doing.  It was time consuming to parse though
a log of that size when you have no paging or keyboard.

> And in this case you say the driver was in fact already bound; that can
> easily be verified through sysfs too in case things aren't behaving the
> way you expect.

Not in a non-booting system with no keyboard you can't. ;)
Lee Jones June 5, 2019, 8:23 a.m. UTC | #6
On Wed, 05 Jun 2019, Ard Biesheuvel wrote:

> On Wed, 5 Jun 2019 at 09:16, Lee Jones <lee.jones@linaro.org> wrote:
> >
> > On Tue, 04 Jun 2019, Bjorn Andersson wrote:
> >
> > > On Tue 04 Jun 03:44 PDT 2019, Lee Jones wrote:
> > >
> > > > The Qualcomm Geni I2C driver currently probes silently which can be
> > > > confusing when debugging potential issues.  Add a low level (INFO)
> > > > print when each I2C controller is successfully initially set-up.
> > > >
> > > > Signed-off-by: Lee Jones <lee.jones@linaro.org>
> > > > ---
> > > >  drivers/i2c/busses/i2c-qcom-geni.c | 2 ++
> > > >  1 file changed, 2 insertions(+)
> > > >
> > > > diff --git a/drivers/i2c/busses/i2c-qcom-geni.c b/drivers/i2c/busses/i2c-qcom-geni.c
> > > > index 0fa93b448e8d..e27466d77767 100644
> > > > --- a/drivers/i2c/busses/i2c-qcom-geni.c
> > > > +++ b/drivers/i2c/busses/i2c-qcom-geni.c
> > > > @@ -598,6 +598,8 @@ static int geni_i2c_probe(struct platform_device *pdev)
> > > >             return ret;
> > > >     }
> > > >
> > > > +   dev_info(&pdev->dev, "Geni-I2C adaptor successfully added\n");
> > > > +
> > >
> > > I would prefer that we do not add such prints, as it would be to accept
> > > the downstream behaviour of spamming the log to the point where no one
> > > will ever look through it.
> >
> > We should be able to find a middle ground.  Spamming the log with all
> > sorts of device specific information/debug is obviously not
> > constructive, but a single liner to advertise that an important
> > device/controller has been successfully initialised is more helpful
> > than it is hinderous.
> >
> > This print was added due to the silent initialisation costing me
> > several hours of debugging ACPI device/driver code (albeit learning a
> > lot about ACPI as I go) just to find out that it was already doing the
> > right thing - just very quietly.
> >
> 
> I agree.
> 
> There are numerous EHCI drivers IIRC which, if compiled in,
> unconditionally print some blurb, whether you have the hardware or
> not, which is pretty annoying.
> 
> In this case, however, having a single line per successfully probed
> device (containing the dev_name and perhaps the MMIO base address or
> some other identifying feature) is pretty useful, and shouldn't be
> regarded as log spamming imo. dev_info() honours the 'quiet' kernel
> command line parameter, and so you will only see the message if you
> actually look at the log.

+999

This is exactly as I see it.

If people want a quiet log/fast boot-up times, they can request it.
Otherwise, it's far more useful to trade a second or two for
important information such as which devices are present/enabled on a
platform.
Johan Hovold June 5, 2019, 8:33 a.m. UTC | #7
On Wed, Jun 05, 2019 at 09:20:47AM +0100, Lee Jones wrote:
> On Wed, 05 Jun 2019, Johan Hovold wrote:

> > No, we don't add noise like this to the logs just because it may be
> > useful while debugging. Even one-liners add up.
> 
> One line per device is should not cause an issue.
> 
> Problems occur when developers try to print all kinds of device
> specifics to the boot log.  A simple, single line for such an
> important device/controller has more benefits than drawbacks.

What about the thousands of probe functions which do not currently spam
the logs? If you want to see all successful probes reliably, you tell
driver core to print it.

> > There are plenty of options for debugging already ranging from adding a
> > temporary dev_info() to the probe function in question to using dynamic
> > debugging to have driver core log every successful probe.
> 
> This is what I ended up doing.  It was time consuming to parse though
> a log of that size when you have no paging or keyboard.

With the right command-line option to enable dynamic debugging you get
one line per successful probe, just like you wanted. Or are you now
saying that one-line per device is too much after all? ;)

> > And in this case you say the driver was in fact already bound; that can
> > easily be verified through sysfs too in case things aren't behaving the
> > way you expect.
> 
> Not in a non-booting system with no keyboard you can't. ;)

Fair enough, but the above would still work.

Johan
Lee Jones June 5, 2019, 8:49 a.m. UTC | #8
On Wed, 05 Jun 2019, Johan Hovold wrote:

> On Wed, Jun 05, 2019 at 09:20:47AM +0100, Lee Jones wrote:
> > On Wed, 05 Jun 2019, Johan Hovold wrote:
> 
> > > No, we don't add noise like this to the logs just because it may be
> > > useful while debugging. Even one-liners add up.
> > 
> > One line per device is should not cause an issue.
> > 
> > Problems occur when developers try to print all kinds of device
> > specifics to the boot log.  A simple, single line for such an
> > important device/controller has more benefits than drawbacks.
> 
> What about the thousands of probe functions which do not currently spam
> the logs? If you want to see all successful probes reliably, you tell
> driver core to print it.
> 
> > > There are plenty of options for debugging already ranging from adding a
> > > temporary dev_info() to the probe function in question to using dynamic
> > > debugging to have driver core log every successful probe.
> > 
> > This is what I ended up doing.  It was time consuming to parse though
> > a log of that size when you have no paging or keyboard.
> 
> With the right command-line option to enable dynamic debugging you get
> one line per successful probe, just like you wanted. Or are you now
> saying that one-line per device is too much after all? ;)

Which command line option are you pertaining to?

> > > And in this case you say the driver was in fact already bound; that can
> > > easily be verified through sysfs too in case things aren't behaving the
> > > way you expect.
> > 
> > Not in a non-booting system with no keyboard you can't. ;)
> 
> Fair enough, but the above would still work.
Johan Hovold June 5, 2019, 8:55 a.m. UTC | #9
On Wed, Jun 05, 2019 at 09:49:21AM +0100, Lee Jones wrote:
> On Wed, 05 Jun 2019, Johan Hovold wrote:
> 
> > On Wed, Jun 05, 2019 at 09:20:47AM +0100, Lee Jones wrote:
> > > On Wed, 05 Jun 2019, Johan Hovold wrote:
 
> > > > There are plenty of options for debugging already ranging from adding a
> > > > temporary dev_info() to the probe function in question to using dynamic
> > > > debugging to have driver core log every successful probe.
> > > 
> > > This is what I ended up doing.  It was time consuming to parse though
> > > a log of that size when you have no paging or keyboard.
> > 
> > With the right command-line option to enable dynamic debugging you get
> > one line per successful probe, just like you wanted. Or are you now
> > saying that one-line per device is too much after all? ;)
> 
> Which command line option are you pertaining to?

To enable dynamic debugging in driver core you could use something like

	CONFIG_CMDLINE="dyndbg=\"func really_probe =p\""

That gives you two printouts per successful probe, for example:

	bus: 'usb-serial': really_probe: probing driver edgeport_ti_1 with device ttyUSB0
	bus: 'usb-serial': really_probe: bound device ttyUSB0 to driver edgeport_ti_1

Or you can of course just change the corresponding pr_debug to pr_info
while debugging.

Johan
Wolfram Sang June 5, 2019, 2:18 p.m. UTC | #10
> To enable dynamic debugging in driver core you could use something like
> 
> 	CONFIG_CMDLINE="dyndbg=\"func really_probe =p\""
> 
> That gives you two printouts per successful probe, for example:
> 
> 	bus: 'usb-serial': really_probe: probing driver edgeport_ti_1 with device ttyUSB0
> 	bus: 'usb-serial': really_probe: bound device ttyUSB0 to driver edgeport_ti_1

I agree that this scales much better than adding strings to every
driver. Also, the driver core will report failed probes other than
-ENODEV, or?

Regarding this patch, however, I don't care much. I'll let the driver
maintainers decide.
Lee Jones June 5, 2019, 6:49 p.m. UTC | #11
On Wed, 05 Jun 2019, Wolfram Sang wrote:

> 
> > To enable dynamic debugging in driver core you could use something like
> > 
> > 	CONFIG_CMDLINE="dyndbg=\"func really_probe =p\""
> > 
> > That gives you two printouts per successful probe, for example:
> > 
> > 	bus: 'usb-serial': really_probe: probing driver edgeport_ti_1 with device ttyUSB0
> > 	bus: 'usb-serial': really_probe: bound device ttyUSB0 to driver edgeport_ti_1
> 
> I agree that this scales much better than adding strings to every
> driver. Also, the driver core will report failed probes other than
> -ENODEV, or?
> 
> Regarding this patch, however, I don't care much. I'll let the driver
> maintainers decide.

I've downgraded this to dev_dbg() in v2.
Johan Hovold June 12, 2019, 2:54 p.m. UTC | #12
On Wed, Jun 05, 2019 at 04:18:12PM +0200, Wolfram Sang wrote:
> 
> > To enable dynamic debugging in driver core you could use something like
> > 
> > 	CONFIG_CMDLINE="dyndbg=\"func really_probe =p\""
> > 
> > That gives you two printouts per successful probe, for example:
> > 
> > 	bus: 'usb-serial': really_probe: probing driver edgeport_ti_1 with device ttyUSB0
> > 	bus: 'usb-serial': really_probe: bound device ttyUSB0 to driver edgeport_ti_1
> 
> I agree that this scales much better than adding strings to every
> driver. Also, the driver core will report failed probes other than
> -ENODEV, or?

Right, errors other than -EPROBE_DEFER, -ENODEV and -ENXIO are always
logged, and the previous three would also be logged with debugging
enabled.

Johan
diff mbox series

Patch

diff --git a/drivers/i2c/busses/i2c-qcom-geni.c b/drivers/i2c/busses/i2c-qcom-geni.c
index 0fa93b448e8d..e27466d77767 100644
--- a/drivers/i2c/busses/i2c-qcom-geni.c
+++ b/drivers/i2c/busses/i2c-qcom-geni.c
@@ -598,6 +598,8 @@  static int geni_i2c_probe(struct platform_device *pdev)
 		return ret;
 	}
 
+	dev_info(&pdev->dev, "Geni-I2C adaptor successfully added\n");
+
 	return 0;
 }