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

[Viacheslav Dubeyko <Slava.Dubeyko@ibm.com>]

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.