INFO: trying to register non-static key in del_timer_sync (2)

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: 9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree: https://github.com/google/kasan/tree/usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=14793fa7200000
kernel config: https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
dashboard link: https://syzkaller.appspot.com/bug?extid=dc4127f950da51639216
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=16f8c22d200000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=16eeadbb200000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+dc4127...@syzkaller.appspotmail.com

usb 1-1: string descriptor 0 read error: -71
usb 1-1: USB disconnect, device number 2
usb 1-1: Direct firmware load for mrvl/usb8801_uapsta.bin failed with error
-2
usb 1-1: Failed to get firmware mrvl/usb8801_uapsta.bin
usb 1-1: info: _mwifiex_fw_dpc: unregister device
INFO: trying to register non-static key.
the code is fine but needs lockdep annotation.
turning off the locking correctness validator.
CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 5.1.0-rc4-319354-g9a33b36 #3
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: events request_firmware_work_func
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0xe8/0x16e lib/dump_stack.c:113
assign_lock_key kernel/locking/lockdep.c:786 [inline]
register_lock_class+0x11b8/0x1250 kernel/locking/lockdep.c:1095
__lock_acquire+0xfb/0x37c0 kernel/locking/lockdep.c:3582
lock_acquire+0x10d/0x2f0 kernel/locking/lockdep.c:4211
del_timer_sync+0x4c/0x150 kernel/time/timer.c:1282
mwifiex_usb_cleanup_tx_aggr
drivers/net/wireless/marvell/mwifiex/usb.c:1358 [inline]
mwifiex_unregister_dev+0x41b/0x690
drivers/net/wireless/marvell/mwifiex/usb.c:1370
_mwifiex_fw_dpc+0x711/0xdd0 drivers/net/wireless/marvell/mwifiex/main.c:651
request_firmware_work_func+0x12d/0x249
drivers/base/firmware_loader/main.c:785
process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
kthread+0x313/0x420 kernel/kthread.c:253
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
------------[ cut here ]------------
ODEBUG: assert_init not available (active state 0) object type: timer_list
hint: (null)
WARNING: CPU: 0 PID: 12 at lib/debugobjects.c:325
debug_print_object+0x162/0x250 lib/debugobjects.c:325
Kernel panic - not syncing: panic_on_warn set ...
CPU: 0 PID: 12 Comm: kworker/0:1 Not tainted 5.1.0-rc4-319354-g9a33b36 #3
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: events request_firmware_work_func
Call Trace:
__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0xe8/0x16e lib/dump_stack.c:113
panic+0x29d/0x5f2 kernel/panic.c:214
__warn.cold+0x20/0x48 kernel/panic.c:571
report_bug+0x262/0x2a0 lib/bug.c:186
fixup_bug arch/x86/kernel/traps.c:179 [inline]
fixup_bug arch/x86/kernel/traps.c:174 [inline]
do_error_trap+0x130/0x1f0 arch/x86/kernel/traps.c:272
do_invalid_op+0x37/0x40 arch/x86/kernel/traps.c:291
invalid_op+0x14/0x20 arch/x86/entry/entry_64.S:973
RIP: 0010:debug_print_object+0x162/0x250 lib/debugobjects.c:325
Code: dd e0 a1 b3 8e 48 89 fa 48 c1 ea 03 80 3c 02 00 0f 85 bf 00 00 00 48
8b 14 dd e0 a1 b3 8e 48 c7 c7 60 96 b3 8e e8 8e 93 d2 fd <0f> 0b 83 05 e9
d6 59 10 01 48 83 c4 20 5b 5d 41 5c 41 5d c3 48 89
RSP: 0018:ffff8880a84b78d8 EFLAGS: 00010286
RAX: 0000000000000000 RBX: 0000000000000005 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff815b1e42 RDI: ffffed1015096f0d
RBP: 0000000000000001 R08: ffff8880a849b100 R09: fffffbfff22f95ed
R10: fffffbfff22f95ec R11: ffffffff917caf63 R12: ffffffff917e7780
R13: ffffffff8161ec90 R14: 1ffff11015096f28 R15: ffff88809fc893f8
debug_object_assert_init lib/debugobjects.c:694 [inline]
debug_object_assert_init+0x23d/0x2f0 lib/debugobjects.c:665
debug_timer_assert_init kernel/time/timer.c:723 [inline]
debug_assert_init kernel/time/timer.c:775 [inline]
try_to_del_timer_sync+0x72/0x110 kernel/time/timer.c:1222
del_timer_sync+0x112/0x150 kernel/time/timer.c:1292
mwifiex_usb_cleanup_tx_aggr
drivers/net/wireless/marvell/mwifiex/usb.c:1358 [inline]
mwifiex_unregister_dev+0x41b/0x690
drivers/net/wireless/marvell/mwifiex/usb.c:1370
_mwifiex_fw_dpc+0x711/0xdd0 drivers/net/wireless/marvell/mwifiex/main.c:651
request_firmware_work_func+0x12d/0x249
drivers/base/firmware_loader/main.c:785
process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
kthread+0x313/0x420 kernel/kthread.c:253
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Kernel Offset: disabled
Rebooting in 86400 seconds..


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches

[Ganapathi Bhat]

Hi syzbot,

>
> syzbot found the following crash on:
>

As per the link(https://syzkaller.appspot.com/bug?extid=dc4127f950da51639216), the issue is fixed; Is it OK? Let us know if we need to do something?

Regards,
Ganapathi

[Dmitry Vyukov]

Hi Ganapathi,

The "fixed" status relates to the similar past bug that was reported
and fixed more than a year ago:
https://groups.google.com/forum/#!msg/syzkaller-bugs/3YnGX1chF2w/jeQjeihtBAAJ
https://syzkaller.appspot.com/bug?id=b4b5c74c57c4b69f4fff86131abb799106182749

This one is still well alive and kicking, with 1200+ crashes and the
last one happened less then 30min ago.

[Ganapathi Bhat]

Hi Dmitry,

> The "fixed" status relates to the similar past bug that was reported and fixed
> more than a year ago:

Oh OK; We understood the issue, working on a change to fix this;

Thanks,
Ganapathi

[Ganapathi Bhat]

Hi Dmitry,

We have a patch to fix this: https://patchwork.kernel.org/patch/10990275/

Regards,
Ganapathi

[Andrey Konovalov]

On Wed, Jun 12, 2019 at 6:03 PM Ganapathi Bhat <gb...@marvell.com> wrote:
>
> Hi Dmitry,
>
> We have a patch to fix this: https://patchwork.kernel.org/patch/10990275/

Hi Ganapathi,

Great, thanks for working on this!

We can ask syzbot to test the fix:

#syz test: https://github.com/google/kasan.git usb-fuzzer

Thanks!

>
> Regards,
> Ganapathi

[syzbot]

Hello,

syzbot has tested the proposed patch and the reproducer did not trigger
crash:

Reported-and-tested-by:
syzbot+dc4127...@syzkaller.appspotmail.com

Tested on:

commit: 69bbe8c7 usb-fuzzer: main usb gadget fuzzer driver
git tree: https://github.com/google/kasan.git usb-fuzzer
kernel config: https://syzkaller.appspot.com/x/.config?x=39290eb0151bec39

compiler: gcc (GCC) 9.0.0 20181231 (experimental)

patch: https://syzkaller.appspot.com/x/patch.diff?x=14171fd2a00000

Note: testing is done by a robot and is best-effort only.

[Andrey Konovalov]

On Wed, Jun 12, 2019 at 6:03 PM Ganapathi Bhat <gb...@marvell.com> wrote:
>
> Hi Dmitry,
>
> We have a patch to fix this: https://patchwork.kernel.org/patch/10990275/

Hi Ganapathi,

Has this patch been accepted anywhere? This bug is still open on syzbot.

Thanks!

[Kalle Valo]

The patch is in "Changes Requested" state which means that the author is
supposed to send a new version based on the review comments.

--
https://wireless.wiki.kernel.org/en/developers/documentation/submittingpatches

[Ganapathi Bhat]

Hi Dmitry/Kalle,

> >>
> >> Hi Dmitry,
> >>
> >> We have a patch to fix this:
> >> https://patchwork.kernel.org/patch/10990275/
> >
> > Hi Ganapathi,
> >
> > Has this patch been accepted anywhere? This bug is still open on syzbot.
>
> The patch is in "Changes Requested" state which means that the author is
> supposed to send a new version based on the review comments.

We will address the review comments and try to push the updated version soon;

Regards,
Ganapathi

[Andrey Konovalov]

Hi Ganapathi,

I was wondering if you've posted the updated version of the fix?

Thanks!

[Ganapathi Bhat]

Hi Andy,

> I was wondering if you've posted the updated version of the fix?

Sorry for the delay; I have started addressing the comment from community; It should be done in couple of days;
Regards,
Ganapathi

[Tetsuo Handa]

syzbot is reporting that del_timer_sync() is called from
mwifiex_usb_cleanup_tx_aggr() from mwifiex_unregister_dev() without
checking timer_setup() from mwifiex_usb_tx_init() was called [1].
Since mwifiex_usb_prepare_tx_aggr_skb() is calling del_timer() if
is_hold_timer_set == true, use the same condition for del_timer_sync().

[1] https://syzkaller.appspot.com/bug?id=fdeef9cf7348be8b8ab5b847f2ed993aba8ea7b6

Reported-by: syzbot <syzbot+373e67...@syzkaller.appspotmail.com>
Cc: Ganapathi Bhat <gb...@marvell.com>
Signed-off-by: Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp>
---
A patch from Ganapathi Bhat ( https://patchwork.kernel.org/patch/10990275/ ) is stalling
at https://lore.kernel.org/linux-usb/MN2PR18MB2637D7C742...@MN2PR18MB2637.namprd18.prod.outlook.com/ .
syzbot by now got this report for 10000 times. Do we want to go with this simple patch?

drivers/net/wireless/marvell/mwifiex/usb.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/drivers/net/wireless/marvell/mwifiex/usb.c b/drivers/net/wireless/marvell/mwifiex/usb.c
index 6f3cfde..04a1461 100644
--- a/drivers/net/wireless/marvell/mwifiex/usb.c
+++ b/drivers/net/wireless/marvell/mwifiex/usb.c
@@ -1353,7 +1353,8 @@ static void mwifiex_usb_cleanup_tx_aggr(struct mwifiex_adapter *adapter)
skb_dequeue(&port->tx_aggr.aggr_list)))
mwifiex_write_data_complete(adapter, skb_tmp,
0, -1);
- del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);
+ if (port->tx_aggr.timer_cnxt.is_hold_timer_set)
+ del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);
port->tx_aggr.timer_cnxt.is_hold_timer_set = false;
port->tx_aggr.timer_cnxt.hold_tmo_msecs = 0;
}
--
1.8.3.1

[Andy Shevchenko]

On Tue, Jul 28, 2020 at 4:46 AM Tetsuo Handa
<penguin...@i-love.sakura.ne.jp> wrote:
>
> syzbot is reporting that del_timer_sync() is called from
> mwifiex_usb_cleanup_tx_aggr() from mwifiex_unregister_dev() without
> checking timer_setup() from mwifiex_usb_tx_init() was called [1].
> Since mwifiex_usb_prepare_tx_aggr_skb() is calling del_timer() if
> is_hold_timer_set == true, use the same condition for del_timer_sync().
>
> [1] https://syzkaller.appspot.com/bug?id=fdeef9cf7348be8b8ab5b847f2ed993aba8ea7b6
>

Can you use BugLink: tag for above?

> Reported-by: syzbot <syzbot+373e67...@syzkaller.appspotmail.com>
> Cc: Ganapathi Bhat <gb...@marvell.com>
> Signed-off-by: Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp>
> ---
> A patch from Ganapathi Bhat ( https://patchwork.kernel.org/patch/10990275/ ) is stalling
> at https://lore.kernel.org/linux-usb/MN2PR18MB2637D7C742...@MN2PR18MB2637.namprd18.prod.outlook.com/ .
> syzbot by now got this report for 10000 times. Do we want to go with this simple patch?
>
> drivers/net/wireless/marvell/mwifiex/usb.c | 3 ++-
> 1 file changed, 2 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/net/wireless/marvell/mwifiex/usb.c b/drivers/net/wireless/marvell/mwifiex/usb.c
> index 6f3cfde..04a1461 100644
> --- a/drivers/net/wireless/marvell/mwifiex/usb.c
> +++ b/drivers/net/wireless/marvell/mwifiex/usb.c
> @@ -1353,7 +1353,8 @@ static void mwifiex_usb_cleanup_tx_aggr(struct mwifiex_adapter *adapter)
> skb_dequeue(&port->tx_aggr.aggr_list)))
> mwifiex_write_data_complete(adapter, skb_tmp,
> 0, -1);
> - del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);
> + if (port->tx_aggr.timer_cnxt.is_hold_timer_set)
> + del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);
> port->tx_aggr.timer_cnxt.is_hold_timer_set = false;
> port->tx_aggr.timer_cnxt.hold_tmo_msecs = 0;
> }
> --
> 1.8.3.1
>

--
With Best Regards,
Andy Shevchenko

[Brian Norris]

Hi,

On Mon, Jul 27, 2020 at 6:45 PM Tetsuo Handa
<penguin...@i-love.sakura.ne.jp> wrote:
>
> syzbot is reporting that del_timer_sync() is called from
> mwifiex_usb_cleanup_tx_aggr() from mwifiex_unregister_dev() without
> checking timer_setup() from mwifiex_usb_tx_init() was called [1].
> Since mwifiex_usb_prepare_tx_aggr_skb() is calling del_timer() if
> is_hold_timer_set == true, use the same condition for del_timer_sync().
>
> [1] https://syzkaller.appspot.com/bug?id=fdeef9cf7348be8b8ab5b847f2ed993aba8ea7b6
>
> Reported-by: syzbot <syzbot+373e67...@syzkaller.appspotmail.com>
> Cc: Ganapathi Bhat <gb...@marvell.com>
> Signed-off-by: Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp>
> ---
> A patch from Ganapathi Bhat ( https://patchwork.kernel.org/patch/10990275/ ) is stalling
> at https://lore.kernel.org/linux-usb/MN2PR18MB2637D7C742...@MN2PR18MB2637.namprd18.prod.outlook.com/ .
> syzbot by now got this report for 10000 times. Do we want to go with this simple patch?

Sorry, that stall is partly my fault, and partly Ganapathi's. It
doesn't help that it took him 4 months to reply to my questions, so I
completely lost even the tiny bit of context I had managed to build up
in my head at initial review time... and so it's still buried in the
dark corners of my inbox. (I think I'll go archive that now, because
it really deserves a better sell than it had initially, if Ganapathi
really wants to land it.)

> drivers/net/wireless/marvell/mwifiex/usb.c | 3 ++-
> 1 file changed, 2 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/net/wireless/marvell/mwifiex/usb.c b/drivers/net/wireless/marvell/mwifiex/usb.c
> index 6f3cfde..04a1461 100644
> --- a/drivers/net/wireless/marvell/mwifiex/usb.c
> +++ b/drivers/net/wireless/marvell/mwifiex/usb.c
> @@ -1353,7 +1353,8 @@ static void mwifiex_usb_cleanup_tx_aggr(struct mwifiex_adapter *adapter)
> skb_dequeue(&port->tx_aggr.aggr_list)))
> mwifiex_write_data_complete(adapter, skb_tmp,
> 0, -1);
> - del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);
> + if (port->tx_aggr.timer_cnxt.is_hold_timer_set)

I believe if we ever actually started aggregation, then the timer can
be active at this point, and thus, the access to 'is_hold_timer_set'
is racy.

This *probably* deserves a better refactor, but in absence of that
(and a better explanation than Ganapathi gave), I think you at least
need to hold port->tx_aggr_lock. So perhaps (totally untested):

spin_lock_bh(&port->tx_aggr_lock);
if (port->tx_aggr.timer_cnxt.is_hold_timer_set) {
port->tx_aggr.timer_cnxt.is_hold_timer_set = false;
spin_unlock_bh(&port->tx_aggr_lock);
/* Timer could still be running, but it can't be restarted at this
point, so this is safe. */
del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);
} else {
spin_unlock_bh(&port->tx_aggr_lock);
}

Otherwise, I think this is fine:

Reviewed-by: Brian Norris <brian...@chromium.org>

I also believe mwifiex_usb_prepare_tx_aggr_skb() needs to stop using
del_timer() (without the _sync()), because otherwise we might have
deactivated the timer already but not ensured that it has completely
finished executing on other CPUs. But that is probably orthogonal to
the current patch. (Again, so much in this driver needs refactoring.)

Side note: this entire TX aggregation feature for USB has been hidden
behind the mwifiex.aggr_ctrl module param since its introduction,
which has always been disabled by default. I wonder whether anybody is
*really* testing it, or whether it's 100% broken, as with many things
in this driver...


Brian

[Brian Norris]

On Fri, Aug 21, 2020 at 1:28 AM Tetsuo Handa

<penguin...@i-love.sakura.ne.jp> wrote:
>
> syzbot is reporting that del_timer_sync() is called from
> mwifiex_usb_cleanup_tx_aggr() from mwifiex_unregister_dev() without
> checking timer_setup() from mwifiex_usb_tx_init() was called [1].
>

> Ganapathi Bhat proposed a possibly cleaner fix, but it seems that
> that fix was forgotten [2].
>
> "grep -FrB1 'del_timer' drivers/ | grep -FA1 '.function)'" says that
> currently there are 28 locations which call del_timer[_sync]() only if
> that timer's function field was initialized (because timer_setup() sets
> that timer's function field). Therefore, let's use same approach here.
>
> [1] https://syzkaller.appspot.com/bug?id=26525f643f454dd7be0078423e3cdb0d57744959
> [2] https://lkml.kernel.org/r/CA+ASDXMHt2gq9Hy+iP_BYkWX...@mail.gmail.com
>
> Reported-by: syzbot <syzbot+dc4127...@syzkaller.appspotmail.com>
> Cc: Ganapathi Bhat <ganapat...@nxp.com>
> Cc: Brian Norris <brian...@chromium.org>
> Signed-off-by: Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp>

This seems good to me:

Reviewed-by: Brian Norris <brian...@chromium.org>

> ---

> drivers/net/wireless/marvell/mwifiex/usb.c | 3 ++-
> 1 file changed, 2 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/net/wireless/marvell/mwifiex/usb.c b/drivers/net/wireless/marvell/mwifiex/usb.c

> index 6f3cfde4654c..426e39d4ccf0 100644

> --- a/drivers/net/wireless/marvell/mwifiex/usb.c
> +++ b/drivers/net/wireless/marvell/mwifiex/usb.c
> @@ -1353,7 +1353,8 @@ static void mwifiex_usb_cleanup_tx_aggr(struct mwifiex_adapter *adapter)
> skb_dequeue(&port->tx_aggr.aggr_list)))
> mwifiex_write_data_complete(adapter, skb_tmp,
> 0, -1);
> - del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);

> + if (port->tx_aggr.timer_cnxt.hold_timer.function)

> + del_timer_sync(&port->tx_aggr.timer_cnxt.hold_timer);
> port->tx_aggr.timer_cnxt.is_hold_timer_set = false;
> port->tx_aggr.timer_cnxt.hold_tmo_msecs = 0;
> }
> --

> 2.18.4
>

[Ganapathi Bhat]

Hi Tetsuo,

> > "grep -FrB1 'del_timer' drivers/ | grep -FA1 '.function)'" says that
> > currently there are 28 locations which call del_timer[_sync]() only if
> > that timer's function field was initialized (because timer_setup()
> > sets that timer's function field). Therefore, let's use same approach here.

Thanks for the change, it look cleaner than my re-work;

Acked-by: Ganapathi Bhat <ganapat...@nxp.com>

Regards,
Ganapathi

[Kalle Valo]

Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp> wrote:

> syzbot is reporting that del_timer_sync() is called from
> mwifiex_usb_cleanup_tx_aggr() from mwifiex_unregister_dev() without
> checking timer_setup() from mwifiex_usb_tx_init() was called [1].
>
> Ganapathi Bhat proposed a possibly cleaner fix, but it seems that
> that fix was forgotten [2].
>

> "grep -FrB1 'del_timer' drivers/ | grep -FA1 '.function)'" says that
> currently there are 28 locations which call del_timer[_sync]() only if
> that timer's function field was initialized (because timer_setup() sets
> that timer's function field). Therefore, let's use same approach here.
>

> [1] https://syzkaller.appspot.com/bug?id=26525f643f454dd7be0078423e3cdb0d57744959
> [2] https://lkml.kernel.org/r/CA+ASDXMHt2gq9Hy+iP_BYkWX...@mail.gmail.com
>
> Reported-by: syzbot <syzbot+dc4127...@syzkaller.appspotmail.com>
> Cc: Ganapathi Bhat <ganapat...@nxp.com>
> Cc: Brian Norris <brian...@chromium.org>
> Signed-off-by: Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp>

> Reviewed-by: Brian Norris <brian...@chromium.org>
> Acked-by: Ganapathi Bhat <ganapat...@nxp.com>

Patch applied to wireless-drivers-next.git, thanks.

621a3a8b1c0e mwifiex: don't call del_timer_sync() on uninitialized timer

--
https://patchwork.kernel.org/patch/11728607/

https://wireless.wiki.kernel.org/en/developers/documentation/submittingpatches