[1/1] lib/vsprintf: Fix %pfwf when current node refcount == 0

Message ID 20231114110456.273844-1-herve.codina@bootlin.com
State New
Headers
Series [1/1] lib/vsprintf: Fix %pfwf when current node refcount == 0 |

Commit Message

Herve Codina Nov. 14, 2023, 11:04 a.m. UTC
  A refcount issue can appeared in __fwnode_link_del() due to the
pr_debug() call:
  WARNING: CPU: 0 PID: 901 at lib/refcount.c:25 refcount_warn_saturate+0xe5/0x110
  Call Trace:
  <TASK>
  ? refcount_warn_saturate+0xe5/0x110
  ? __warn+0x81/0x130
  ? refcount_warn_saturate+0xe5/0x110
  ? report_bug+0x191/0x1c0
  ? srso_alias_return_thunk+0x5/0x7f
  ? prb_read_valid+0x1b/0x30
  ? handle_bug+0x3c/0x80
  ? exc_invalid_op+0x17/0x70
  ? asm_exc_invalid_op+0x1a/0x20
  ? refcount_warn_saturate+0xe5/0x110
  kobject_get+0x68/0x70
  of_node_get+0x1e/0x30
  of_fwnode_get+0x28/0x40
  fwnode_full_name_string+0x34/0x90
  fwnode_string+0xdb/0x140
  vsnprintf+0x17b/0x630
  va_format.isra.0+0x71/0x130
  vsnprintf+0x17b/0x630
  vprintk_store+0x162/0x4d0
  ? srso_alias_return_thunk+0x5/0x7f
  ? srso_alias_return_thunk+0x5/0x7f
  ? srso_alias_return_thunk+0x5/0x7f
  ? try_to_wake_up+0x9c/0x620
  ? rwsem_mark_wake+0x1b2/0x310
  vprintk_emit+0xe4/0x2b0
  _printk+0x5c/0x80
  __dynamic_pr_debug+0x131/0x160
  ? srso_alias_return_thunk+0x5/0x7f
  __fwnode_link_del+0x25/0xa0
  fwnode_links_purge+0x39/0xb0
  of_node_release+0xd9/0x180
  kobject_put+0x7b/0x190
  ...

Indeed, an fwnode (of_node) is being destroyed and so, of_node_release()
is called because the of_node refcount reached 0.
From of_node_release() several function calls are done and lead to
a pr_debug() calls with %pfwf to print the fwnode full name.
The issue is not present if we change %pfwf to %pfwP.

To print the full name, %pfwf iterates over the current node and its
parents and obtain/drop a reference to all nodes involved.

In order to allow to print the full name (%pfwf) of a node while it is
being destroyed, do not obtain/drop a reference to this current node.

Fixes: a92eb7621b9f ("lib/vsprintf: Make use of fwnode API to obtain node names and separators")
Cc: stable@vger.kernel.org
Signed-off-by: Herve Codina <herve.codina@bootlin.com>
---
 lib/vsprintf.c | 14 ++++++++++++--
 1 file changed, 12 insertions(+), 2 deletions(-)
  

Comments

Sakari Ailus Nov. 14, 2023, 11:28 a.m. UTC | #1
Hi Herve,

Thanks for the patch.

On Tue, Nov 14, 2023 at 12:04:56PM +0100, Herve Codina wrote:
> A refcount issue can appeared in __fwnode_link_del() due to the
> pr_debug() call:
>   WARNING: CPU: 0 PID: 901 at lib/refcount.c:25 refcount_warn_saturate+0xe5/0x110
>   Call Trace:
>   <TASK>
>   ? refcount_warn_saturate+0xe5/0x110
>   ? __warn+0x81/0x130
>   ? refcount_warn_saturate+0xe5/0x110
>   ? report_bug+0x191/0x1c0
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? prb_read_valid+0x1b/0x30
>   ? handle_bug+0x3c/0x80
>   ? exc_invalid_op+0x17/0x70
>   ? asm_exc_invalid_op+0x1a/0x20
>   ? refcount_warn_saturate+0xe5/0x110
>   kobject_get+0x68/0x70
>   of_node_get+0x1e/0x30
>   of_fwnode_get+0x28/0x40
>   fwnode_full_name_string+0x34/0x90
>   fwnode_string+0xdb/0x140
>   vsnprintf+0x17b/0x630
>   va_format.isra.0+0x71/0x130
>   vsnprintf+0x17b/0x630
>   vprintk_store+0x162/0x4d0
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? try_to_wake_up+0x9c/0x620
>   ? rwsem_mark_wake+0x1b2/0x310
>   vprintk_emit+0xe4/0x2b0
>   _printk+0x5c/0x80
>   __dynamic_pr_debug+0x131/0x160
>   ? srso_alias_return_thunk+0x5/0x7f
>   __fwnode_link_del+0x25/0xa0
>   fwnode_links_purge+0x39/0xb0
>   of_node_release+0xd9/0x180
>   kobject_put+0x7b/0x190
>   ...
> 
> Indeed, an fwnode (of_node) is being destroyed and so, of_node_release()
> is called because the of_node refcount reached 0.
> From of_node_release() several function calls are done and lead to
> a pr_debug() calls with %pfwf to print the fwnode full name.
> The issue is not present if we change %pfwf to %pfwP.
> 
> To print the full name, %pfwf iterates over the current node and its
> parents and obtain/drop a reference to all nodes involved.
> 
> In order to allow to print the full name (%pfwf) of a node while it is
> being destroyed, do not obtain/drop a reference to this current node.
> 
> Fixes: a92eb7621b9f ("lib/vsprintf: Make use of fwnode API to obtain node names and separators")
> Cc: stable@vger.kernel.org
> Signed-off-by: Herve Codina <herve.codina@bootlin.com>
> ---
>  lib/vsprintf.c | 14 ++++++++++++--
>  1 file changed, 12 insertions(+), 2 deletions(-)
> 
> diff --git a/lib/vsprintf.c b/lib/vsprintf.c
> index afb88b24fa74..74ef229c2783 100644
> --- a/lib/vsprintf.c
> +++ b/lib/vsprintf.c
> @@ -2108,8 +2108,8 @@ char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
>  {
>  	int depth;
>  
> -	/* Loop starting from the root node to the current node. */
> -	for (depth = fwnode_count_parents(fwnode); depth >= 0; depth--) {
> +	/* Loop starting from the root node to the parent of current node. */
> +	for (depth = fwnode_count_parents(fwnode); depth > 0; depth--) {
>  		struct fwnode_handle *__fwnode =
>  			fwnode_get_nth_parent(fwnode, depth);

How about, without changing the loop:

		/*
		 * Only get a reference for other nodes, fwnode refcount
		 * may be 0 here.
		 */
		struct fwnode_handle *__fwnode =
			depth ? fwnode_get_nth_parent(fwnode, depth) : fwnode;

>  
> @@ -2121,6 +2121,16 @@ char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
>  		fwnode_handle_put(__fwnode);

And:

		if (__fwnode != fwnode)
			fwnode_handle_put(__fwnode);

>  	}
>  
> +	/* Handle current node without calling fwnode_handle_{get,put}().
> +	 * This allows to print the full node name while the current node is
> +	 * being destroyed (ie print from a function called because of
> +	 * refcount == 0) without any refcount issues.
> +	 */
> +	buf = string(buf, end, fwnode_get_name_prefix(fwnode),
> +		     default_str_spec);
> +	buf = string(buf, end, fwnode_get_name(fwnode),
> +		     default_str_spec);

It'd avoid duplicating this part, too, which I find worth the while.

> +
>  	return buf;
>  }
>
  
Herve Codina Nov. 14, 2023, 11:48 a.m. UTC | #2
Hi Sakari,

On Tue, 14 Nov 2023 11:28:43 +0000
Sakari Ailus <sakari.ailus@linux.intel.com> wrote:

> > --- a/lib/vsprintf.c
> > +++ b/lib/vsprintf.c
> > @@ -2108,8 +2108,8 @@ char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
> >  {
> >  	int depth;
> >  
> > -	/* Loop starting from the root node to the current node. */
> > -	for (depth = fwnode_count_parents(fwnode); depth >= 0; depth--) {
> > +	/* Loop starting from the root node to the parent of current node. */
> > +	for (depth = fwnode_count_parents(fwnode); depth > 0; depth--) {
> >  		struct fwnode_handle *__fwnode =
> >  			fwnode_get_nth_parent(fwnode, depth);  
> 
> How about, without changing the loop:
> 
> 		/*
> 		 * Only get a reference for other nodes, fwnode refcount
> 		 * may be 0 here.
> 		 */
> 		struct fwnode_handle *__fwnode =
> 			depth ? fwnode_get_nth_parent(fwnode, depth) : fwnode;
> 
> >  
> > @@ -2121,6 +2121,16 @@ char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
> >  		fwnode_handle_put(__fwnode);  
> 
> And:
> 
> 		if (__fwnode != fwnode)
> 			fwnode_handle_put(__fwnode);
> 

Sure.
I will just change to keep the both tests consistent.
I mean test with depth or test with __fwnode != fwnode but avoid
mixing them.

What do you think about testing using depth in all cases and so:
	if (depth)
		fwnode_handle_put(__fwnode);

Best regards,
Hervé
  
Sakari Ailus Nov. 14, 2023, 12:29 p.m. UTC | #3
Hi Herve,

On Tue, Nov 14, 2023 at 12:48:32PM +0100, Herve Codina wrote:
> Hi Sakari,
> 
> On Tue, 14 Nov 2023 11:28:43 +0000
> Sakari Ailus <sakari.ailus@linux.intel.com> wrote:
> 
> > > --- a/lib/vsprintf.c
> > > +++ b/lib/vsprintf.c
> > > @@ -2108,8 +2108,8 @@ char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
> > >  {
> > >  	int depth;
> > >  
> > > -	/* Loop starting from the root node to the current node. */
> > > -	for (depth = fwnode_count_parents(fwnode); depth >= 0; depth--) {
> > > +	/* Loop starting from the root node to the parent of current node. */
> > > +	for (depth = fwnode_count_parents(fwnode); depth > 0; depth--) {
> > >  		struct fwnode_handle *__fwnode =
> > >  			fwnode_get_nth_parent(fwnode, depth);  
> > 
> > How about, without changing the loop:
> > 
> > 		/*
> > 		 * Only get a reference for other nodes, fwnode refcount
> > 		 * may be 0 here.
> > 		 */
> > 		struct fwnode_handle *__fwnode =
> > 			depth ? fwnode_get_nth_parent(fwnode, depth) : fwnode;
> > 
> > >  
> > > @@ -2121,6 +2121,16 @@ char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
> > >  		fwnode_handle_put(__fwnode);  
> > 
> > And:
> > 
> > 		if (__fwnode != fwnode)
> > 			fwnode_handle_put(__fwnode);
> > 
> 
> Sure.
> I will just change to keep the both tests consistent.
> I mean test with depth or test with __fwnode != fwnode but avoid
> mixing them.
> 
> What do you think about testing using depth in all cases and so:
> 	if (depth)
> 		fwnode_handle_put(__fwnode);

I'd compare fwnodes as we're putting __fwnode since we've gotten a
reference to fwnodes different from fwnode. I don't have a strong opinion
on this though, up to you.
  
Andy Shevchenko Nov. 14, 2023, 1:12 p.m. UTC | #4
On Tue, Nov 14, 2023 at 12:04:56PM +0100, Herve Codina wrote:
> A refcount issue can appeared in __fwnode_link_del() due to the
> pr_debug() call:

>   WARNING: CPU: 0 PID: 901 at lib/refcount.c:25 refcount_warn_saturate+0xe5/0x110
>   Call Trace:
>   <TASK>
>   ? refcount_warn_saturate+0xe5/0x110
>   ? __warn+0x81/0x130
>   ? refcount_warn_saturate+0xe5/0x110
>   ? report_bug+0x191/0x1c0
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? prb_read_valid+0x1b/0x30
>   ? handle_bug+0x3c/0x80
>   ? exc_invalid_op+0x17/0x70
>   ? asm_exc_invalid_op+0x1a/0x20
>   ? refcount_warn_saturate+0xe5/0x110
>   kobject_get+0x68/0x70
>   of_node_get+0x1e/0x30
>   of_fwnode_get+0x28/0x40
>   fwnode_full_name_string+0x34/0x90
>   fwnode_string+0xdb/0x140
>   vsnprintf+0x17b/0x630
>   va_format.isra.0+0x71/0x130
>   vsnprintf+0x17b/0x630
>   vprintk_store+0x162/0x4d0
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? srso_alias_return_thunk+0x5/0x7f
>   ? try_to_wake_up+0x9c/0x620
>   ? rwsem_mark_wake+0x1b2/0x310
>   vprintk_emit+0xe4/0x2b0
>   _printk+0x5c/0x80
>   __dynamic_pr_debug+0x131/0x160
>   ? srso_alias_return_thunk+0x5/0x7f
>   __fwnode_link_del+0x25/0xa0
>   fwnode_links_purge+0x39/0xb0
>   of_node_release+0xd9/0x180
>   kobject_put+0x7b/0x190
>   ...

Please, do not put so many unrelated lines of backtrace in the commit message.
Leave only the important ones (the Submitting Patches document suggests some
like ~3-5 lines only).

> Indeed, an fwnode (of_node) is being destroyed and so, of_node_release()
> is called because the of_node refcount reached 0.
> From of_node_release() several function calls are done and lead to
> a pr_debug() calls with %pfwf to print the fwnode full name.
> The issue is not present if we change %pfwf to %pfwP.
> 
> To print the full name, %pfwf iterates over the current node and its
> parents and obtain/drop a reference to all nodes involved.
> 
> In order to allow to print the full name (%pfwf) of a node while it is
> being destroyed, do not obtain/drop a reference to this current node.
  
Herve Codina Nov. 14, 2023, 1:19 p.m. UTC | #5
On Tue, 14 Nov 2023 15:12:47 +0200
Andy Shevchenko <andriy.shevchenko@linux.intel.com> wrote:

> On Tue, Nov 14, 2023 at 12:04:56PM +0100, Herve Codina wrote:
> > A refcount issue can appeared in __fwnode_link_del() due to the
> > pr_debug() call:  
> 
> >   WARNING: CPU: 0 PID: 901 at lib/refcount.c:25 refcount_warn_saturate+0xe5/0x110
> >   Call Trace:
> >   <TASK>
> >   ? refcount_warn_saturate+0xe5/0x110
> >   ? __warn+0x81/0x130
> >   ? refcount_warn_saturate+0xe5/0x110
> >   ? report_bug+0x191/0x1c0
> >   ? srso_alias_return_thunk+0x5/0x7f
> >   ? prb_read_valid+0x1b/0x30
> >   ? handle_bug+0x3c/0x80
> >   ? exc_invalid_op+0x17/0x70
> >   ? asm_exc_invalid_op+0x1a/0x20
> >   ? refcount_warn_saturate+0xe5/0x110
> >   kobject_get+0x68/0x70
> >   of_node_get+0x1e/0x30
> >   of_fwnode_get+0x28/0x40
> >   fwnode_full_name_string+0x34/0x90
> >   fwnode_string+0xdb/0x140
> >   vsnprintf+0x17b/0x630
> >   va_format.isra.0+0x71/0x130
> >   vsnprintf+0x17b/0x630
> >   vprintk_store+0x162/0x4d0
> >   ? srso_alias_return_thunk+0x5/0x7f
> >   ? srso_alias_return_thunk+0x5/0x7f
> >   ? srso_alias_return_thunk+0x5/0x7f
> >   ? try_to_wake_up+0x9c/0x620
> >   ? rwsem_mark_wake+0x1b2/0x310
> >   vprintk_emit+0xe4/0x2b0
> >   _printk+0x5c/0x80
> >   __dynamic_pr_debug+0x131/0x160
> >   ? srso_alias_return_thunk+0x5/0x7f
> >   __fwnode_link_del+0x25/0xa0
> >   fwnode_links_purge+0x39/0xb0
> >   of_node_release+0xd9/0x180
> >   kobject_put+0x7b/0x190
> >   ...  
> 
> Please, do not put so many unrelated lines of backtrace in the commit message.
> Leave only the important ones (the Submitting Patches document suggests some
> like ~3-5 lines only).

Ok, I will remove some of them.

Best regards,
Hervé
  
Andy Shevchenko Nov. 14, 2023, 1:27 p.m. UTC | #6
On Tue, Nov 14, 2023 at 02:19:34PM +0100, Herve Codina wrote:
> On Tue, 14 Nov 2023 15:12:47 +0200
> Andy Shevchenko <andriy.shevchenko@linux.intel.com> wrote:
> > On Tue, Nov 14, 2023 at 12:04:56PM +0100, Herve Codina wrote:
> > > A refcount issue can appeared in __fwnode_link_del() due to the
> > > pr_debug() call:  

---8<---

> > >   WARNING: CPU: 0 PID: 901 at lib/refcount.c:25 refcount_warn_saturate+0xe5/0x110
> > >   Call Trace:

> > >   ? refcount_warn_saturate+0xe5/0x110

	...
> > >   of_node_get+0x1e/0x30
> > >   of_fwnode_get+0x28/0x40
> > >   fwnode_full_name_string+0x34/0x90
> > >   fwnode_string+0xdb/0x140
	...

> > >   vsnprintf+0x17b/0x630
	...
> > >   __fwnode_link_del+0x25/0xa0
> > >   fwnode_links_purge+0x39/0xb0
> > >   of_node_release+0xd9/0x180
	...

---8<---

> > Please, do not put so many unrelated lines of backtrace in the commit message.
> > Leave only the important ones (the Submitting Patches document suggests some
> > like ~3-5 lines only).
> 
> Ok, I will remove some of them.

Thanks (my suggestion is above).
  
Andy Shevchenko Nov. 14, 2023, 1:28 p.m. UTC | #7
On Tue, Nov 14, 2023 at 03:27:43PM +0200, Andy Shevchenko wrote:
> On Tue, Nov 14, 2023 at 02:19:34PM +0100, Herve Codina wrote:
> > On Tue, 14 Nov 2023 15:12:47 +0200
> > Andy Shevchenko <andriy.shevchenko@linux.intel.com> wrote:
> > > On Tue, Nov 14, 2023 at 12:04:56PM +0100, Herve Codina wrote:
> > > > A refcount issue can appeared in __fwnode_link_del() due to the
> > > > pr_debug() call:  

---8<---

> > > >   WARNING: CPU: 0 PID: 901 at lib/refcount.c:25 refcount_warn_saturate+0xe5/0x110
> > > >   Call Trace:

> > > >   ? refcount_warn_saturate+0xe5/0x110
> 
> 	...

These are actually not needed as duplicating WARNING above.

> > > >   of_node_get+0x1e/0x30
> > > >   of_fwnode_get+0x28/0x40
> > > >   fwnode_full_name_string+0x34/0x90
> > > >   fwnode_string+0xdb/0x140
> 	...
> 
> > > >   vsnprintf+0x17b/0x630
> 	...
> > > >   __fwnode_link_del+0x25/0xa0
> > > >   fwnode_links_purge+0x39/0xb0
> > > >   of_node_release+0xd9/0x180
> 	...

---8<---

> > > Please, do not put so many unrelated lines of backtrace in the commit message.
> > > Leave only the important ones (the Submitting Patches document suggests some
> > > like ~3-5 lines only).
> > 
> > Ok, I will remove some of them.
> 
> Thanks (my suggestion is above).
  

Patch

diff --git a/lib/vsprintf.c b/lib/vsprintf.c
index afb88b24fa74..74ef229c2783 100644
--- a/lib/vsprintf.c
+++ b/lib/vsprintf.c
@@ -2108,8 +2108,8 @@  char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
 {
 	int depth;
 
-	/* Loop starting from the root node to the current node. */
-	for (depth = fwnode_count_parents(fwnode); depth >= 0; depth--) {
+	/* Loop starting from the root node to the parent of current node. */
+	for (depth = fwnode_count_parents(fwnode); depth > 0; depth--) {
 		struct fwnode_handle *__fwnode =
 			fwnode_get_nth_parent(fwnode, depth);
 
@@ -2121,6 +2121,16 @@  char *fwnode_full_name_string(struct fwnode_handle *fwnode, char *buf,
 		fwnode_handle_put(__fwnode);
 	}
 
+	/* Handle current node without calling fwnode_handle_{get,put}().
+	 * This allows to print the full node name while the current node is
+	 * being destroyed (ie print from a function called because of
+	 * refcount == 0) without any refcount issues.
+	 */
+	buf = string(buf, end, fwnode_get_name_prefix(fwnode),
+		     default_str_spec);
+	buf = string(buf, end, fwnode_get_name(fwnode),
+		     default_str_spec);
+
 	return buf;
 }