[PATCH] ceph: Fix log output race condition in osd client

[PATCH] ceph: Fix log output race condition in osd client

[Simon Buttgereit]

OSD client logging has a problem in get_osd() and put_osd().
For one logging output refcount_read() is called twice. If recount
value changes between both calls logging output is not consistent.

This patch adds an additional variable to store the current refcount
before using it in the logging macro.

Signed-off-by: Simon Buttgereit <simon.buttgereit@tu-ilmenau.de>
---
 net/ceph/osd_client.c | 10 ++++++----
 1 file changed, 6 insertions(+), 4 deletions(-)

diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
index 6664ea73ccf8..b8d20ab1976e 100644
--- a/net/ceph/osd_client.c
+++ b/net/ceph/osd_client.c
@@ -1280,8 +1280,9 @@ static struct ceph_osd *create_osd(struct ceph_osd_client *osdc, int onum)
 static struct ceph_osd *get_osd(struct ceph_osd *osd)
 {
 	if (refcount_inc_not_zero(&osd->o_ref)) {
-		dout("get_osd %p %d -> %d\n", osd, refcount_read(&osd->o_ref)-1,
-		     refcount_read(&osd->o_ref));
+		unsigned int refcount = refcount_read(&osd->o_ref);
+
+		dout("get_osd %p %d -> %d\n", osd, refcount - 1, refcount);
 		return osd;
 	} else {
 		dout("get_osd %p FAIL\n", osd);
@@ -1291,8 +1292,9 @@ static struct ceph_osd *get_osd(struct ceph_osd *osd)
 
 static void put_osd(struct ceph_osd *osd)
 {
-	dout("put_osd %p %d -> %d\n", osd, refcount_read(&osd->o_ref),
-	     refcount_read(&osd->o_ref) - 1);
+	unsigned int refcount = refcount_read(&osd->o_ref);
+
+	dout("put_osd %p %d -> %d\n", osd, refcount, refcount - 1);
 	if (refcount_dec_and_test(&osd->o_ref)) {
 		osd_cleanup(osd);
 		kfree(osd);
-- 
2.51.0

Re: [PATCH] ceph: Fix log output race condition in osd client

[Viacheslav Dubeyko]

On Tue, 2025-09-23 at 13:08 +0200, Simon Buttgereit wrote:
> OSD client logging has a problem in get_osd() and put_osd().
> For one logging output refcount_read() is called twice. If recount
> value changes between both calls logging output is not consistent.
> 
> This patch adds an additional variable to store the current refcount
> before using it in the logging macro.
> 
> Signed-off-by: Simon Buttgereit <simon.buttgereit@tu-ilmenau.de>
> ---
>  net/ceph/osd_client.c | 10 ++++++----
>  1 file changed, 6 insertions(+), 4 deletions(-)
> 
> diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
> index 6664ea73ccf8..b8d20ab1976e 100644
> --- a/net/ceph/osd_client.c
> +++ b/net/ceph/osd_client.c
> @@ -1280,8 +1280,9 @@ static struct ceph_osd *create_osd(struct ceph_osd_client *osdc, int onum)
>  static struct ceph_osd *get_osd(struct ceph_osd *osd)
>  {
>  	if (refcount_inc_not_zero(&osd->o_ref)) {
> -		dout("get_osd %p %d -> %d\n", osd, refcount_read(&osd->o_ref)-1,
> -		     refcount_read(&osd->o_ref));
> +		unsigned int refcount = refcount_read(&osd->o_ref);
> +
> +		dout("get_osd %p %d -> %d\n", osd, refcount - 1, refcount);

Frankly speaking, I don't see the point in this change. First of all, it's the
debug output and to be really precise could be not necessary here. And it is
easy to make correct conclusion from the debug output about real value of
refcount, even if value changes between both calls. Secondly, more important,
currently we have  refcount_read() as part of dout() call. After this change,
the refcount_read() will be called and assigned to refcount value, even if we
don't need in debug output.

Are you sure that you can compile the driver without warnings if
CONFIG_DYNAMIC_DEBUG=n?

Thanks,
Slava.

>  		return osd;
>  	} else {
>  		dout("get_osd %p FAIL\n", osd);
> @@ -1291,8 +1292,9 @@ static struct ceph_osd *get_osd(struct ceph_osd *osd)
>  
>  static void put_osd(struct ceph_osd *osd)
>  {
> -	dout("put_osd %p %d -> %d\n", osd, refcount_read(&osd->o_ref),
> -	     refcount_read(&osd->o_ref) - 1);
> +	unsigned int refcount = refcount_read(&osd->o_ref);
> +
> +	dout("put_osd %p %d -> %d\n", osd, refcount, refcount - 1);
>  	if (refcount_dec_and_test(&osd->o_ref)) {
>  		osd_cleanup(osd);
>  		kfree(osd);

Re: [PATCH] ceph: Fix log output race condition in osd client

[Simon Buttgereit]

On Tue, 2025-09-23 at 17:27 +0000, Viacheslav Dubeyko wrote:
> On Tue, 2025-09-23 at 13:08 +0200, Simon Buttgereit wrote:
> > OSD client logging has a problem in get_osd() and put_osd().
> > For one logging output refcount_read() is called twice. If recount
> > value changes between both calls logging output is not consistent.
> > 
> > This patch adds an additional variable to store the current
> > refcount
> > before using it in the logging macro.
> > 
> > Signed-off-by: Simon Buttgereit <simon.buttgereit@tu-ilmenau.de>
> > ---
> >  net/ceph/osd_client.c | 10 ++++++----
> >  1 file changed, 6 insertions(+), 4 deletions(-)
> > 
> > diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
> > index 6664ea73ccf8..b8d20ab1976e 100644
> > --- a/net/ceph/osd_client.c
> > +++ b/net/ceph/osd_client.c
> > @@ -1280,8 +1280,9 @@ static struct ceph_osd *create_osd(struct
> > ceph_osd_client *osdc, int onum)
> >  static struct ceph_osd *get_osd(struct ceph_osd *osd)
> >  {
> >  	if (refcount_inc_not_zero(&osd->o_ref)) {
> > -		dout("get_osd %p %d -> %d\n", osd,
> > refcount_read(&osd->o_ref)-1,
> > -		     refcount_read(&osd->o_ref));
> > +		unsigned int refcount = refcount_read(&osd-
> > >o_ref);
> > +
> > +		dout("get_osd %p %d -> %d\n", osd, refcount - 1,
> > refcount);
> 
> Frankly speaking, I don't see the point in this change. First of all,
> it's the
> debug output and to be really precise could be not necessary here.
> And it is
> easy to make correct conclusion from the debug output about real
> value of
> refcount, even if value changes between both calls. Secondly, more
> important,
> currently we have  refcount_read() as part of dout() call. After this
> change,
> the refcount_read() will be called and assigned to refcount value,
> even if we
> don't need in debug output.
> 
> Are you sure that you can compile the driver without warnings if
> CONFIG_DYNAMIC_DEBUG=n?
> 
> Thanks,
> Slava.
> 
> >  		return osd;
> >  	} else {
> >  		dout("get_osd %p FAIL\n", osd);
> > @@ -1291,8 +1292,9 @@ static struct ceph_osd *get_osd(struct
> > ceph_osd *osd)
> >  
> >  static void put_osd(struct ceph_osd *osd)
> >  {
> > -	dout("put_osd %p %d -> %d\n", osd, refcount_read(&osd-
> > >o_ref),
> > -	     refcount_read(&osd->o_ref) - 1);
> > +	unsigned int refcount = refcount_read(&osd->o_ref);
> > +
> > +	dout("put_osd %p %d -> %d\n", osd, refcount, refcount -
> > 1);
> >  	if (refcount_dec_and_test(&osd->o_ref)) {
> >  		osd_cleanup(osd);
> >  		kfree(osd);

Hi Slava,
thank you for your quick answer.

I checked it again: I built the kernel with gcc 15.2.1 with -Werror and
CONFIG_DYNAMIC_DEBUG=n and everything ran through fine without any
errors.
I guess because of the way no_printk(fmt, ...) is built.

And for sure, this is only debug output, but right now, there is a race
condition, which I went into, and in my opinion this should be fixed.
Another option, which would be completely fine for me, could be to
remove one recount_read call. This would result in something like:

dout("get_osd %p; new refcount = %d\n", osd, refcount_read(&osd-
>o_ref));

If you have another idea on how to handle this I'm open to your
suggestions.

Best Regards
Simon

RE: [PATCH] ceph: Fix log output race condition in osd client

[Viacheslav Dubeyko]

On Wed, 2025-09-24 at 15:57 +0200, Simon Buttgereit wrote:
> On Tue, 2025-09-23 at 17:27 +0000, Viacheslav Dubeyko wrote:
> > On Tue, 2025-09-23 at 13:08 +0200, Simon Buttgereit wrote:
> > > OSD client logging has a problem in get_osd() and put_osd().
> > > For one logging output refcount_read() is called twice. If recount
> > > value changes between both calls logging output is not consistent.
> > > 
> > > This patch adds an additional variable to store the current
> > > refcount
> > > before using it in the logging macro.
> > > 
> > > Signed-off-by: Simon Buttgereit <simon.buttgereit@tu-ilmenau.de>
> > > ---
> > >  net/ceph/osd_client.c | 10 ++++++----
> > >  1 file changed, 6 insertions(+), 4 deletions(-)
> > > 
> > > diff --git a/net/ceph/osd_client.c b/net/ceph/osd_client.c
> > > index 6664ea73ccf8..b8d20ab1976e 100644
> > > --- a/net/ceph/osd_client.c
> > > +++ b/net/ceph/osd_client.c
> > > @@ -1280,8 +1280,9 @@ static struct ceph_osd *create_osd(struct
> > > ceph_osd_client *osdc, int onum)
> > >  static struct ceph_osd *get_osd(struct ceph_osd *osd)
> > >  {
> > >  	if (refcount_inc_not_zero(&osd->o_ref)) {
> > > -		dout("get_osd %p %d -> %d\n", osd,
> > > refcount_read(&osd->o_ref)-1,
> > > -		     refcount_read(&osd->o_ref));
> > > +		unsigned int refcount = refcount_read(&osd-
> > > > o_ref);
> > > +
> > > +		dout("get_osd %p %d -> %d\n", osd, refcount - 1,
> > > refcount);
> > 
> > Frankly speaking, I don't see the point in this change. First of all,
> > it's the
> > debug output and to be really precise could be not necessary here.
> > And it is
> > easy to make correct conclusion from the debug output about real
> > value of
> > refcount, even if value changes between both calls. Secondly, more
> > important,
> > currently we have  refcount_read() as part of dout() call. After this
> > change,
> > the refcount_read() will be called and assigned to refcount value,
> > even if we
> > don't need in debug output.
> > 
> > Are you sure that you can compile the driver without warnings if
> > CONFIG_DYNAMIC_DEBUG=n?
> > 
> > Thanks,
> > Slava.
> > 
> > >  		return osd;
> > >  	} else {
> > >  		dout("get_osd %p FAIL\n", osd);
> > > @@ -1291,8 +1292,9 @@ static struct ceph_osd *get_osd(struct
> > > ceph_osd *osd)
> > >  
> > >  static void put_osd(struct ceph_osd *osd)
> > >  {
> > > -	dout("put_osd %p %d -> %d\n", osd, refcount_read(&osd-
> > > > o_ref),
> > > -	     refcount_read(&osd->o_ref) - 1);
> > > +	unsigned int refcount = refcount_read(&osd->o_ref);
> > > +
> > > +	dout("put_osd %p %d -> %d\n", osd, refcount, refcount -
> > > 1);
> > >  	if (refcount_dec_and_test(&osd->o_ref)) {
> > >  		osd_cleanup(osd);
> > >  		kfree(osd);
> 
> Hi Slava,
> thank you for your quick answer.
> 
> I checked it again: I built the kernel with gcc 15.2.1 with -Werror and
> CONFIG_DYNAMIC_DEBUG=n and everything ran through fine without any
> errors.
> I guess because of the way no_printk(fmt, ...) is built.
> 
> And for sure, this is only debug output, but right now, there is a race
> condition, which I went into, and in my opinion this should be fixed.
> Another option, which would be completely fine for me, could be to
> remove one recount_read call. This would result in something like:
> 
> dout("get_osd %p; new refcount = %d\n", osd, refcount_read(&osd-
> > o_ref));
> 
> If you have another idea on how to handle this I'm open to your
> suggestions.
> 

Hi Simon,

I think that removing one refcount_read() call looks like more clean solution.
Likewise statement:

dout("put_osd %p %d -> %d\n", osd, refcount_read(&osd->o_ref),
refcount_read(&osd->o_ref) - 1);

smells really bad for my taste and it looks like the overkill anyway. :)

Thanks,
Slava.