Re: INFO: rcu detected stall in vprintk_func
On (04/02/18 10:54), Sergey Senozhatsky wrote:
> > > If you forward the report, please keep this part and the footer.
> > >
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
[..]
> diff --git a/net/nfc/llcp_core.c b/net/nfc/llcp_core.c
> index ef4026a23e80..a309a27581da 100644
> --- a/net/nfc/llcp_core.c
> +++ b/net/nfc/llcp_core.c
> @@ -1386,7 +1386,7 @@ static void nfc_llcp_recv_agf(struct nfc_llcp_local
> *local, struct sk_buff *skb)
>
> new_skb = nfc_alloc_recv_skb(pdu_len, GFP_KERNEL);
> if (new_skb == NULL) {
> - pr_err("Could not allocate PDU\n");
> + pr_err_ratelimited("Could not allocate PDU\n");
> return;
> }
And of course I ended up patching the wrong function...
What I actually meant was:
---
diff --git a/net/nfc/llcp_commands.c b/net/nfc/llcp_commands.c
index 2ceefa183cee..2f3becb709b8 100644
--- a/net/nfc/llcp_commands.c
+++ b/net/nfc/llcp_commands.c
@@ -755,7 +755,7 @@ int nfc_llcp_send_ui_frame(struct nfc_llcp_sock *sock, u8
ssap, u8 dsap,
pdu = nfc_alloc_send_skb(sock->dev, &sock->sk, MSG_DONTWAIT,
frag_len + LLCP_HEADER_SIZE, &err);
if (pdu == NULL) {
- pr_err("Could not allocate PDU\n");
+ pr_err_ratelimited("Could not allocate PDU\n");
continue;
}
Re: INFO: rcu detected stall in vprintk_func
On (04/01/18 12:51), Dmitry Vyukov wrote:
[..]
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: syzbot+3f28bd18291266ec8...@syzkaller.appspotmail.com
> > It will help syzbot understand when the bug is fixed. See footer for
> > details.
> > If you forward the report, please keep this part and the footer.
> >
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
> > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
Yes, this thing
do {
remote_miu = sock->remote_miu > LLCP_MAX_MIU ?
local->remote_miu : sock->remote_miu;
frag_len = min_t(size_t, remote_miu, remaining_len);
pr_debug("Fragment %zd bytes remaining %zd",
frag_len, remaining_len);
pdu = nfc_alloc_send_skb(sock->dev, &sock->sk, MSG_DONTWAIT,
frag_len + LLCP_HEADER_SIZE, &err);
if (pdu == NULL) {
pr_err("Could not allocate PDU\n");
continue;
}
is basically
do {
pr_err("Could not allocate PDU\n");
} while (1)
Can cause problems sometimes. But this loop is a bit worrisome
even without the printk() call.
>From printk() side, we only can do rate limiting here. Would be
great if nfc maintainers could take a look and tweak the loop
maybe.
---
diff --git a/net/nfc/llcp_core.c b/net/nfc/llcp_core.c
index ef4026a23e80..a309a27581da 100644
--- a/net/nfc/llcp_core.c
+++ b/net/nfc/llcp_core.c
@@ -1386,7 +1386,7 @@ static void nfc_llcp_recv_agf(struct nfc_llcp_local
*local, struct sk_buff *skb)
new_skb = nfc_alloc_recv_skb(pdu_len, GFP_KERNEL);
if (new_skb == NULL) {
- pr_err("Could not allocate PDU\n");
+ pr_err_ratelimited("Could not allocate PDU\n");
return;
}
Re: INFO: rcu detected stall in vprintk_func
On Sun, Apr 1, 2018 at 12:49 PM, syzbot wrote: > Hello, > > syzbot hit the following crash on upstream commit > 3eb2ce825ea1ad89d20f7a3b5780df850e4be274 (Sun Mar 25 22:44:30 2018 +) > Linux 4.16-rc7 > syzbot dashboard link: > https://syzkaller.appspot.com/bug?extid=3f28bd18291266ec826b > > Unfortunately, I don't have any reproducer for this crash yet. > Raw console output: > https://syzkaller.appspot.com/x/log.txt?id=4815791329378304 > Kernel config: > https://syzkaller.appspot.com/x/.config?id=-2340295454854568752 > compiler: gcc (GCC) 7.1.1 20170620 The problem seems to be in nfc, so +nfc maintainers. > IMPORTANT: if you fix the bug, please add the following tag to the commit: > Reported-by: syzbot+3f28bd18291266ec8...@syzkaller.appspotmail.com > It will help syzbot understand when the bug is fixed. See footer for > details. > If you forward the report, please keep this part and the footer. > > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > INFO: rcu_sched detected stalls on CPUs/tasks: > (detected by 1, t=125006 jiffies, g=23111, c=23110, q=45) > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > syz-executor1 R running task24512 13655 4242 0x0008 > Call Trace: > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > print_other_cpu_stall+0x996/0x1090 kernel/rcu/tree.c:1480 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > check_cpu_stall.isra.61+0x6e6/0x15b0 kernel/rcu/tree.c:1598 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > update_process_times+0x30/0x60 kernel/time/timer.c:1636 > tick_sched_timer+0x42/0x120 kernel/time/tick-sched.c:1194 > __run_hrtimer kernel/time/hrtimer.c:1349 [inline] > __hrtimer_run_queues+0x39c/0xec0 kernel/time/hrtimer.c:1411 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > hrtimer_interrupt+0x2a5/0x6f0 kernel/time/hrtimer.c:1469 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:857 > RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:778 > [inline] > RIP: 0010:console_unlock+0xd98/0xfb0 kernel/printk/printk.c:2399 > RAX: 0001 RBX: 0200 RCX: 815a8fef > RDX: 0001 RSI: c90004937000 RDI: 0246 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > R10: R11: R12: dc00 > R13: R14: 83ba1660 R15: dc00 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > vprintk_func+0x57/0xc0 kernel/printk/printk_safe.c:379 > printk+0xaa/0xca kernel/printk/printk.c:1980 > nfc_llcp_send_ui_frame+0x430/0x4e0 net/nfc/llcp_commands.c:758 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > __sys_sendmmsg+0x1ee/0x620 net/socket.c:2136 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > SYSC_sendmmsg net/socket.c:2167 [inline] > SyS_sendmmsg+0x35/0x60 net/socket.c:2162 > do_syscall_64+0x281/0x940 arch/x86/entry/common.c:287 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > entry_SYSCALL_64_after_hwframe+0x42/0xb7 > RSP: 002b:7fdb811c4c68 EFLAGS: 0246 ORIG_RAX: 0133 > RAX: ffda RBX: 7fdb811c56d4 RCX: 00454879 > RBP: 0072bea0 R08: R09: > R10: R11: 0246 R12: > R13: 04c0 R14: 006f82a0 R15: > rcu_sched kthread starved for 125907 jiffies! g23111 c23110 f0x2 > RCU_GP_WAIT_FQS(3) ->state=0x0 ->cpu=1 > llcp: nfc_llcp_send_ui_frame: Could not allocate PDU > rcu_sched R running task23448 8 2 0x8000 > context_switch kernel/sched/core.c:2862 [inline] > __schedule+0x8fb/0x1ec0 kernel/sched/core.c:3440 > llcp: nfc_llcp_send_
