syzbot


INFO: task hung in blk_trace_remove (2)

Status: upstream: reported C repro on 2024/01/25 19:31
Subsystems: block trace
[Documentation on labels]
Reported-by: syzbot+2373f6be3e6de4f92562@syzkaller.appspotmail.com
First crash: 304d, last: 45d
Cause bisection: introduced by (bisect log) :
commit 0d345996e4cb573f8cc81d49b3ee9a7fd2035bef
Author: Pengfei Xu <pengfei.xu@intel.com>
Date: Mon Jul 31 03:04:18 2023 +0000

  x86/kernel: increase kcov coverage under arch/x86/kernel folder

Crash: INFO: task hung in blk_trace_remove (log)
Repro: C syz .config
  
Fix bisection: fixed by (bisect log) :
commit ae94b263f5f69c180347e795fbefa051b65aacc3
Author: Dmitry Vyukov <dvyukov@google.com>
Date: Tue Jun 11 07:50:33 2024 +0000

  x86: Ignore stack unwinding in KCOV

  
Discussions (5)
Title Replies (including bot) Last reply
[syzbot] [block?] [trace?] INFO: task hung in blk_trace_remove (2) 14 (30) 2024/11/13 17:22
[syzbot] Monthly trace report (Oct 2024) 4 (5) 2024/10/15 14:05
[syzbot] Monthly trace report (May 2024) 3 (4) 2024/06/02 21:06
[syzbot] Monthly block report (Mar 2024) 0 (1) 2024/03/12 09:29
[PATCH] trace/blktrace: fix task hung in blk_trace_remove 2 (2) 2024/01/31 14:54
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.19 INFO: task hung in blk_trace_remove 1 977d 977d 0/1 auto-closed as invalid on 2022/07/18 01:50
upstream INFO: task hung in blk_trace_remove block trace 1 1710d 1705d 0/28 auto-closed as invalid on 2020/07/14 22:05
upstream INFO: task can't die in reclaim_throttle mm C error 76 1071d 1078d 0/28 auto-obsoleted due to no activity on 2022/10/21 07:45
Last patch testing requests (23)
Created Duration User Patch Repo Result
2024/10/06 14:28 25m retest repro upstream report log
2024/09/13 05:45 23m retest repro linux-next report log
2024/08/10 10:25 18m retest repro upstream report log
2024/06/30 07:31 23m retest repro linux-next report log
2024/06/01 09:45 28m retest repro upstream report log
2024/05/31 07:54 18m retest repro upstream report log
2024/04/20 10:54 27m retest repro linux-next error
2024/02/06 16:33 22m retest repro linux-next error
2024/02/06 02:38 18m retest repro upstream report log
2024/01/31 11:54 23m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master OK log
2024/01/31 10:15 25m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master OK log
2024/01/31 10:13 24m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master OK log
2024/01/31 09:38 17m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/31 09:32 16m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/31 08:18 17m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/31 01:04 3h09m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/30 13:39 17m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/30 10:53 45m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master OK log
2024/01/30 09:56 16m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/30 08:38 21m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/30 06:48 20m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
2024/01/30 02:16 4h15m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master error
2024/01/30 01:01 30m eadavis@qq.com patch https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master report log
Fix bisection attempts (5)
Created Duration User Patch Repo Result
2024/11/13 08:01 9h20m bisect fix upstream OK (1) job log
2024/09/22 11:59 2h09m bisect fix upstream OK (0) job log log
2024/08/19 08:09 2h47m bisect fix upstream OK (0) job log log
2024/07/19 10:34 2h06m bisect fix upstream OK (0) job log log
2024/03/11 18:10 3h54m bisect fix upstream OK (0) job log log

Sample crash report:
INFO: task syz-executor340:5169 blocked for more than 143 seconds.
      Not tainted 6.9.0-syzkaller-08284-gea5f6ad9ad96 #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor340 state:D stack:28432 pid:5169  tgid:5167  ppid:5129   flags:0x00004006
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5409 [inline]
 __schedule+0x17e8/0x4a50 kernel/sched/core.c:6746
 __schedule_loop kernel/sched/core.c:6823 [inline]
 schedule+0x14b/0x320 kernel/sched/core.c:6838
 schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6895
 __mutex_lock_common kernel/locking/mutex.c:684 [inline]
 __mutex_lock+0x6a4/0xd70 kernel/locking/mutex.c:752
 blk_trace_remove+0x20/0x40 kernel/trace/blktrace.c:406
 sg_ioctl_common drivers/scsi/sg.c:1129 [inline]
 sg_ioctl+0x4bc/0x2e80 drivers/scsi/sg.c:1163
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:904 [inline]
 __se_sys_ioctl+0xfe/0x170 fs/ioctl.c:890
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf5/0x240 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f7eddabcfd9
RSP: 002b:00007f7edda52238 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f7eddb443f8 RCX: 00007f7eddabcfd9
RDX: 0000000000000000 RSI: 0000000000001276 RDI: 0000000000000003
RBP: 00007f7eddb443f0 R08: 00007ffe19fa9287 R09: 00007f7edda526c0
R10: 0000000000000000 R11: 0000000000000246 R12: 2367732f7665642f
R13: 000000000000006e R14: 00007ffe19fa91a0 R15: 00007ffe19fa9288
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/30:
 #0: ffffffff8e334360 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire include/linux/rcupdate.h:329 [inline]
 #0: ffffffff8e334360 (rcu_read_lock){....}-{1:2}, at: rcu_read_lock include/linux/rcupdate.h:781 [inline]
 #0: ffffffff8e334360 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x55/0x2a0 kernel/locking/lockdep.c:6614
2 locks held by getty/4850:
 #0: ffff88802ab950a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70 drivers/tty/tty_ldisc.c:243
 #1: ffffc900031332f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6b5/0x1e10 drivers/tty/n_tty.c:2201
2 locks held by syz-executor340/5168:
1 lock held by syz-executor340/5169:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove+0x20/0x40 kernel/trace/blktrace.c:406
1 lock held by syz-executor340/5171:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xb0/0x1e0 kernel/trace/blktrace.c:648
1 lock held by syz-executor340/5172:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove+0x20/0x40 kernel/trace/blktrace.c:406
1 lock held by syz-executor340/5180:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xb0/0x1e0 kernel/trace/blktrace.c:648
1 lock held by syz-executor340/5181:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove+0x20/0x40 kernel/trace/blktrace.c:406
1 lock held by syz-executor340/5184:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xb0/0x1e0 kernel/trace/blktrace.c:648
1 lock held by syz-executor340/5187:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove+0x20/0x40 kernel/trace/blktrace.c:406
1 lock held by syz-executor340/5186:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xb0/0x1e0 kernel/trace/blktrace.c:648
1 lock held by syz-executor340/5188:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove+0x20/0x40 kernel/trace/blktrace.c:406
1 lock held by syz-executor340/5190:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xb0/0x1e0 kernel/trace/blktrace.c:648
1 lock held by syz-executor340/5191:
 #0: ffff88801ffaed30 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove+0x20/0x40 kernel/trace/blktrace.c:406

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

NMI backtrace for cpu 1
CPU: 1 PID: 30 Comm: khungtaskd Not tainted 6.9.0-syzkaller-08284-gea5f6ad9ad96 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
Call Trace:
 <TASK>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0x241/0x360 lib/dump_stack.c:114
 nmi_cpu_backtrace+0x49c/0x4d0 lib/nmi_backtrace.c:113
 nmi_trigger_cpumask_backtrace+0x198/0x320 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:160 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:223 [inline]
 watchdog+0xfde/0x1020 kernel/hung_task.c:380
 kthread+0x2f2/0x390 kernel/kthread.c:389
 ret_from_fork+0x4d/0x80 arch/x86/kernel/process.c:147
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
 </TASK>
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 5168 Comm: syz-executor340 Not tainted 6.9.0-syzkaller-08284-gea5f6ad9ad96 #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/02/2024
RIP: 0010:kasan_check_range+0x7/0x290 mm/kasan/generic.c:188
Code: 4f ac e4 ff 90 0f 0b 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 66 0f 1f 00 55 41 57 <41> 56 41 54 53 b0 01 48 85 f6 0f 84 a0 01 00 00 4c 8d 04 37 49 39
RSP: 0018:ffffc90002f4f128 EFLAGS: 00000046
RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff81729da0
RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffffffff8facda28
RBP: ffffc90002f4f270 R08: ffffffff92f9d587 R09: 1ffffffff25f3ab0
R10: dffffc0000000000 R11: fffffbfff25f3ab1 R12: 1ffff920005e9e34
R13: ffffffff81ef0f8f R14: 1ffff920005e9e54 R15: dffffc0000000000
FS:  00007f7edda736c0(0000) GS:ffff8880b9400000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00005555869eb738 CR3: 000000002baa6000 CR4: 0000000000350ef0
Call Trace:
 <NMI>
 </NMI>
 <TASK>
 instrument_atomic_read include/linux/instrumented.h:68 [inline]
 _test_bit include/asm-generic/bitops/instrumented-non-atomic.h:141 [inline]
 cpumask_test_cpu include/linux/cpumask.h:545 [inline]
 cpu_online include/linux/cpumask.h:1160 [inline]
 trace_lock_release include/trace/events/lock.h:69 [inline]
 lock_release+0xb0/0x9f0 kernel/locking/lockdep.c:5765
 seqcount_lockdep_reader_access+0xfc/0x1e0 include/linux/seqlock.h:73
 read_seqbegin include/linux/seqlock.h:772 [inline]
 zone_span_seqbegin include/linux/memory_hotplug.h:151 [inline]
 page_outside_zone_boundaries mm/page_alloc.c:451 [inline]
 bad_range+0x5f/0x270 mm/page_alloc.c:470
 expand mm/page_alloc.c:1395 [inline]
 __rmqueue_smallest mm/page_alloc.c:1577 [inline]
 __rmqueue mm/page_alloc.c:2107 [inline]
 rmqueue_bulk mm/page_alloc.c:2133 [inline]
 __rmqueue_pcplist+0x15e1/0x2620 mm/page_alloc.c:2826
 rmqueue_pcplist mm/page_alloc.c:2868 [inline]
 rmqueue mm/page_alloc.c:2905 [inline]
 get_page_from_freelist+0x856/0x35b0 mm/page_alloc.c:3314
 __alloc_pages+0x256/0x6c0 mm/page_alloc.c:4575
 alloc_pages_mpol+0x3e8/0x680 mm/mempolicy.c:2264
 relay_alloc_buf kernel/relay.c:121 [inline]
 relay_create_buf kernel/relay.c:162 [inline]
 relay_open_buf+0x2bd/0xd60 kernel/relay.c:384
 relay_open+0x3aa/0x890 kernel/relay.c:517
 do_blk_trace_setup+0x547/0x970 kernel/trace/blktrace.c:591
 __blk_trace_setup kernel/trace/blktrace.c:631 [inline]
 blk_trace_setup+0x119/0x1e0 kernel/trace/blktrace.c:649
 sg_ioctl_common drivers/scsi/sg.c:1121 [inline]
 sg_ioctl+0xa4c/0x2e80 drivers/scsi/sg.c:1163
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:904 [inline]
 __se_sys_ioctl+0xfe/0x170 fs/ioctl.c:890
 do_syscall_x64 arch/x86/entry/common.c:52 [inline]
 do_syscall_64+0xf5/0x240 arch/x86/entry/common.c:83
 entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f7eddabcfd9
Code: 28 00 00 00 75 05 48 83 c4 28 c3 e8 91 1a 00 00 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 c7 c1 b0 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007f7edda73238 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f7eddb443e8 RCX: 00007f7eddabcfd9
RDX: 0000000020000040 RSI: 00000000c0481273 RDI: 0000000000000003
RBP: 00007f7eddb443e0 R08: 00007f7edda736c0 R09: 00007f7edda736c0
R10: 00007f7edda736c0 R11: 0000000000000246 R12: 2367732f7665642f
R13: 0000000000000016 R14: 00007ffe19fa91a0 R15: 00007ffe19fa9288
 </TASK>
INFO: NMI handler (nmi_cpu_backtrace_handler) took too long to run: 2.655 msecs

Crashes (6):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/05/17 07:39 upstream ea5f6ad9ad96 c2e07261 .config console log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-root INFO: task hung in blk_trace_remove
2024/01/21 19:21 linux-next ad5c60d66016 9bd8dcda .config strace log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-linux-next-kasan-gce-root INFO: task hung in blk_trace_remove
2024/03/28 09:07 upstream fe46a7dd189e 454571b6 .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root INFO: task hung in blk_trace_remove
2024/01/22 17:21 upstream 6613476e225e 9bd8dcda .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce-selinux-root INFO: task hung in blk_trace_remove
2024/01/21 22:08 upstream 7a396820222d 9bd8dcda .config console log report syz C [disk image] [vmlinux] [kernel image] ci-upstream-kasan-gce INFO: task hung in blk_trace_remove
2024/01/21 16:02 linux-next ad5c60d66016 9bd8dcda .config console log report info [disk image] [vmlinux] [kernel image] ci-upstream-linux-next-kasan-gce-root INFO: task hung in blk_trace_remove
* Struck through repros no longer work on HEAD.