INFO: task hung in vhost_net_stop_vq

Hello,

syzbot found the following crash on:

HEAD commit:    ef78e5ec9214 ia64: export node_distance function
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=175c2415400000
kernel config:  https://syzkaller.appspot.com/x/.config?x=c94f9f0c0363db4b
dashboard link: https://syzkaller.appspot.com/bug?extid=d21e6e297322a900c128
compiler:       gcc (GCC) 8.0.1 20180413 (experimental)
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=141db34d400000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=108ef293400000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: <redacted>

IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): veth1: link is not ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready
IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
8021q: adding VLAN 0 to HW filter on device team0
INFO: task syz-executor251:6230 blocked for more than 140 seconds.
      Not tainted 4.20.0-rc4+ #132
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor251 D21080  6230   6229 0x80000002
Call Trace:
 context_switch kernel/sched/core.c:2831 [inline]
 __schedule+0x8cf/0x21d0 kernel/sched/core.c:3472
 schedule+0xfe/0x460 kernel/sched/core.c:3516
 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3574
 __mutex_lock_common kernel/locking/mutex.c:1002 [inline]
 __mutex_lock+0xaff/0x16f0 kernel/locking/mutex.c:1072
 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:1087
 vhost_net_stop_vq+0x2d/0x120 drivers/vhost/net.c:1306
 vhost_net_stop drivers/vhost/net.c:1320 [inline]
 vhost_net_release+0x5b/0x1d0 drivers/vhost/net.c:1352
 __fput+0x385/0xa30 fs/file_table.c:278
 ____fput+0x15/0x20 fs/file_table.c:309
 task_work_run+0x1e8/0x2a0 kernel/task_work.c:113
 exit_task_work include/linux/task_work.h:22 [inline]

98 more lines

syzbot has bisected this bug to:

commit 6b1e6cc7855b09a0a9bfa1d9f30172ba366f161c
Author: Jason Wang [off-list ref]
Date:   Thu Jun 23 06:04:32 2016 +0000

    vhost: new device IOTLB API

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1486ad27200000
start commit:   6b1e6cc7 vhost: new device IOTLB API
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=1686ad27200000
console output: https://syzkaller.appspot.com/x/log.txt?x=1286ad27200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=c94f9f0c0363db4b
dashboard link: https://syzkaller.appspot.com/bug?extid=d21e6e297322a900c128
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=141db34d400000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=108ef293400000

Reported-by: <redacted>
Fixes: 6b1e6cc7 ("vhost: new device IOTLB API")

Looks like more iotlb locking mess?

On Tue, Mar 19, 2019 at 10:21:00PM -0700, syzbot wrote:

syzbot has bisected this bug to:

commit 6b1e6cc7855b09a0a9bfa1d9f30172ba366f161c
Author: Jason Wang [off-list ref]
Date:   Thu Jun 23 06:04:32 2016 +0000

    vhost: new device IOTLB API

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1486ad27200000
start commit:   6b1e6cc7 vhost: new device IOTLB API
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=1686ad27200000
console output: https://syzkaller.appspot.com/x/log.txt?x=1286ad27200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=c94f9f0c0363db4b
dashboard link: https://syzkaller.appspot.com/bug?extid=d21e6e297322a900c128
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=141db34d400000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=108ef293400000

Reported-by: <redacted>
Fixes: 6b1e6cc7 ("vhost: new device IOTLB API")

On 2019/3/25 下午10:02, Michael S. Tsirkin wrote:

Looks like more iotlb locking mess?

Looking at the calltrace:

[  221.743675] =============================================
[  221.744297] [ INFO: possible recursive locking detected ]
[  221.744944] 4.7.0+ #1 Not tainted
[  221.745326] ---------------------------------------------
[  221.746128] syz-executor1/6823 is trying to acquire lock:
[  221.746737]  (&vq->mutex){+.+...}, at: [<ffffffff84484b70>] vhost_process_iotlb_msg+0xe0/0x9e0
[  221.747789]
[  221.747789] but task is already holding lock:
[  221.748470]  (&vq->mutex){+.+...}, at: [<ffffffff84484b70>] vhost_process_iotlb_msg+0xe0/0x9e0
[  221.749535]
[  221.749535] other info that might help us debug this:
[  221.750280]  Possible unsafe locking scenario:
[  221.750280]
[  221.750946]        CPU0
[  221.751232]        ----
[  221.751523]   lock(&vq->mutex);
[  221.751922]   lock(&vq->mutex);
[  221.752339]
[  221.752339]  *** DEADLOCK ***
[  221.752339]

I could not think of a path that can hit this. And I could not reproduce with the reproducer in the link in net-next.

Thanks

On Tue, Mar 19, 2019 at 10:21:00PM -0700, syzbot wrote:

quoted

syzbot has bisected this bug to:

commit 6b1e6cc7855b09a0a9bfa1d9f30172ba366f161c
Author: Jason Wang [off-list ref]
Date:   Thu Jun 23 06:04:32 2016 +0000

     vhost: new device IOTLB API

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1486ad27200000
start commit:   6b1e6cc7 vhost: new device IOTLB API
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=1686ad27200000
console output: https://syzkaller.appspot.com/x/log.txt?x=1286ad27200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=c94f9f0c0363db4b
dashboard link: https://syzkaller.appspot.com/bug?extid=d21e6e297322a900c128
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=141db34d400000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=108ef293400000

Reported-by: <redacted>
Fixes: 6b1e6cc7 ("vhost: new device IOTLB API")

On Tue, Mar 26, 2019 at 11:17 AM Jason Wang [off-list ref] wrote:

On 2019/3/25 下午10:02, Michael S. Tsirkin wrote:

quoted

Looks like more iotlb locking mess?

Looking at the calltrace:

[  221.743675] =============================================
[  221.744297] [ INFO: possible recursive locking detected ]
[  221.744944] 4.7.0+ #1 Not tainted
[  221.745326] ---------------------------------------------
[  221.746128] syz-executor1/6823 is trying to acquire lock:
[  221.746737]  (&vq->mutex){+.+...}, at: [<ffffffff84484b70>] vhost_process_iotlb_msg+0xe0/0x9e0
[  221.747789]
[  221.747789] but task is already holding lock:
[  221.748470]  (&vq->mutex){+.+...}, at: [<ffffffff84484b70>] vhost_process_iotlb_msg+0xe0/0x9e0
[  221.749535]
[  221.749535] other info that might help us debug this:
[  221.750280]  Possible unsafe locking scenario:
[  221.750280]
[  221.750946]        CPU0
[  221.751232]        ----
[  221.751523]   lock(&vq->mutex);
[  221.751922]   lock(&vq->mutex);
[  221.752339]
[  221.752339]  *** DEADLOCK ***
[  221.752339]

I could not think of a path that can hit this. And I could not reproduce with the reproducer in the link in net-next.

Looking at the bisection log, syzbot is able to reproduce this
super-reliably on multiple kernel revisions. Are you sure you are
using the right config/revision? What else can be in play? syzbot uses
VMs. The image is available.

Thanks

quoted

On Tue, Mar 19, 2019 at 10:21:00PM -0700, syzbot wrote:

quoted

syzbot has bisected this bug to:

commit 6b1e6cc7855b09a0a9bfa1d9f30172ba366f161c
Author: Jason Wang [off-list ref]
Date:   Thu Jun 23 06:04:32 2016 +0000

     vhost: new device IOTLB API

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1486ad27200000
start commit:   6b1e6cc7 vhost: new device IOTLB API
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=1686ad27200000
console output: https://syzkaller.appspot.com/x/log.txt?x=1286ad27200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=c94f9f0c0363db4b
dashboard link: https://syzkaller.appspot.com/bug?extid=d21e6e297322a900c128
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=141db34d400000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=108ef293400000

Reported-by: <redacted>
Fixes: 6b1e6cc7 ("vhost: new device IOTLB API")

--
You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/df4f2cf6-8469-f894-8f45-7c48a6a1801f%40redhat.com.
For more options, visit https://groups.google.com/d/optout.

On 2019/3/26 下午6:28, Dmitry Vyukov wrote:

On Tue, Mar 26, 2019 at 11:17 AM Jason Wang[off-list ref]  wrote:

quoted

On 2019/3/25 下午10:02, Michael S. Tsirkin wrote:

quoted

Looks like more iotlb locking mess?

Looking at the calltrace:

[  221.743675] =============================================
[  221.744297] [ INFO: possible recursive locking detected ]
[  221.744944] 4.7.0+ #1 Not tainted
[  221.745326] ---------------------------------------------
[  221.746128] syz-executor1/6823 is trying to acquire lock:
[  221.746737]  (&vq->mutex){+.+...}, at: [<ffffffff84484b70>] vhost_process_iotlb_msg+0xe0/0x9e0
[  221.747789]
[  221.747789] but task is already holding lock:
[  221.748470]  (&vq->mutex){+.+...}, at: [<ffffffff84484b70>] vhost_process_iotlb_msg+0xe0/0x9e0
[  221.749535]
[  221.749535] other info that might help us debug this:
[  221.750280]  Possible unsafe locking scenario:
[  221.750280]
[  221.750946]        CPU0
[  221.751232]        ----
[  221.751523]   lock(&vq->mutex);
[  221.751922]   lock(&vq->mutex);
[  221.752339]
[  221.752339]  *** DEADLOCK ***
[  221.752339]

I could not think of a path that can hit this. And I could not reproduce with the reproducer in the link in net-next.

Looking at the bisection log, syzbot is able to reproduce this
super-reliably on multiple kernel revisions. Are you sure you are
using the right config/revision? What else can be in play? syzbot uses
VMs. The image is available.

Yes, looks like the reason is vhost accept zero size iova range which lead a infinite loop when trying to translate iova. Will post a patch to fix this.

Thanks