| Message ID | Zyrsg3bvNu1rswqb@gmail.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | usb: raw_gadget: Add debug logs to a troubleshoot a double-free bug in raw_release. | expand |
On Wed, Nov 6, 2024 at 1:11 PM Chang Yu <marcus.yu.56@gmail.com> wrote: > > syzkaller reported a double free bug > (https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c) in > raw_release. > > From the stack traces it looks like either raw_release was invoked > twice or there were some between kref_get in raw_ioctl_run and > kref_put raw_release. But these should not be possible. We need > more logs to understand the cause. > > Make raw_release and raw_ioctl_run report the ref count before > and after get/put to help debug this. > > Signed-off-by: Chang Yu <marcus.yu.56@gmail.com> > Reported-by: syzbot+3e563d99e70973c0755c@syzkaller.appspotmail.com > Link: https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c > --- > drivers/usb/gadget/legacy/raw_gadget.c | 14 ++++++++++++++ > 1 file changed, 14 insertions(+) > > diff --git a/drivers/usb/gadget/legacy/raw_gadget.c b/drivers/usb/gadget/legacy/raw_gadget.c > index 112fd18d8c99..ac4e319c743f 100644 > --- a/drivers/usb/gadget/legacy/raw_gadget.c > +++ b/drivers/usb/gadget/legacy/raw_gadget.c > @@ -194,6 +194,8 @@ static struct raw_dev *dev_new(void) > return NULL; > /* Matches kref_put() in raw_release(). */ > kref_init(&dev->count); > + dev_dbg(dev->dev, "%s kref count initialized: %d\n", > + __func__, kref_read(&dev->count)); > spin_lock_init(&dev->lock); > init_completion(&dev->ep0_done); > raw_event_queue_init(&dev->queue); > @@ -464,13 +466,21 @@ static int raw_release(struct inode *inode, struct file *fd) > dev_err(dev->dev, > "usb_gadget_unregister_driver() failed with %d\n", > ret); > + dev_dbg(dev->dev, "%s kref count before unregister driver put: %d\n", > + __func__, kref_read(&dev->count)); > /* Matches kref_get() in raw_ioctl_run(). */ > kref_put(&dev->count, dev_free); > + dev_dbg(dev->dev, "%s kref count after unregister driver put: %d\n", > + __func__, kref_read(&dev->count)); > } > > out_put: > + dev_dbg(dev->dev, "%s kref count before final put: %d\n", > + __func__, kref_read(&dev->count)); > /* Matches dev_new() in raw_open(). */ > kref_put(&dev->count, dev_free); > + dev_dbg(dev->dev, "%s kref count after final put: %d\n", > + __func__, kref_read(&dev->count)); > return ret; > } > > @@ -603,8 +613,12 @@ static int raw_ioctl_run(struct raw_dev *dev, unsigned long value) > } > dev->gadget_registered = true; > dev->state = STATE_DEV_RUNNING; > + dev_dbg(dev->dev, "%s kref count before get: %d\n", > + __func__, kref_read(&dev->count)); > /* Matches kref_put() in raw_release(). */ > kref_get(&dev->count); > + dev_dbg(dev->dev, "%s kref count after get: %d\n", > + __func__, kref_read(&dev->count)); > > out_unlock: > spin_unlock_irqrestore(&dev->lock, flags); > -- > 2.47.0 > Hi Chang, This patch looks very specific to the bug we're trying to debug - I don't think it makes sense to apply it to the mainline. What you can do instead is ask syzbot to run the reproducer it has with this patch applied via the #syz test command. Thank you!
On Wed, Nov 06, 2024 at 01:35:27PM +0900, Andrey Konovalov wrote: > On Wed, Nov 6, 2024 at 1:11 PM Chang Yu <marcus.yu.56@gmail.com> wrote: > > > > syzkaller reported a double free bug > > (https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c) in > > raw_release. > > > > From the stack traces it looks like either raw_release was invoked > > twice or there were some between kref_get in raw_ioctl_run and > > kref_put raw_release. But these should not be possible. We need > > more logs to understand the cause. > > > > Make raw_release and raw_ioctl_run report the ref count before > > and after get/put to help debug this. > > > > Signed-off-by: Chang Yu <marcus.yu.56@gmail.com> > > Reported-by: syzbot+3e563d99e70973c0755c@syzkaller.appspotmail.com > > Link: https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c > > --- > > drivers/usb/gadget/legacy/raw_gadget.c | 14 ++++++++++++++ > > 1 file changed, 14 insertions(+) > > > > diff --git a/drivers/usb/gadget/legacy/raw_gadget.c b/drivers/usb/gadget/legacy/raw_gadget.c > > index 112fd18d8c99..ac4e319c743f 100644 > > --- a/drivers/usb/gadget/legacy/raw_gadget.c > > +++ b/drivers/usb/gadget/legacy/raw_gadget.c > > @@ -194,6 +194,8 @@ static struct raw_dev *dev_new(void) > > return NULL; > > /* Matches kref_put() in raw_release(). */ > > kref_init(&dev->count); > > + dev_dbg(dev->dev, "%s kref count initialized: %d\n", > > + __func__, kref_read(&dev->count)); > > spin_lock_init(&dev->lock); > > init_completion(&dev->ep0_done); > > raw_event_queue_init(&dev->queue); > > @@ -464,13 +466,21 @@ static int raw_release(struct inode *inode, struct file *fd) > > dev_err(dev->dev, > > "usb_gadget_unregister_driver() failed with %d\n", > > ret); > > + dev_dbg(dev->dev, "%s kref count before unregister driver put: %d\n", > > + __func__, kref_read(&dev->count)); > > /* Matches kref_get() in raw_ioctl_run(). */ > > kref_put(&dev->count, dev_free); > > + dev_dbg(dev->dev, "%s kref count after unregister driver put: %d\n", > > + __func__, kref_read(&dev->count)); > > } > > > > out_put: > > + dev_dbg(dev->dev, "%s kref count before final put: %d\n", > > + __func__, kref_read(&dev->count)); > > /* Matches dev_new() in raw_open(). */ > > kref_put(&dev->count, dev_free); > > + dev_dbg(dev->dev, "%s kref count after final put: %d\n", > > + __func__, kref_read(&dev->count)); > > return ret; > > } > > > > @@ -603,8 +613,12 @@ static int raw_ioctl_run(struct raw_dev *dev, unsigned long value) > > } > > dev->gadget_registered = true; > > dev->state = STATE_DEV_RUNNING; > > + dev_dbg(dev->dev, "%s kref count before get: %d\n", > > + __func__, kref_read(&dev->count)); > > /* Matches kref_put() in raw_release(). */ > > kref_get(&dev->count); > > + dev_dbg(dev->dev, "%s kref count after get: %d\n", > > + __func__, kref_read(&dev->count)); > > > > out_unlock: > > spin_unlock_irqrestore(&dev->lock, flags); > > -- > > 2.47.0 > > > > Hi Chang, > > This patch looks very specific to the bug we're trying to debug - I > don't think it makes sense to apply it to the mainline. > > What you can do instead is ask syzbot to run the reproducer it has > with this patch applied via the #syz test command. > > Thank you! Thank you for the tips, Andrey. I will do that. My apologies for the rookie mistake. I'm pretty new to kernel patching/debugging and I'm still learning the correct way to do stuff. Thank you again for your help!
On Tue, Nov 05, 2024 at 08:11:47PM -0800, Chang Yu wrote: > syzkaller reported a double free bug > (https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c) in > raw_release. > > >From the stack traces it looks like either raw_release was invoked > twice or there were some between kref_get in raw_ioctl_run and > kref_put raw_release. But these should not be possible. We need > more logs to understand the cause. > > Make raw_release and raw_ioctl_run report the ref count before > and after get/put to help debug this. > > Signed-off-by: Chang Yu <marcus.yu.56@gmail.com> > Reported-by: syzbot+3e563d99e70973c0755c@syzkaller.appspotmail.com > Link: https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c > --- > drivers/usb/gadget/legacy/raw_gadget.c | 14 ++++++++++++++ > 1 file changed, 14 insertions(+) > > diff --git a/drivers/usb/gadget/legacy/raw_gadget.c b/drivers/usb/gadget/legacy/raw_gadget.c > index 112fd18d8c99..ac4e319c743f 100644 > --- a/drivers/usb/gadget/legacy/raw_gadget.c > +++ b/drivers/usb/gadget/legacy/raw_gadget.c > @@ -194,6 +194,8 @@ static struct raw_dev *dev_new(void) > return NULL; > /* Matches kref_put() in raw_release(). */ > kref_init(&dev->count); > + dev_dbg(dev->dev, "%s kref count initialized: %d\n", > + __func__, kref_read(&dev->count)); Please note that you never need to add a __func__ to a dev_dbg() call, as it is already present automatically for you. thanks, greg k-h
On Wed, Nov 06, 2024 at 01:35:27PM +0900, Andrey Konovalov wrote: > On Wed, Nov 6, 2024 at 1:11 PM Chang Yu <marcus.yu.56@gmail.com> wrote: > > > > syzkaller reported a double free bug > > (https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c) in > > raw_release. > > > > From the stack traces it looks like either raw_release was invoked > > twice or there were some between kref_get in raw_ioctl_run and > > kref_put raw_release. But these should not be possible. We need > > more logs to understand the cause. > > > > Make raw_release and raw_ioctl_run report the ref count before > > and after get/put to help debug this. > > > > Signed-off-by: Chang Yu <marcus.yu.56@gmail.com> > > Reported-by: syzbot+3e563d99e70973c0755c@syzkaller.appspotmail.com > > Link: https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c > > --- > > drivers/usb/gadget/legacy/raw_gadget.c | 14 ++++++++++++++ > > 1 file changed, 14 insertions(+) > > > > diff --git a/drivers/usb/gadget/legacy/raw_gadget.c b/drivers/usb/gadget/legacy/raw_gadget.c > > index 112fd18d8c99..ac4e319c743f 100644 > > --- a/drivers/usb/gadget/legacy/raw_gadget.c > > +++ b/drivers/usb/gadget/legacy/raw_gadget.c > > @@ -194,6 +194,8 @@ static struct raw_dev *dev_new(void) > > return NULL; > > /* Matches kref_put() in raw_release(). */ > > kref_init(&dev->count); > > + dev_dbg(dev->dev, "%s kref count initialized: %d\n", > > + __func__, kref_read(&dev->count)); > > spin_lock_init(&dev->lock); > > init_completion(&dev->ep0_done); > > raw_event_queue_init(&dev->queue); > > @@ -464,13 +466,21 @@ static int raw_release(struct inode *inode, struct file *fd) > > dev_err(dev->dev, > > "usb_gadget_unregister_driver() failed with %d\n", > > ret); > > + dev_dbg(dev->dev, "%s kref count before unregister driver put: %d\n", > > + __func__, kref_read(&dev->count)); > > /* Matches kref_get() in raw_ioctl_run(). */ > > kref_put(&dev->count, dev_free); > > + dev_dbg(dev->dev, "%s kref count after unregister driver put: %d\n", > > + __func__, kref_read(&dev->count)); > > } > > > > out_put: > > + dev_dbg(dev->dev, "%s kref count before final put: %d\n", > > + __func__, kref_read(&dev->count)); > > /* Matches dev_new() in raw_open(). */ > > kref_put(&dev->count, dev_free); > > + dev_dbg(dev->dev, "%s kref count after final put: %d\n", > > + __func__, kref_read(&dev->count)); > > return ret; > > } > > > > @@ -603,8 +613,12 @@ static int raw_ioctl_run(struct raw_dev *dev, unsigned long value) > > } > > dev->gadget_registered = true; > > dev->state = STATE_DEV_RUNNING; > > + dev_dbg(dev->dev, "%s kref count before get: %d\n", > > + __func__, kref_read(&dev->count)); > > /* Matches kref_put() in raw_release(). */ > > kref_get(&dev->count); > > + dev_dbg(dev->dev, "%s kref count after get: %d\n", > > + __func__, kref_read(&dev->count)); > > > > out_unlock: > > spin_unlock_irqrestore(&dev->lock, flags); > > -- > > 2.47.0 > > > > Hi Chang, > > This patch looks very specific to the bug we're trying to debug - I > don't think it makes sense to apply it to the mainline. > > What you can do instead is ask syzbot to run the reproducer it has > with this patch applied via the #syz test command. > > Thank you! In addition you should change your dev_dbg() calls to dev_info(), because dev_dbg() output will not show up in the syzbot console log. Alan Stern
diff --git a/drivers/usb/gadget/legacy/raw_gadget.c b/drivers/usb/gadget/legacy/raw_gadget.c index 112fd18d8c99..ac4e319c743f 100644 --- a/drivers/usb/gadget/legacy/raw_gadget.c +++ b/drivers/usb/gadget/legacy/raw_gadget.c @@ -194,6 +194,8 @@ static struct raw_dev *dev_new(void) return NULL; /* Matches kref_put() in raw_release(). */ kref_init(&dev->count); + dev_dbg(dev->dev, "%s kref count initialized: %d\n", + __func__, kref_read(&dev->count)); spin_lock_init(&dev->lock); init_completion(&dev->ep0_done); raw_event_queue_init(&dev->queue); @@ -464,13 +466,21 @@ static int raw_release(struct inode *inode, struct file *fd) dev_err(dev->dev, "usb_gadget_unregister_driver() failed with %d\n", ret); + dev_dbg(dev->dev, "%s kref count before unregister driver put: %d\n", + __func__, kref_read(&dev->count)); /* Matches kref_get() in raw_ioctl_run(). */ kref_put(&dev->count, dev_free); + dev_dbg(dev->dev, "%s kref count after unregister driver put: %d\n", + __func__, kref_read(&dev->count)); } out_put: + dev_dbg(dev->dev, "%s kref count before final put: %d\n", + __func__, kref_read(&dev->count)); /* Matches dev_new() in raw_open(). */ kref_put(&dev->count, dev_free); + dev_dbg(dev->dev, "%s kref count after final put: %d\n", + __func__, kref_read(&dev->count)); return ret; } @@ -603,8 +613,12 @@ static int raw_ioctl_run(struct raw_dev *dev, unsigned long value) } dev->gadget_registered = true; dev->state = STATE_DEV_RUNNING; + dev_dbg(dev->dev, "%s kref count before get: %d\n", + __func__, kref_read(&dev->count)); /* Matches kref_put() in raw_release(). */ kref_get(&dev->count); + dev_dbg(dev->dev, "%s kref count after get: %d\n", + __func__, kref_read(&dev->count)); out_unlock: spin_unlock_irqrestore(&dev->lock, flags);
syzkaller reported a double free bug (https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c) in raw_release. From the stack traces it looks like either raw_release was invoked twice or there were some between kref_get in raw_ioctl_run and kref_put raw_release. But these should not be possible. We need more logs to understand the cause. Make raw_release and raw_ioctl_run report the ref count before and after get/put to help debug this. Signed-off-by: Chang Yu <marcus.yu.56@gmail.com> Reported-by: syzbot+3e563d99e70973c0755c@syzkaller.appspotmail.com Link: https://syzkaller.appspot.com/bug?extid=3e563d99e70973c0755c --- drivers/usb/gadget/legacy/raw_gadget.c | 14 ++++++++++++++ 1 file changed, 14 insertions(+)