[syzbot] [wireless?] WARNING in kcov_remote_start (3)

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: a6bd6c933339 Add linux-next specific files for 20240328
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=15c85eb1180000
kernel config: https://syzkaller.appspot.com/x/.config?x=b0058bda1436e073
dashboard link: https://syzkaller.appspot.com/bug?extid=0438378d6f157baae1a2
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/7c1618ff7d25/disk-a6bd6c93.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/875519f620fe/vmlinux-a6bd6c93.xz
kernel image: https://storage.googleapis.com/syzbot-assets/ad92b057fb96/bzImage-a6bd6c93.xz

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

------------[ cut here ]------------
WARNING: CPU: 1 PID: 2400 at kernel/kcov.c:860 kcov_remote_start+0x549/0x7e0 kernel/kcov.c:860
Modules linked in:
CPU: 1 PID: 2400 Comm: kworker/u8:7 Not tainted 6.9.0-rc1-next-20240328-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 02/29/2024
Workqueue: events_unbound cfg80211_wiphy_work
RIP: 0010:kcov_remote_start+0x549/0x7e0 kernel/kcov.c:860
Code: 4c 89 ff be 03 00 00 00 e8 14 99 16 03 e9 fd fa ff ff e8 8a 26 ea 09 41 f7 c6 00 02 00 00 0f 84 eb fa ff ff e9 7f fc ff ff 90 <0f> 0b 90 e8 8f 43 ea 09 89 c0 48 c7 c7 c8 d4 02 00 48 03 3c c5 d0
RSP: 0018:ffffc90009b17aa8 EFLAGS: 00010002
RAX: 0000000080000000 RBX: ffff888029649e00 RCX: 0000000000000002
RDX: dffffc0000000000 RSI: ffffffff8bcae740 RDI: ffffffff8c1f77c0
RBP: 0000000000000000 R08: ffffffff92f3358f R09: 1ffffffff25e66b1
R10: dffffc0000000000 R11: fffffbfff25e66b2 R12: ffffffff8195747e
R13: ffff88807c8cd748 R14: 0000000000000246 R15: ffff8880b952d4c8
FS: 0000000000000000(0000) GS:ffff8880b9500000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fc66d258d58 CR3: 00000000222ca000 CR4: 00000000003506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
kcov_remote_start_common include/linux/kcov.h:48 [inline]
ieee80211_iface_work+0x21f/0xf10 net/mac80211/iface.c:1654
cfg80211_wiphy_work+0x221/0x260 net/wireless/core.c:437
process_one_work kernel/workqueue.c:3218 [inline]
process_scheduled_works+0xa2c/0x1830 kernel/workqueue.c:3299
worker_thread+0x86d/0xd70 kernel/workqueue.c:3380
kthread+0x2f0/0x390 kernel/kthread.c:388
ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:243
</TASK>


---
This report 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 issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

If the report is already addressed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to overwrite report's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the report is a duplicate of another one, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

[Johannes Berg]

On Thu, 2024-03-28 at 04:00 -0700, syzbot wrote:
>
> ------------[ cut here ]------------
> WARNING: CPU: 1 PID: 2400 at kernel/kcov.c:860 kcov_remote_start+0x549/0x7e0 kernel/kcov.c:860

This is

/*
* Check that kcov_remote_start() is not called twice in background
* threads nor called by user tasks (with enabled kcov).
*/
mode = READ_ONCE(t->kcov_mode);
if (WARN_ON(in_task() && kcov_mode_enabled(mode))) {
local_unlock_irqrestore(&kcov_percpu_data.lock, flags);
return;
}

but I have no idea what that even means?

> Workqueue: events_unbound cfg80211_wiphy_work
> RIP: 0010:kcov_remote_start+0x549/0x7e0 kernel/kcov.c:860

...

> Call Trace:
> <TASK>
> kcov_remote_start_common include/linux/kcov.h:48 [inline]
> ieee80211_iface_work+0x21f/0xf10 net/mac80211/iface.c:1654
> cfg80211_wiphy_work+0x221/0x260 net/wireless/core.c:437
> process_one_work kernel/workqueue.c:3218 [inline]
> process_scheduled_works+0xa2c/0x1830 kernel/workqueue.c:3299
> worker_thread+0x86d/0xd70 kernel/workqueue.c:3380

It's a worker thread. Was this not intended to be called in threads?

johannes

[Andrey Konovalov]

I think the problem is that the KCOV annotations in the NFC code are
buggy: kcov_remote_stop() is never called if the loop in nci_rx_work()
exits on one of the breaks. With the recent addition of the nci_plen()
check, this started happening often. But breaks existed in the loop
before that too.

We need to move kcov_remote_stop() into the loop and call it every
time the loop exits.

Dmitry, could you PTAL and confirm this? You added the annotation for
NFC, AFAICS.

Thanks!

[Tetsuo Handa]

Commit 7e8cdc97148c ("nfc: Add KCOV annotations") added
kcov_remote_start_common()/kcov_remote_stop() pair into nci_rx_work(),
with an assumption that kcov_remote_stop() is called upon continue of
the for loop. But commit d24b03535e5e ("nfc: nci: Fix uninit-value in
nci_dev_up and nci_ntf_packet") forgot to call kcov_remote_stop() before
break of the for loop.

Reported-by: syzbot <syzbot+043837...@syzkaller.appspotmail.com>
Closes: https://syzkaller.appspot.com/bug?extid=0438378d6f157baae1a2
Fixes: d24b03535e5e ("nfc: nci: Fix uninit-value in nci_dev_up and nci_ntf_packet")
Debugged-by: Andrey Konovalov <andre...@gmail.com>
Signed-off-by: Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp>
---
net/nfc/nci/core.c | 1 +
1 file changed, 1 insertion(+)

diff --git a/net/nfc/nci/core.c b/net/nfc/nci/core.c
index 0d26c8ec9993..b133dc55304c 100644
--- a/net/nfc/nci/core.c
+++ b/net/nfc/nci/core.c
@@ -1518,6 +1518,7 @@ static void nci_rx_work(struct work_struct *work)

if (!nci_plen(skb->data)) {
kfree_skb(skb);
+ kcov_remote_stop();
break;
}

--
2.34.1

[Krzysztof Kozlowski]

On 05/05/2024 12:36, Tetsuo Handa wrote:
> Commit 7e8cdc97148c ("nfc: Add KCOV annotations") added
> kcov_remote_start_common()/kcov_remote_stop() pair into nci_rx_work(),
> with an assumption that kcov_remote_stop() is called upon continue of
> the for loop. But commit d24b03535e5e ("nfc: nci: Fix uninit-value in
> nci_dev_up and nci_ntf_packet") forgot to call kcov_remote_stop() before
> break of the for loop.
>
> Reported-by: syzbot <syzbot+043837...@syzkaller.appspotmail.com>
> Closes: https://syzkaller.appspot.com/bug?extid=0438378d6f157baae1a2
> Fixes: d24b03535e5e ("nfc: nci: Fix uninit-value in nci_dev_up and nci_ntf_packet")
> Debugged-by: Andrey Konovalov <andre...@gmail.com>
> Signed-off-by: Tetsuo Handa <penguin...@I-love.SAKURA.ne.jp>

Reviewed-by: Krzysztof Kozlowski <krzysztof...@linaro.org>

Best regards,
Krzysztof

[patchwork-b...@kernel.org]

Hello:

This patch was applied to netdev/net.git (main)
by Jakub Kicinski <ku...@kernel.org>:

On Sun, 5 May 2024 19:36:49 +0900 you wrote:
> Commit 7e8cdc97148c ("nfc: Add KCOV annotations") added
> kcov_remote_start_common()/kcov_remote_stop() pair into nci_rx_work(),
> with an assumption that kcov_remote_stop() is called upon continue of
> the for loop. But commit d24b03535e5e ("nfc: nci: Fix uninit-value in
> nci_dev_up and nci_ntf_packet") forgot to call kcov_remote_stop() before
> break of the for loop.
>

> [...]

Here is the summary with links:
- nfc: nci: Fix kcov check in nci_rx_work()
https://git.kernel.org/netdev/net/c/19e35f24750d

You are awesome, thank you!
--
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html

[Tetsuo Handa]

Hello.

syzbot is still reporting warning in kcov_remote_start() from
__usb_hcd_giveback_urb() path. I guess that commit 8fea0c8fda30
("usb: core: hcd: Convert from tasklet to BH workqueue") broke
the in_serving_softirq() workaround explained in commit e89eed02a5f1
("kcov, usb: hide in_serving_softirq checks in __usb_hcd_giveback_urb").

How can we fix this workaround?


-----------[ cut here ]------------
WARNING: CPU: 0 PID: 16 at kernel/kcov.c:870 kcov_remote_start+0x5a2/0x7e0 kernel/kcov.c:870
Modules linked in:
CPU: 0 PID: 16 Comm: ksoftirqd/0 Not tainted 6.9.0-rc7-next-20240510-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
RIP: 0010:kcov_remote_start+0x5a2/0x7e0 kernel/kcov.c:870
Code: 24 00 00 00 00 9c 8f 04 24 f7 04 24 00 02 00 00 0f 85 a6 01 00 00 41 f7 c6 00 02 00 00 0f 84 93 fa ff ff fb e9 8d fa ff ff 90 <0f> 0b 90 e8 26 71 f4 09 89 c0 48 c7 c7 c8 d4 02 00 48 03 3c c5 e0
RSP: 0018:ffffc900000079c0 EFLAGS: 00010002
RAX: 0000000080010101 RBX: ffff8880172cda00 RCX: 0000000000000002
RDX: dffffc0000000000 RSI: ffffffff8bcac680 RDI: ffffffff8c1fdcc0
RBP: 0100000000000004 R08: ffffffff92fb25f7 R09: 1ffffffff25f64be
R10: dffffc0000000000 R11: fffffbfff25f64bf R12: ffffffff8196262e
R13: 00000000ffffffb9 R14: 0000000000000006 R15: ffff8880b942d4c8
FS: 0000000000000000(0000) GS:ffff8880b9400000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00007f3793bff800 CR3: 000000001eccc000 CR4: 00000000003506f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:

<IRQ>
kcov_remote_start_usb include/linux/kcov.h:53 [inline]
kcov_remote_start_usb_softirq include/linux/kcov.h:66 [inline]
__usb_hcd_giveback_urb+0x34a/0x530 drivers/usb/core/hcd.c:1647
dummy_timer+0x830/0x45d0 drivers/usb/gadget/udc/dummy_hcd.c:1987
__run_hrtimer kernel/time/hrtimer.c:1687 [inline]
__hrtimer_run_queues+0x5a5/0xd50 kernel/time/hrtimer.c:1751
hrtimer_interrupt+0x396/0x990 kernel/time/hrtimer.c:1813
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1032 [inline]
__sysvec_apic_timer_interrupt+0x110/0x3f0 arch/x86/kernel/apic/apic.c:1049
instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1043 [inline]
sysvec_apic_timer_interrupt+0xa1/0xc0 arch/x86/kernel/apic/apic.c:1043
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:152 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0xd8/0x140 kernel/locking/spinlock.c:194
Code: 9c 8f 44 24 20 42 80 3c 23 00 74 08 4c 89 f7 e8 6e 7a 66 f6 f6 44 24 21 02 75 52 41 f7 c7 00 02 00 00 74 01 fb bf 01 00 00 00 <e8> c3 3a d0 f5 65 8b 05 34 7a 6e 74 85 c0 74 43 48 c7 04 24 0e 36
RSP: 0018:ffffc900001577c0 EFLAGS: 00000206
RAX: 51fa7c47925ba500 RBX: 1ffff9200002aefc RCX: ffffffff8172dd7a
RDX: dffffc0000000000 RSI: ffffffff8bcab500 RDI: 0000000000000001
RBP: ffffc90000157860 R08: ffffffff92fb25f7 R09: 1ffffffff25f64be
R10: dffffc0000000000 R11: fffffbfff25f64bf R12: dffffc0000000000
R13: 1ffff9200002aef8 R14: ffffc900001577e0 R15: 0000000000000246
__usb_hcd_giveback_urb+0x373/0x530 drivers/usb/core/hcd.c:1648
usb_giveback_urb_bh+0x306/0x4e0 drivers/usb/core/hcd.c:1682
process_one_work kernel/workqueue.c:3231 [inline]
process_scheduled_works+0xa2c/0x1830 kernel/workqueue.c:3312
bh_worker+0x2a5/0x620 kernel/workqueue.c:3572
tasklet_hi_action+0xf/0x90 kernel/softirq.c:816
handle_softirqs+0x2d6/0x990 kernel/softirq.c:554
run_ksoftirqd+0xca/0x130 kernel/softirq.c:928
smpboot_thread_fn+0x544/0xa30 kernel/smpboot.c:164
kthread+0x2f0/0x390 kernel/kthread.c:389
ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:147
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
</TASK>

[Dmitry Vyukov]

Missed this before somehow.
The other breaks seems to be from the switch, so should be fine:
https://elixir.bootlin.com/linux/v6.9-rc6/source/net/nfc/nci/core.c#L1528

Tetsuo, thanks for fixing it.