lkml.org 
[lkml]   [2023]   [Aug]   [19]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    Date
    SubjectRe: [syzbot] [jfs?] INFO: task hung in path_mount (2)
    From
    Hello,

    syzbot has tested the proposed patch but the reproducer is still triggering an issue:
    INFO: task hung in iterate_supers

    INFO: task syz-executor.2:5688 blocked for more than 143 seconds.
    Not tainted 6.5.0-rc6-syzkaller-dirty #0
    "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
    task:syz-executor.2 state:D stack:24584 pid:5688 ppid:5393 flags:0x00004006
    Call Trace:
    <TASK>
    context_switch kernel/sched/core.c:5381 [inline]
    __schedule+0x1873/0x48f0 kernel/sched/core.c:6710
    schedule+0xc3/0x180 kernel/sched/core.c:6786
    schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6845
    rwsem_down_read_slowpath+0x5f4/0x950 kernel/locking/rwsem.c:1086
    __down_read_common kernel/locking/rwsem.c:1250 [inline]
    __down_read kernel/locking/rwsem.c:1263 [inline]
    down_read+0x9c/0x2f0 kernel/locking/rwsem.c:1522
    iterate_supers+0xb0/0x1e0 fs/super.c:742
    quota_sync_all fs/quota/quota.c:69 [inline]
    __do_sys_quotactl fs/quota/quota.c:938 [inline]
    __se_sys_quotactl+0x391/0xa30 fs/quota/quota.c:917
    do_syscall_x64 arch/x86/entry/common.c:50 [inline]
    do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
    entry_SYSCALL_64_after_hwframe+0x63/0xcd
    RIP: 0033:0x7fb3b1a7cae9
    RSP: 002b:00007fb3b28b80c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000b3
    RAX: ffffffffffffffda RBX: 00007fb3b1b9bf80 RCX: 00007fb3b1a7cae9
    RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff80000101
    RBP: 00007fb3b1ac847a R08: 0000000000000000 R09: 0000000000000000
    R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
    R13: 000000000000000b R14: 00007fb3b1b9bf80 R15: 00007fff6eac0208
    </TASK>
    INFO: task syz-executor.4:5709 blocked for more than 143 seconds.
    Not tainted 6.5.0-rc6-syzkaller-dirty #0
    "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
    task:syz-executor.4 state:D stack:25840 pid:5709 ppid:5390 flags:0x00004006
    Call Trace:
    <TASK>
    context_switch kernel/sched/core.c:5381 [inline]
    __schedule+0x1873/0x48f0 kernel/sched/core.c:6710
    schedule+0xc3/0x180 kernel/sched/core.c:6786
    schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6845
    rwsem_down_write_slowpath+0xedd/0x13a0 kernel/locking/rwsem.c:1178
    __down_write_common+0x1aa/0x200 kernel/locking/rwsem.c:1306
    do_remount fs/namespace.c:2879 [inline]
    path_mount+0xbdd/0xfa0 fs/namespace.c:3654
    do_mount fs/namespace.c:3675 [inline]
    __do_sys_mount fs/namespace.c:3884 [inline]
    __se_sys_mount+0x2d9/0x3c0 fs/namespace.c:3861
    do_syscall_x64 arch/x86/entry/common.c:50 [inline]
    do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
    entry_SYSCALL_64_after_hwframe+0x63/0xcd
    RIP: 0033:0x7efee2a7e1ea
    RSP: 002b:00007efee3842ee8 EFLAGS: 00000246 ORIG_RAX: 00000000000000a5
    RAX: ffffffffffffffda RBX: 00007efee3842f80 RCX: 00007efee2a7e1ea
    RDX: 0000000020000180 RSI: 0000000020000100 RDI: 0000000000000000
    RBP: 0000000020000180 R08: 00007efee3842f80 R09: 0000000001a404ac
    R10: 0000000001a404ac R11: 0000000000000246 R12: 0000000020000100
    R13: 00007efee3842f40 R14: 0000000000000000 R15: 0000000020003600
    </TASK>
    INFO: task syz-executor.0:5687 blocked for more than 143 seconds.
    Not tainted 6.5.0-rc6-syzkaller-dirty #0
    "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
    task:syz-executor.0 state:D stack:24584 pid:5687 ppid:5386 flags:0x00004006
    Call Trace:
    <TASK>
    context_switch kernel/sched/core.c:5381 [inline]
    __schedule+0x1873/0x48f0 kernel/sched/core.c:6710
    schedule+0xc3/0x180 kernel/sched/core.c:6786
    jfs_flush_journal+0x733/0xec0 fs/jfs/jfs_logmgr.c:1564
    jfs_sync_fs+0x80/0xa0 fs/jfs/super.c:684
    dquot_quota_sync+0xdb/0x490 fs/quota/dquot.c:704
    iterate_supers+0x12b/0x1e0 fs/super.c:744
    quota_sync_all fs/quota/quota.c:69 [inline]
    __do_sys_quotactl fs/quota/quota.c:938 [inline]
    __se_sys_quotactl+0x391/0xa30 fs/quota/quota.c:917
    do_syscall_x64 arch/x86/entry/common.c:50 [inline]
    do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
    entry_SYSCALL_64_after_hwframe+0x63/0xcd
    RIP: 0033:0x7fd84a27cae9
    RSP: 002b:00007fd84afa50c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000b3
    RAX: ffffffffffffffda RBX: 00007fd84a39bf80 RCX: 00007fd84a27cae9
    RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff80000101
    RBP: 00007fd84a2c847a R08: 0000000000000000 R09: 0000000000000000
    R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
    R13: 000000000000000b R14: 00007fd84a39bf80 R15: 00007ffd56f86288
    </TASK>
    INFO: task syz-executor.5:5689 blocked for more than 144 seconds.
    Not tainted 6.5.0-rc6-syzkaller-dirty #0
    "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
    task:syz-executor.5 state:D stack:24584 pid:5689 ppid:5387 flags:0x00004006
    Call Trace:
    <TASK>
    context_switch kernel/sched/core.c:5381 [inline]
    __schedule+0x1873/0x48f0 kernel/sched/core.c:6710
    schedule+0xc3/0x180 kernel/sched/core.c:6786
    schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6845
    rwsem_down_read_slowpath+0x5f4/0x950 kernel/locking/rwsem.c:1086
    __down_read_common kernel/locking/rwsem.c:1250 [inline]
    __down_read kernel/locking/rwsem.c:1263 [inline]
    down_read+0x9c/0x2f0 kernel/locking/rwsem.c:1522
    iterate_supers+0xb0/0x1e0 fs/super.c:742
    quota_sync_all fs/quota/quota.c:69 [inline]
    __do_sys_quotactl fs/quota/quota.c:938 [inline]
    __se_sys_quotactl+0x391/0xa30 fs/quota/quota.c:917
    do_syscall_x64 arch/x86/entry/common.c:50 [inline]
    do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
    entry_SYSCALL_64_after_hwframe+0x63/0xcd
    RIP: 0033:0x7f05ae27cae9
    RSP: 002b:00007f05aef3a0c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000b3
    RAX: ffffffffffffffda RBX: 00007f05ae39bf80 RCX: 00007f05ae27cae9
    RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff80000101
    RBP: 00007f05ae2c847a R08: 0000000000000000 R09: 0000000000000000
    R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
    R13: 000000000000000b R14: 00007f05ae39bf80 R15: 00007ffed97249c8
    </TASK>
    INFO: task syz-executor.1:5702 blocked for more than 144 seconds.
    Not tainted 6.5.0-rc6-syzkaller-dirty #0
    "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
    task:syz-executor.1 state:D stack:24584 pid:5702 ppid:5378 flags:0x00004006
    Call Trace:
    <TASK>
    context_switch kernel/sched/core.c:5381 [inline]
    __schedule+0x1873/0x48f0 kernel/sched/core.c:6710
    schedule+0xc3/0x180 kernel/sched/core.c:6786
    schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6845
    rwsem_down_read_slowpath+0x5f4/0x950 kernel/locking/rwsem.c:1086
    __down_read_common kernel/locking/rwsem.c:1250 [inline]
    __down_read kernel/locking/rwsem.c:1263 [inline]
    down_read+0x9c/0x2f0 kernel/locking/rwsem.c:1522
    iterate_supers+0xb0/0x1e0 fs/super.c:742
    quota_sync_all fs/quota/quota.c:69 [inline]
    __do_sys_quotactl fs/quota/quota.c:938 [inline]
    __se_sys_quotactl+0x391/0xa30 fs/quota/quota.c:917
    do_syscall_x64 arch/x86/entry/common.c:50 [inline]
    do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
    entry_SYSCALL_64_after_hwframe+0x63/0xcd
    RIP: 0033:0x7f862b87cae9
    RSP: 002b:00007f862c6030c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000b3
    RAX: ffffffffffffffda RBX: 00007f862b99bf80 RCX: 00007f862b87cae9
    RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff80000101
    RBP: 00007f862b8c847a R08: 0000000000000000 R09: 0000000000000000
    R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
    R13: 000000000000000b R14: 00007f862b99bf80 R15: 00007ffe1c3a7d68
    </TASK>
    INFO: task syz-executor.3:5710 blocked for more than 144 seconds.
    Not tainted 6.5.0-rc6-syzkaller-dirty #0
    "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
    task:syz-executor.3 state:D stack:24584 pid:5710 ppid:5382 flags:0x00004006
    Call Trace:
    <TASK>
    context_switch kernel/sched/core.c:5381 [inline]
    __schedule+0x1873/0x48f0 kernel/sched/core.c:6710
    schedule+0xc3/0x180 kernel/sched/core.c:6786
    schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:6845
    rwsem_down_read_slowpath+0x5f4/0x950 kernel/locking/rwsem.c:1086
    __down_read_common kernel/locking/rwsem.c:1250 [inline]
    __down_read kernel/locking/rwsem.c:1263 [inline]
    down_read+0x9c/0x2f0 kernel/locking/rwsem.c:1522
    iterate_supers+0xb0/0x1e0 fs/super.c:742
    quota_sync_all fs/quota/quota.c:69 [inline]
    __do_sys_quotactl fs/quota/quota.c:938 [inline]
    __se_sys_quotactl+0x391/0xa30 fs/quota/quota.c:917
    do_syscall_x64 arch/x86/entry/common.c:50 [inline]
    do_syscall_64+0x41/0xc0 arch/x86/entry/common.c:80
    entry_SYSCALL_64_after_hwframe+0x63/0xcd
    RIP: 0033:0x7f626d07cae9
    RSP: 002b:00007f626de8d0c8 EFLAGS: 00000246 ORIG_RAX: 00000000000000b3
    RAX: ffffffffffffffda RBX: 00007f626d19bf80 RCX: 00007f626d07cae9
    RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff80000101
    RBP: 00007f626d0c847a R08: 0000000000000000 R09: 0000000000000000
    R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
    R13: 000000000000000b R14: 00007f626d19bf80 R15: 00007ffe891110e8
    </TASK>

    Showing all locks held in the system:
    1 lock held by rcu_tasks_kthre/13:
    #0: ffffffff8d3295b0 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x29/0xd20 kernel/rcu/tasks.h:522
    1 lock held by rcu_tasks_trace/14:
    #0: ffffffff8d329970 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x29/0xd20 kernel/rcu/tasks.h:522
    1 lock held by khungtaskd/28:
    #0: ffffffff8d3293e0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
    2 locks held by kworker/u4:2/41:
    2 locks held by getty/4770:
    #0: ffff88814bd10098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:243
    #1: ffffc900015c02f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6b1/0x1dc0 drivers/tty/n_tty.c:2187
    1 lock held by syz-executor.2/5688:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.4/5709:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: do_remount fs/namespace.c:2879 [inline]
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: path_mount+0xbdd/0xfa0 fs/namespace.c:3654
    1 lock held by syz-executor.0/5687:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.5/5689:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.1/5702:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.3/5710:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.0/5982:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.2/6002:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.5/6005:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.1/6010:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.4/6012:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.3/6014:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.0/6048:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.2/6104:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.5/6108:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.3/6129:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.1/6131:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742
    1 lock held by syz-executor.4/6135:
    #0: ffff8880694560e0 (&type->s_umount_key#64){++++}-{3:3}, at: iterate_supers+0xb0/0x1e0 fs/super.c:742

    =============================================

    NMI backtrace for cpu 0
    CPU: 0 PID: 28 Comm: khungtaskd Not tainted 6.5.0-rc6-syzkaller-dirty #0
    Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/26/2023
    Call Trace:
    <TASK>
    __dump_stack lib/dump_stack.c:88 [inline]
    dump_stack_lvl+0x1e7/0x2d0 lib/dump_stack.c:106
    nmi_cpu_backtrace+0x498/0x4d0 lib/nmi_backtrace.c:113
    nmi_trigger_cpumask_backtrace+0x187/0x300 lib/nmi_backtrace.c:62
    trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
    check_hung_uninterruptible_tasks kernel/hung_task.c:222 [inline]
    watchdog+0xec2/0xf00 kernel/hung_task.c:379
    kthread+0x2b8/0x350 kernel/kthread.c:389
    ret_from_fork+0x2e/0x60 arch/x86/kernel/process.c:145
    ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
    </TASK>
    Sending NMI from CPU 0 to CPUs 1:
    NMI backtrace for cpu 1
    CPU: 1 PID: 5445 Comm: kworker/1:5 Not tainted 6.5.0-rc6-syzkaller-dirty #0
    Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 07/26/2023
    Workqueue: events nsim_dev_trap_report_work
    RIP: 0010:on_stack arch/x86/include/asm/stacktrace.h:56 [inline]
    RIP: 0010:unwind_next_frame+0x1932/0x2390 arch/x86/kernel/unwind_orc.c:665
    Code: 89 f8 48 c1 e8 03 80 3c 18 00 74 05 e8 17 e6 a7 00 4c 8b 75 08 48 8d 5d 10 48 89 d8 48 c1 e8 03 48 b9 00 00 00 00 00 fc ff df <80> 3c 08 00 74 08 48 89 df e8 f0 e5 a7 00 4d 39 fe 0f 87 ba 00 00
    RSP: 0018:ffffc90005ae7610 EFLAGS: 00000a06
    RAX: 1ffff92000b5cede RBX: ffffc90005ae76f0 RCX: dffffc0000000000
    RDX: dffffc0000000000 RSI: ffffc90005ae0000 RDI: ffffc90005ae76e8
    RBP: ffffc90005ae76e0 R08: ffffc90005ae7850 R09: 0000000000000000
    R10: ffffc90005ae7730 R11: fffff52000b5cee8 R12: 1ffffffff1e31b57
    R13: 1ffff92000b5cedd R14: ffffc90005ae0000 R15: ffffc90005ae7860
    FS: 0000000000000000(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000
    CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    CR2: 0000555d7f21b030 CR3: 000000002c0f7000 CR4: 00000000003506e0
    DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
    DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
    Call Trace:
    <NMI>
    </NMI>
    <TASK>
    arch_stack_walk+0x111/0x140 arch/x86/kernel/stacktrace.c:25
    stack_trace_save+0x117/0x1c0 kernel/stacktrace.c:122
    kasan_save_stack mm/kasan/common.c:45 [inline]
    kasan_set_track+0x4f/0x70 mm/kasan/common.c:52
    kasan_save_free_info+0x28/0x40 mm/kasan/generic.c:522
    ____kasan_slab_free+0xd6/0x120 mm/kasan/common.c:236
    kasan_slab_free include/linux/kasan.h:162 [inline]
    slab_free_hook mm/slub.c:1792 [inline]
    slab_free_freelist_hook mm/slub.c:1818 [inline]
    slab_free mm/slub.c:3801 [inline]
    kmem_cache_free+0x292/0x500 mm/slub.c:3823
    nsim_dev_trap_report drivers/net/netdevsim/dev.c:821 [inline]
    nsim_dev_trap_report_work+0x761/0xa90 drivers/net/netdevsim/dev.c:850
    process_one_work+0x92c/0x12c0 kernel/workqueue.c:2600
    worker_thread+0xa63/0x1210 kernel/workqueue.c:2751
    kthread+0x2b8/0x350 kernel/kthread.c:389
    ret_from_fork+0x2e/0x60 arch/x86/kernel/process.c:145
    ret_from_fork_asm+0x11/0x20 arch/x86/entry/entry_64.S:304
    </TASK>


    Tested on:

    commit: 2ccdd1b1 Linux 6.5-rc6
    git tree: https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
    console output: https://syzkaller.appspot.com/x/log.txt?x=10ba0ebba80000
    kernel config: https://syzkaller.appspot.com/x/.config?x=9c37cc0e4fcc5f8d
    dashboard link: https://syzkaller.appspot.com/bug?extid=fb337a5ea8454f5f1e3f
    compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
    patch: https://syzkaller.appspot.com/x/patch.diff?x=16856a4ba80000

    \
     
     \ /
      Last update: 2023-08-20 05:24    [W:6.718 / U:0.080 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site