[v2,03/15] drivers: thermal: tsens: Add __func__ identifier to debug statements

Commit Message

Amit Kucheria Aug. 27, 2019, 12:13 p.m. UTC

Printing the function name when enabling debugging makes logs easier to
read.

Signed-off-by: Amit Kucheria <[e-mail]>
Reviewed-by: Stephen Boyd <[e-mail]>
Reviewed-by: Daniel Lezcano <[e-mail]>
---
 drivers/thermal/qcom/tsens-common.c | 8 ++++----
 drivers/thermal/qcom/tsens.c        | 6 +++---
 2 files changed, 7 insertions(+), 7 deletions(-)

Comments

Daniel Thompson Aug. 29, 2019, 2:04 p.m. UTC | #1

On Tue, Aug 27, 2019 at 05:43:59PM +0530, Amit Kucheria wrote:
> Printing the function name when enabling debugging makes logs easier to
> read.
> 
> Signed-off-by: Amit Kucheria <[e-mail]>
> Reviewed-by: Stephen Boyd <[e-mail]>
> Reviewed-by: Daniel Lezcano <[e-mail]>

This should need to be manually added at each call site; it is already
built into the logging system (the f flag for dynamic debug)?


Daniel.

> ---
>  drivers/thermal/qcom/tsens-common.c | 8 ++++----
>  drivers/thermal/qcom/tsens.c        | 6 +++---
>  2 files changed, 7 insertions(+), 7 deletions(-)
> 
> diff --git a/drivers/thermal/qcom/tsens-common.c b/drivers/thermal/qcom/tsens-common.c
> index c037bdf92c663..7437bfe196e50 100644
> --- a/drivers/thermal/qcom/tsens-common.c
> +++ b/drivers/thermal/qcom/tsens-common.c
> @@ -42,8 +42,8 @@ void compute_intercept_slope(struct tsens_priv *priv, u32 *p1,
>  
>  	for (i = 0; i < priv->num_sensors; i++) {
>  		dev_dbg(priv->dev,
> -			"sensor%d - data_point1:%#x data_point2:%#x\n",
> -			i, p1[i], p2[i]);
> +			"%s: sensor%d - data_point1:%#x data_point2:%#x\n",
> +			__func__, i, p1[i], p2[i]);
>  
>  		priv->sensor[i].slope = SLOPE_DEFAULT;
>  		if (mode == TWO_PT_CALIB) {
> @@ -60,7 +60,7 @@ void compute_intercept_slope(struct tsens_priv *priv, u32 *p1,
>  		priv->sensor[i].offset = (p1[i] * SLOPE_FACTOR) -
>  				(CAL_DEGC_PT1 *
>  				priv->sensor[i].slope);
> -		dev_dbg(priv->dev, "offset:%d\n", priv->sensor[i].offset);
> +		dev_dbg(priv->dev, "%s: offset:%d\n", __func__, priv->sensor[i].offset);
>  	}
>  }
>  
> @@ -209,7 +209,7 @@ int __init init_common(struct tsens_priv *priv)
>  	if (ret)
>  		goto err_put_device;
>  	if (!enabled) {
> -		dev_err(dev, "tsens device is not enabled\n");
> +		dev_err(dev, "%s: device not enabled\n", __func__);
>  		ret = -ENODEV;
>  		goto err_put_device;
>  	}
> diff --git a/drivers/thermal/qcom/tsens.c b/drivers/thermal/qcom/tsens.c
> index 542a7f8c3d962..06c6bbd69a1a7 100644
> --- a/drivers/thermal/qcom/tsens.c
> +++ b/drivers/thermal/qcom/tsens.c
> @@ -127,7 +127,7 @@ static int tsens_probe(struct platform_device *pdev)
>  		of_property_read_u32(np, "#qcom,sensors", &num_sensors);
>  
>  	if (num_sensors <= 0) {
> -		dev_err(dev, "invalid number of sensors\n");
> +		dev_err(dev, "%s: invalid number of sensors\n", __func__);
>  		return -EINVAL;
>  	}
>  
> @@ -156,7 +156,7 @@ static int tsens_probe(struct platform_device *pdev)
>  
>  	ret = priv->ops->init(priv);
>  	if (ret < 0) {
> -		dev_err(dev, "tsens init failed\n");
> +		dev_err(dev, "%s: init failed\n", __func__);
>  		return ret;
>  	}
>  
> @@ -164,7 +164,7 @@ static int tsens_probe(struct platform_device *pdev)
>  		ret = priv->ops->calibrate(priv);
>  		if (ret < 0) {
>  			if (ret != -EPROBE_DEFER)
> -				dev_err(dev, "tsens calibration failed\n");
> +				dev_err(dev, "%s: calibration failed\n", __func__);
>  			return ret;
>  		}
>  	}
> -- 
> 2.17.1
>

Amit Kucheria Aug. 29, 2019, 2:28 p.m. UTC | #2

On Thu, Aug 29, 2019 at 7:35 PM Daniel Thompson
<[e-mail]> wrote:
>
> On Tue, Aug 27, 2019 at 05:43:59PM +0530, Amit Kucheria wrote:
> > Printing the function name when enabling debugging makes logs easier to
> > read.
> >
> > Signed-off-by: Amit Kucheria <[e-mail]>
> > Reviewed-by: Stephen Boyd <[e-mail]>
> > Reviewed-by: Daniel Lezcano <[e-mail]>
>
> This should need to be manually added at each call site; it is already
> built into the logging system (the f flag for dynamic debug)?

I assume you meant "shouldn't".

I haven't yet integrated dynamic debug into my daily workflow.

Last time I looked at it, it was a bit bothersome to use because I
needed to lookup exact line numbers to trigger useful information. And
those line numbers constantly keep changing as I work on the driver,
so it was a bit painful to script. Not to mention the syntax to frob
the correct files in debugfs to enable this functionality.

As opposed to this, adding the following to the makefile is so easy. :-)

CFLAGS_tsens-common.o          := -DDEBUG

Perhaps I am using it all wrong? How would I go about using dynamic
debug instead of this patch?

Regards,
Amit

Daniel Thompson Aug. 29, 2019, 3:19 p.m. UTC | #3

On Thu, Aug 29, 2019 at 07:58:45PM +0530, Amit Kucheria wrote:
> On Thu, Aug 29, 2019 at 7:35 PM Daniel Thompson
> <[e-mail]> wrote:
> >
> > On Tue, Aug 27, 2019 at 05:43:59PM +0530, Amit Kucheria wrote:
> > > Printing the function name when enabling debugging makes logs easier to
> > > read.
> > >
> > > Signed-off-by: Amit Kucheria <[e-mail]>
> > > Reviewed-by: Stephen Boyd <[e-mail]>
> > > Reviewed-by: Daniel Lezcano <[e-mail]>
> >
> > This should need to be manually added at each call site; it is already
> > built into the logging system (the f flag for dynamic debug)?
> 
> I assume you meant "shouldn't".

Quite so. Sorry about that.


> I haven't yet integrated dynamic debug into my daily workflow.
> 
> Last time I looked at it, it was a bit bothersome to use because I
> needed to lookup exact line numbers to trigger useful information. And
> those line numbers constantly keep changing as I work on the driver,
> so it was a bit painful to script. Not to mention the syntax to frob
> the correct files in debugfs to enable this functionality.
> 
> As opposed to this, adding the following to the makefile is so easy. :-)
> 
> CFLAGS_tsens-common.o          := -DDEBUG
> 
> Perhaps I am using it all wrong? How would I go about using dynamic
> debug instead of this patch?

Throwing dyndbg="file <fname>.c +pf" onto the kernel command line is a
good start (+p enables debug level prints, +f causes messages to include
the function name).

When the C files map to module names (whether the modules are actually
built-in or not) then <module>.dyndbg=+pf is a bit cleaner and allows
you to debug the whole of a driver without how it is decomposed into
files.

There are (many) other controls to play with[1] but the above should be
sufficient to simulate -DDEBUG .


Daniel.

[1]
https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html

Amit Kucheria Aug. 29, 2019, 4:14 p.m. UTC | #4

On Thu, Aug 29, 2019 at 8:49 PM Daniel Thompson
<[e-mail]> wrote:
>
> On Thu, Aug 29, 2019 at 07:58:45PM +0530, Amit Kucheria wrote:
> > On Thu, Aug 29, 2019 at 7:35 PM Daniel Thompson
> > <[e-mail]> wrote:
> > >
> > > On Tue, Aug 27, 2019 at 05:43:59PM +0530, Amit Kucheria wrote:
> > > > Printing the function name when enabling debugging makes logs easier to
> > > > read.
> > > >
> > > > Signed-off-by: Amit Kucheria <[e-mail]>
> > > > Reviewed-by: Stephen Boyd <[e-mail]>
> > > > Reviewed-by: Daniel Lezcano <[e-mail]>
> > >
> > > This should need to be manually added at each call site; it is already
> > > built into the logging system (the f flag for dynamic debug)?
> >
> > I assume you meant "shouldn't".
>
> Quite so. Sorry about that.
>
> > I haven't yet integrated dynamic debug into my daily workflow.
> >
> > Last time I looked at it, it was a bit bothersome to use because I
> > needed to lookup exact line numbers to trigger useful information. And
> > those line numbers constantly keep changing as I work on the driver,
> > so it was a bit painful to script. Not to mention the syntax to frob
> > the correct files in debugfs to enable this functionality.
> >
> > As opposed to this, adding the following to the makefile is so easy. :-)
> >
> > CFLAGS_tsens-common.o          := -DDEBUG
> >
> > Perhaps I am using it all wrong? How would I go about using dynamic
> > debug instead of this patch?
>
> Throwing dyndbg="file <fname>.c +pf" onto the kernel command line is a
> good start (+p enables debug level prints, +f causes messages to include
> the function name).

That's useful to know.

$ git grep __func__ | wc -l
30914

Want to send some patches? :-)

> When the C files map to module names (whether the modules are actually
> built-in or not) then <module>.dyndbg=+pf is a bit cleaner and allows
> you to debug the whole of a driver without how it is decomposed into
> files.

And if changing the kernel cmdline options isn't possible or is inconvenient?

> There are (many) other controls to play with[1] but the above should be
> sufficient to simulate -DDEBUG .

The "hard" bit is explicitly poking the line number in a file to
activate a paricular pr_dbg statement. Even if I scripted it, those
lines numbers keep changing in an actively developed driver.

Somehow, I've always felt dyndbg was more useful to debug a production
system where recompiling the kernel wasn't an option e.g. reporting an
issue back to a distro-kernel vendor.

> Daniel.
>
> [1]
> https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html

Daniel Thompson Aug. 29, 2019, 4:34 p.m. UTC | #5

On Thu, Aug 29, 2019 at 09:44:04PM +0530, Amit Kucheria wrote:
> On Thu, Aug 29, 2019 at 8:49 PM Daniel Thompson
> <[e-mail]> wrote:
> >
> > On Thu, Aug 29, 2019 at 07:58:45PM +0530, Amit Kucheria wrote:
> > > On Thu, Aug 29, 2019 at 7:35 PM Daniel Thompson
> > > <[e-mail]> wrote:
> > > >
> > > > On Tue, Aug 27, 2019 at 05:43:59PM +0530, Amit Kucheria wrote:
> > > > > Printing the function name when enabling debugging makes logs easier to
> > > > > read.
> > > > >
> > > > > Signed-off-by: Amit Kucheria <[e-mail]>
> > > > > Reviewed-by: Stephen Boyd <[e-mail]>
> > > > > Reviewed-by: Daniel Lezcano <[e-mail]>
> > > >
> > > > This should need to be manually added at each call site; it is already
> > > > built into the logging system (the f flag for dynamic debug)?
> > >
> > > I assume you meant "shouldn't".
> >
> > Quite so. Sorry about that.
> >
> > > I haven't yet integrated dynamic debug into my daily workflow.
> > >
> > > Last time I looked at it, it was a bit bothersome to use because I
> > > needed to lookup exact line numbers to trigger useful information. And
> > > those line numbers constantly keep changing as I work on the driver,
> > > so it was a bit painful to script. Not to mention the syntax to frob
> > > the correct files in debugfs to enable this functionality.
> > >
> > > As opposed to this, adding the following to the makefile is so easy. :-)
> > >
> > > CFLAGS_tsens-common.o          := -DDEBUG
> > >
> > > Perhaps I am using it all wrong? How would I go about using dynamic
> > > debug instead of this patch?
> >
> > Throwing dyndbg="file <fname>.c +pf" onto the kernel command line is a
> > good start (+p enables debug level prints, +f causes messages to include
> > the function name).
> 
> That's useful to know.
> 
> $ git grep __func__ | wc -l
> 30914
> 
> Want to send some patches? :-)

I know. Sad isn't it?

To be fair plenty of patches already circulate tidying up this sort of
thing (along with the removal of inane messages such as informing us
that a function run).


> > When the C files map to module names (whether the modules are actually
> > built-in or not) then <module>.dyndbg=+pf is a bit cleaner and allows
> > you to debug the whole of a driver without how it is decomposed into
> > files.
> 
> And if changing the kernel cmdline options isn't possible or is inconvenient?

Architectures where this problem offer CONFIG_CMDLINE_FORCE meaning if
you are already building a custom kernel you can override whatever
cmdline the bootloader gives you.


> > There are (many) other controls to play with[1] but the above should be
> > sufficient to simulate -DDEBUG .
> 
> The "hard" bit is explicitly poking the line number in a file to
> activate a paricular pr_dbg statement. Even if I scripted it, those
> lines numbers keep changing in an actively developed driver.

Line numbers? Nothing I suggested contained a line number.


Daniel.

> 
> Somehow, I've always felt dyndbg was more useful to debug a production
> system where recompiling the kernel wasn't an option e.g. reporting an
> issue back to a distro-kernel vendor.
> 
> > Daniel.
> >
> > [1]
> > https://www.kernel.org/doc/html/latest/admin-guide/dynamic-debug-howto.html

Patch

diff --git a/drivers/thermal/qcom/tsens-common.c b/drivers/thermal/qcom/tsens-common.c
index c037bdf92c663..7437bfe196e50 100644
--- a/drivers/thermal/qcom/tsens-common.c
+++ b/drivers/thermal/qcom/tsens-common.c
@@ -42,8 +42,8 @@  void compute_intercept_slope(struct tsens_priv *priv, u32 *p1,
 
 	for (i = 0; i < priv->num_sensors; i++) {
 		dev_dbg(priv->dev,
-			"sensor%d - data_point1:%#x data_point2:%#x\n",
-			i, p1[i], p2[i]);
+			"%s: sensor%d - data_point1:%#x data_point2:%#x\n",
+			__func__, i, p1[i], p2[i]);
 
 		priv->sensor[i].slope = SLOPE_DEFAULT;
 		if (mode == TWO_PT_CALIB) {
@@ -60,7 +60,7 @@  void compute_intercept_slope(struct tsens_priv *priv, u32 *p1,
 		priv->sensor[i].offset = (p1[i] * SLOPE_FACTOR) -
 				(CAL_DEGC_PT1 *
 				priv->sensor[i].slope);
-		dev_dbg(priv->dev, "offset:%d\n", priv->sensor[i].offset);
+		dev_dbg(priv->dev, "%s: offset:%d\n", __func__, priv->sensor[i].offset);
 	}
 }
 
@@ -209,7 +209,7 @@  int __init init_common(struct tsens_priv *priv)
 	if (ret)
 		goto err_put_device;
 	if (!enabled) {
-		dev_err(dev, "tsens device is not enabled\n");
+		dev_err(dev, "%s: device not enabled\n", __func__);
 		ret = -ENODEV;
 		goto err_put_device;
 	}
diff --git a/drivers/thermal/qcom/tsens.c b/drivers/thermal/qcom/tsens.c
index 542a7f8c3d962..06c6bbd69a1a7 100644
--- a/drivers/thermal/qcom/tsens.c
+++ b/drivers/thermal/qcom/tsens.c
@@ -127,7 +127,7 @@  static int tsens_probe(struct platform_device *pdev)
 		of_property_read_u32(np, "#qcom,sensors", &num_sensors);
 
 	if (num_sensors <= 0) {
-		dev_err(dev, "invalid number of sensors\n");
+		dev_err(dev, "%s: invalid number of sensors\n", __func__);
 		return -EINVAL;
 	}
 
@@ -156,7 +156,7 @@  static int tsens_probe(struct platform_device *pdev)
 
 	ret = priv->ops->init(priv);
 	if (ret < 0) {
-		dev_err(dev, "tsens init failed\n");
+		dev_err(dev, "%s: init failed\n", __func__);
 		return ret;
 	}
 
@@ -164,7 +164,7 @@  static int tsens_probe(struct platform_device *pdev)
 		ret = priv->ops->calibrate(priv);
 		if (ret < 0) {
 			if (ret != -EPROBE_DEFER)
-				dev_err(dev, "tsens calibration failed\n");
+				dev_err(dev, "%s: calibration failed\n", __func__);
 			return ret;
 		}
 	}