linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* INFO: task hung in blk_trace_remove
@ 2020-03-21  7:12 syzbot
  2020-03-21  7:15 ` Dmitry Vyukov
  0 siblings, 1 reply; 6+ messages in thread
From: syzbot @ 2020-03-21  7:12 UTC (permalink / raw)
  To: axboe, linux-block, linux-kernel, mingo, rostedt, syzkaller-bugs

Hello,

syzbot found the following crash on:

HEAD commit:    fb33c651 Linux 5.6-rc6
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=140688d3e00000
kernel config:  https://syzkaller.appspot.com/x/.config?x=9f894bd92023de02
dashboard link: https://syzkaller.appspot.com/bug?extid=c07afbbb410e9f712273
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)

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

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

INFO: task syz-executor.4:7237 blocked for more than 143 seconds.
      Not tainted 5.6.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4  D26576  7237   9609 0x00004004
Call Trace:
 schedule+0xd0/0x2a0 kernel/sched/core.c:4154
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
 blk_trace_remove+0x1e/0x40 kernel/trace/blktrace.c:361
 sg_ioctl_common+0x221/0x2710 drivers/scsi/sg.c:1125
 sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
 vfs_ioctl fs/ioctl.c:47 [inline]
 ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
 __do_sys_ioctl fs/ioctl.c:772 [inline]
 __se_sys_ioctl fs/ioctl.c:770 [inline]
 __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45c849
Code: Bad RIP value.
RSP: 002b:00007f5ba5a3bc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f5ba5a3c6d4 RCX: 000000000045c849
RDX: 0000000000000000 RSI: 0000000000001276 RDI: 0000000000000003
RBP: 000000000076bf00 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 000000000000022b R14: 00000000004c4526 R15: 000000000076bf0c
INFO: task syz-executor.4:7266 blocked for more than 146 seconds.
      Not tainted 5.6.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4  D27752  7266   9609 0x00004004
Call Trace:
 schedule+0xd0/0x2a0 kernel/sched/core.c:4154
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
 blk_trace_setup+0x2f/0x60 kernel/trace/blktrace.c:588
 sg_ioctl_common+0x2f2/0x2710 drivers/scsi/sg.c:1116
 sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
 vfs_ioctl fs/ioctl.c:47 [inline]
 ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
 __do_sys_ioctl fs/ioctl.c:772 [inline]
 __se_sys_ioctl fs/ioctl.c:770 [inline]
 __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45c849
Code: Bad RIP value.
RSP: 002b:00007f5ba5a1ac78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f5ba5a1b6d4 RCX: 000000000045c849
RDX: 0000000020000080 RSI: 00000000c0481273 RDI: 0000000000000008
RBP: 000000000076bfa0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000228 R14: 00000000004c44eb R15: 000000000076bfac
INFO: task syz-executor.5:7265 blocked for more than 149 seconds.
      Not tainted 5.6.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.5  D26736  7265   9613 0x00004004
Call Trace:
 schedule+0xd0/0x2a0 kernel/sched/core.c:4154
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
 blk_trace_setup+0x2f/0x60 kernel/trace/blktrace.c:588
 sg_ioctl_common+0x2f2/0x2710 drivers/scsi/sg.c:1116
 sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
 vfs_ioctl fs/ioctl.c:47 [inline]
 ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
 __do_sys_ioctl fs/ioctl.c:772 [inline]
 __se_sys_ioctl fs/ioctl.c:770 [inline]
 __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
 do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45c849
Code: Bad RIP value.
RSP: 002b:00007f576f48ac78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007f576f48b6d4 RCX: 000000000045c849
RDX: 0000000020000080 RSI: 00000000c0481273 RDI: 0000000000000006


---
This bug 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 syzkaller@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: INFO: task hung in blk_trace_remove
  2020-03-21  7:12 INFO: task hung in blk_trace_remove syzbot
@ 2020-03-21  7:15 ` Dmitry Vyukov
  2020-03-23 17:12   ` Todd Kjos
  0 siblings, 1 reply; 6+ messages in thread
From: Dmitry Vyukov @ 2020-03-21  7:15 UTC (permalink / raw)
  To: syzbot, Greg Kroah-Hartman, Arve Hjønnevåg, Todd Kjos,
	Martijn Coenen, Joel Fernandes, Christian Brauner,
	open list:ANDROID DRIVERS
  Cc: Jens Axboe, linux-block, LKML, Ingo Molnar, Steven Rostedt,
	syzkaller-bugs

On Sat, Mar 21, 2020 at 8:12 AM syzbot
<syzbot+c07afbbb410e9f712273@syzkaller.appspotmail.com> wrote:
>
> Hello,
>
> syzbot found the following crash on:
>
> HEAD commit:    fb33c651 Linux 5.6-rc6
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=140688d3e00000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=9f894bd92023de02
> dashboard link: https://syzkaller.appspot.com/bug?extid=c07afbbb410e9f712273
> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
>
> Unfortunately, I don't have any reproducer for this crash yet.
>
> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+c07afbbb410e9f712273@syzkaller.appspotmail.com

+ashmem maintainers

From the log, ashmem spews an infinite sequence of some errors which
probably stall the machine:

[ 1094.685541][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641097791
[ 1094.701750][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641383141
[ 1094.708003][ T9576] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641233534
[ 1094.723597][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641083174
[ 1094.730025][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641098111
[ 1094.745592][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641383221
[ 1094.753153][ T9576] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641233534
[ 1094.767903][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641084454
[ 1094.819845][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641526579
[ 1094.830116][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641098111
[ 1094.845813][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641527219
[ 1094.852188][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641098751
[ 1094.871456][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641527219
[ 1094.874256][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641098751
[ 1094.890195][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641528499
[ 1094.895999][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641087014
[ 1094.912931][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641528499
[ 1094.918797][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641100031
[ 1094.936636][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641531059
[ 1094.941391][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641081897
[ 1094.957463][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641531059
[ 1094.963568][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641100031
[ 1094.980233][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641536179
[ 1094.985311][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641081899
[ 1095.001393][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641536179
[ 1095.008146][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641102591
[ 1095.024425][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641525942
[ 1095.029644][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641081904
[ 1095.046399][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641525942
[ 1095.052377][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641102591
[ 1095.068000][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641525944
[ 1095.073934][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641081914
[ 1095.091076][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641525944
[ 1095.096925][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641107711
[ 1095.112305][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641525949
[ 1095.118570][ T1876] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641081934
[ 1095.135413][ T7239] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641525949
[ 1095.141206][ T9460] vmscan: shrink_slab:
ashmem_shrink_scan+0x0/0x500 negative objects to delete
nr=-6917529027641107711



> INFO: task syz-executor.4:7237 blocked for more than 143 seconds.
>       Not tainted 5.6.0-rc6-syzkaller #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> syz-executor.4  D26576  7237   9609 0x00004004
> Call Trace:
>  schedule+0xd0/0x2a0 kernel/sched/core.c:4154
>  schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
>  __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
>  __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
>  blk_trace_remove+0x1e/0x40 kernel/trace/blktrace.c:361
>  sg_ioctl_common+0x221/0x2710 drivers/scsi/sg.c:1125
>  sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
>  vfs_ioctl fs/ioctl.c:47 [inline]
>  ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
>  __do_sys_ioctl fs/ioctl.c:772 [inline]
>  __se_sys_ioctl fs/ioctl.c:770 [inline]
>  __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
>  do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
>  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> RIP: 0033:0x45c849
> Code: Bad RIP value.
> RSP: 002b:00007f5ba5a3bc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 00007f5ba5a3c6d4 RCX: 000000000045c849
> RDX: 0000000000000000 RSI: 0000000000001276 RDI: 0000000000000003
> RBP: 000000000076bf00 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
> R13: 000000000000022b R14: 00000000004c4526 R15: 000000000076bf0c
> INFO: task syz-executor.4:7266 blocked for more than 146 seconds.
>       Not tainted 5.6.0-rc6-syzkaller #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> syz-executor.4  D27752  7266   9609 0x00004004
> Call Trace:
>  schedule+0xd0/0x2a0 kernel/sched/core.c:4154
>  schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
>  __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
>  __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
>  blk_trace_setup+0x2f/0x60 kernel/trace/blktrace.c:588
>  sg_ioctl_common+0x2f2/0x2710 drivers/scsi/sg.c:1116
>  sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
>  vfs_ioctl fs/ioctl.c:47 [inline]
>  ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
>  __do_sys_ioctl fs/ioctl.c:772 [inline]
>  __se_sys_ioctl fs/ioctl.c:770 [inline]
>  __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
>  do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
>  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> RIP: 0033:0x45c849
> Code: Bad RIP value.
> RSP: 002b:00007f5ba5a1ac78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 00007f5ba5a1b6d4 RCX: 000000000045c849
> RDX: 0000000020000080 RSI: 00000000c0481273 RDI: 0000000000000008
> RBP: 000000000076bfa0 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
> R13: 0000000000000228 R14: 00000000004c44eb R15: 000000000076bfac
> INFO: task syz-executor.5:7265 blocked for more than 149 seconds.
>       Not tainted 5.6.0-rc6-syzkaller #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> syz-executor.5  D26736  7265   9613 0x00004004
> Call Trace:
>  schedule+0xd0/0x2a0 kernel/sched/core.c:4154
>  schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
>  __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
>  __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
>  blk_trace_setup+0x2f/0x60 kernel/trace/blktrace.c:588
>  sg_ioctl_common+0x2f2/0x2710 drivers/scsi/sg.c:1116
>  sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
>  vfs_ioctl fs/ioctl.c:47 [inline]
>  ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
>  __do_sys_ioctl fs/ioctl.c:772 [inline]
>  __se_sys_ioctl fs/ioctl.c:770 [inline]
>  __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
>  do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
>  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> RIP: 0033:0x45c849
> Code: Bad RIP value.
> RSP: 002b:00007f576f48ac78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 00007f576f48b6d4 RCX: 000000000045c849
> RDX: 0000000020000080 RSI: 00000000c0481273 RDI: 0000000000000006
>
>
> ---
> This bug 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 syzkaller@googlegroups.com.
>
> syzbot will keep track of this bug report. See:
> https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
>
> --
> 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/0000000000000bec9805a1581f05%40google.com.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: INFO: task hung in blk_trace_remove
  2020-03-21  7:15 ` Dmitry Vyukov
@ 2020-03-23 17:12   ` Todd Kjos
  0 siblings, 0 replies; 6+ messages in thread
From: Todd Kjos @ 2020-03-23 17:12 UTC (permalink / raw)
  To: Dmitry Vyukov
  Cc: syzbot, Greg Kroah-Hartman, Arve Hjønnevåg, Todd Kjos,
	Martijn Coenen, Joel Fernandes, Christian Brauner,
	open list:ANDROID DRIVERS, Jens Axboe, linux-block, LKML,
	Ingo Molnar, Steven Rostedt, syzkaller-bugs

On Sat, Mar 21, 2020 at 12:15 AM Dmitry Vyukov <dvyukov@google.com> wrote:
>
> On Sat, Mar 21, 2020 at 8:12 AM syzbot
> <syzbot+c07afbbb410e9f712273@syzkaller.appspotmail.com> wrote:
> >
> > Hello,
> >
> > syzbot found the following crash on:
> >
> > HEAD commit:    fb33c651 Linux 5.6-rc6
> > git tree:       upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=140688d3e00000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=9f894bd92023de02
> > dashboard link: https://syzkaller.appspot.com/bug?extid=c07afbbb410e9f712273
> > compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> >
> > Unfortunately, I don't have any reproducer for this crash yet.
> >
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: syzbot+c07afbbb410e9f712273@syzkaller.appspotmail.com
>
> +ashmem maintainers

We'll have a look.

>
> From the log, ashmem spews an infinite sequence of some errors which
> probably stall the machine:
>
> [ 1094.685541][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641097791
> [ 1094.701750][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641383141
> [ 1094.708003][ T9576] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641233534
> [ 1094.723597][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641083174
> [ 1094.730025][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641098111
> [ 1094.745592][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641383221
> [ 1094.753153][ T9576] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641233534
> [ 1094.767903][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641084454
> [ 1094.819845][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641526579
> [ 1094.830116][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641098111
> [ 1094.845813][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641527219
> [ 1094.852188][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641098751
> [ 1094.871456][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641527219
> [ 1094.874256][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641098751
> [ 1094.890195][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641528499
> [ 1094.895999][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641087014
> [ 1094.912931][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641528499
> [ 1094.918797][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641100031
> [ 1094.936636][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641531059
> [ 1094.941391][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641081897
> [ 1094.957463][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641531059
> [ 1094.963568][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641100031
> [ 1094.980233][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641536179
> [ 1094.985311][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641081899
> [ 1095.001393][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641536179
> [ 1095.008146][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641102591
> [ 1095.024425][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641525942
> [ 1095.029644][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641081904
> [ 1095.046399][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641525942
> [ 1095.052377][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641102591
> [ 1095.068000][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641525944
> [ 1095.073934][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641081914
> [ 1095.091076][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641525944
> [ 1095.096925][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641107711
> [ 1095.112305][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641525949
> [ 1095.118570][ T1876] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641081934
> [ 1095.135413][ T7239] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641525949
> [ 1095.141206][ T9460] vmscan: shrink_slab:
> ashmem_shrink_scan+0x0/0x500 negative objects to delete
> nr=-6917529027641107711
>
>
>
> > INFO: task syz-executor.4:7237 blocked for more than 143 seconds.
> >       Not tainted 5.6.0-rc6-syzkaller #0
> > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > syz-executor.4  D26576  7237   9609 0x00004004
> > Call Trace:
> >  schedule+0xd0/0x2a0 kernel/sched/core.c:4154
> >  schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
> >  __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
> >  __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
> >  blk_trace_remove+0x1e/0x40 kernel/trace/blktrace.c:361
> >  sg_ioctl_common+0x221/0x2710 drivers/scsi/sg.c:1125
> >  sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
> >  vfs_ioctl fs/ioctl.c:47 [inline]
> >  ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
> >  __do_sys_ioctl fs/ioctl.c:772 [inline]
> >  __se_sys_ioctl fs/ioctl.c:770 [inline]
> >  __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
> >  do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
> >  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > RIP: 0033:0x45c849
> > Code: Bad RIP value.
> > RSP: 002b:00007f5ba5a3bc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> > RAX: ffffffffffffffda RBX: 00007f5ba5a3c6d4 RCX: 000000000045c849
> > RDX: 0000000000000000 RSI: 0000000000001276 RDI: 0000000000000003
> > RBP: 000000000076bf00 R08: 0000000000000000 R09: 0000000000000000
> > R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
> > R13: 000000000000022b R14: 00000000004c4526 R15: 000000000076bf0c
> > INFO: task syz-executor.4:7266 blocked for more than 146 seconds.
> >       Not tainted 5.6.0-rc6-syzkaller #0
> > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > syz-executor.4  D27752  7266   9609 0x00004004
> > Call Trace:
> >  schedule+0xd0/0x2a0 kernel/sched/core.c:4154
> >  schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
> >  __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
> >  __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
> >  blk_trace_setup+0x2f/0x60 kernel/trace/blktrace.c:588
> >  sg_ioctl_common+0x2f2/0x2710 drivers/scsi/sg.c:1116
> >  sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
> >  vfs_ioctl fs/ioctl.c:47 [inline]
> >  ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
> >  __do_sys_ioctl fs/ioctl.c:772 [inline]
> >  __se_sys_ioctl fs/ioctl.c:770 [inline]
> >  __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
> >  do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
> >  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > RIP: 0033:0x45c849
> > Code: Bad RIP value.
> > RSP: 002b:00007f5ba5a1ac78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> > RAX: ffffffffffffffda RBX: 00007f5ba5a1b6d4 RCX: 000000000045c849
> > RDX: 0000000020000080 RSI: 00000000c0481273 RDI: 0000000000000008
> > RBP: 000000000076bfa0 R08: 0000000000000000 R09: 0000000000000000
> > R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
> > R13: 0000000000000228 R14: 00000000004c44eb R15: 000000000076bfac
> > INFO: task syz-executor.5:7265 blocked for more than 149 seconds.
> >       Not tainted 5.6.0-rc6-syzkaller #0
> > "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > syz-executor.5  D26736  7265   9613 0x00004004
> > Call Trace:
> >  schedule+0xd0/0x2a0 kernel/sched/core.c:4154
> >  schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4213
> >  __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
> >  __mutex_lock+0x7ab/0x13c0 kernel/locking/mutex.c:1103
> >  blk_trace_setup+0x2f/0x60 kernel/trace/blktrace.c:588
> >  sg_ioctl_common+0x2f2/0x2710 drivers/scsi/sg.c:1116
> >  sg_ioctl+0x8f/0x120 drivers/scsi/sg.c:1159
> >  vfs_ioctl fs/ioctl.c:47 [inline]
> >  ksys_ioctl+0x11a/0x180 fs/ioctl.c:763
> >  __do_sys_ioctl fs/ioctl.c:772 [inline]
> >  __se_sys_ioctl fs/ioctl.c:770 [inline]
> >  __x64_sys_ioctl+0x6f/0xb0 fs/ioctl.c:770
> >  do_syscall_64+0xf6/0x7d0 arch/x86/entry/common.c:294
> >  entry_SYSCALL_64_after_hwframe+0x49/0xbe
> > RIP: 0033:0x45c849
> > Code: Bad RIP value.
> > RSP: 002b:00007f576f48ac78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> > RAX: ffffffffffffffda RBX: 00007f576f48b6d4 RCX: 000000000045c849
> > RDX: 0000000020000080 RSI: 00000000c0481273 RDI: 0000000000000006
> >
> >
> > ---
> > This bug 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 syzkaller@googlegroups.com.
> >
> > syzbot will keep track of this bug report. See:
> > https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
> >
> > --
> > 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/0000000000000bec9805a1581f05%40google.com.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: INFO: task hung in blk_trace_remove
  2022-07-03  4:57 Dae R. Jeong
  2022-07-03  5:05 ` Dae R. Jeong
@ 2022-07-03  7:12 ` Christoph Hellwig
  1 sibling, 0 replies; 6+ messages in thread
From: Christoph Hellwig @ 2022-07-03  7:12 UTC (permalink / raw)
  To: Dae R. Jeong; +Cc: axboe, rostedt, mingo, linux-block, linux-kernel

On Sun, Jul 03, 2022 at 01:57:20PM +0900, Dae R. Jeong wrote:
> Hello,
> 
> We observed an issue "INFO: task hung in blk_trace_remove" during
> fuzzing.
> 
> Unfortunately, we have not found a reproducer for the crash yet. We
> will inform you if we have any update on this crash.
> 
> The crash information is attached at the end of this email.

This looks like it is due to locking an on the /dev/sg node instead
of the more usual (and more tested) block device node.

It might make sense to run with lockdep enabled to get a better
grip on potential locking issues here.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: INFO: task hung in blk_trace_remove
  2022-07-03  4:57 Dae R. Jeong
@ 2022-07-03  5:05 ` Dae R. Jeong
  2022-07-03  7:12 ` Christoph Hellwig
  1 sibling, 0 replies; 6+ messages in thread
From: Dae R. Jeong @ 2022-07-03  5:05 UTC (permalink / raw)
  To: axboe, rostedt, mingo, linux-block, linux-kernel

On Sun, Jul 03, 2022 at 01:57:25PM +0900, Dae R. Jeong wrote:
> Hello,
> 
> We observed an issue "INFO: task hung in blk_trace_remove" during
> fuzzing.

We also observed a similar issue "INFO: task hung in
blk_trace_setup". At this point, we don't know whether these two
issues are caused by the same reason.

Unfortunately, we have not found a reproducer for this crash. We will
inform you if we have any update.

The crash information is attached at the end of this email.


Best regards,
Dae R. Jeong

------

- Kernel commit:
92f20ff72066d

- Crash report:

INFO: task syz-executor.0:13708 blocked for more than 143 seconds.
      Not tainted 5.19.0-rc3-32288-g0f3b08299494 #15
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0  state:D stack:26560 pid:13708 ppid:  6772 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5146 [inline]
 __schedule+0x96c/0x10f0 kernel/sched/core.c:6458
 schedule+0xea/0x1b0 kernel/sched/core.c:6530
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
 __mutex_lock_common+0xe0f/0x25e0 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:799
 blk_trace_setup+0xa9/0x1b0 kernel/trace/blktrace.c:616
 sg_ioctl_common drivers/scsi/sg.c:1122 [inline]
 sg_ioctl+0x1b61/0x4000 drivers/scsi/sg.c:1164
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:870 [inline]
 __se_sys_ioctl+0x129/0x1c0 fs/ioctl.c:856
 do_syscall_x64 arch/x86/entry/common.c:51 [inline]
 do_syscall_64+0x4e/0xa0 arch/x86/entry/common.c:82
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x478dc9
RSP: 002b:00007f5dde784be8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 000000000077d4a0 RCX: 0000000000478dc9
RDX: 0000000020000340 RSI: 00000000c0481273 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000077d4a8
R13: 000000000077d4ac R14: 000000000077d4a0 R15: 00007ffdfb78c900
 </TASK>
INFO: task syz-executor.0:13709 blocked for more than 143 seconds.
      Not tainted 5.19.0-rc3-32288-g0f3b08299494 #15
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0  state:D stack:26608 pid:13709 ppid:  6772 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5146 [inline]
 __schedule+0x96c/0x10f0 kernel/sched/core.c:6458
 schedule+0xea/0x1b0 kernel/sched/core.c:6530
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
 __mutex_lock_common+0xe0f/0x25e0 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:799
 blk_trace_setup+0xa9/0x1b0 kernel/trace/blktrace.c:616
 sg_ioctl_common drivers/scsi/sg.c:1122 [inline]
 sg_ioctl+0x1b61/0x4000 drivers/scsi/sg.c:1164
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:870 [inline]
 __se_sys_ioctl+0x129/0x1c0 fs/ioctl.c:856
 do_syscall_x64 arch/x86/entry/common.c:51 [inline]
 do_syscall_64+0x4e/0xa0 arch/x86/entry/common.c:82
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x478dc9
RSP: 002b:00007f5dde763be8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 000000000077e9c0 RCX: 0000000000478dc9
RDX: 00000000200003c0 RSI: 00000000c0481273 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000077e9c8
R13: 000000000077e9cc R14: 000000000077e9c0 R15: 00007ffdfb78c900
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/40:
 #0: ffffffff9071a3e0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
1 lock held by systemd-journal/3025:
 #0: ffff8880b933bb58 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x25/0x110 kernel/sched/core.c:544
1 lock held by in:imklog/6630:
 #0: ffff88801c6e40e8 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x2f3/0x430 fs/file.c:1036
2 locks held by syz-executor.0/13707:
1 lock held by syz-executor.0/13708:
 #0: ffff88814c195ff8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xa9/0x1b0 kernel/trace/blktrace.c:616
1 lock held by syz-executor.0/13709:
 #0: ffff88814c195ff8 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_setup+0xa9/0x1b0 kernel/trace/blktrace.c:616

^ permalink raw reply	[flat|nested] 6+ messages in thread

* INFO: task hung in blk_trace_remove
@ 2022-07-03  4:57 Dae R. Jeong
  2022-07-03  5:05 ` Dae R. Jeong
  2022-07-03  7:12 ` Christoph Hellwig
  0 siblings, 2 replies; 6+ messages in thread
From: Dae R. Jeong @ 2022-07-03  4:57 UTC (permalink / raw)
  To: axboe, rostedt, mingo, linux-block, linux-kernel

Hello,

We observed an issue "INFO: task hung in blk_trace_remove" during
fuzzing.

Unfortunately, we have not found a reproducer for the crash yet. We
will inform you if we have any update on this crash.

The crash information is attached at the end of this email.


Best regards,
Dae R. Jeong

------

- Kernel commit:
92f20ff72066d

- Crash report: 
INFO: task syz-executor.0:13658 blocked for more than 143 seconds.
      Not tainted 5.19.0-rc3-32288-g0f3b08299494 #3
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.0  state:D stack:27824 pid:13658 ppid:  6759 flags:0x00004004
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5146 [inline]
 __schedule+0x96c/0x10f0 kernel/sched/core.c:6458
 schedule+0xea/0x1b0 kernel/sched/core.c:6530
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6589
 __mutex_lock_common+0xe0f/0x25e0 kernel/locking/mutex.c:679
 __mutex_lock kernel/locking/mutex.c:747 [inline]
 mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:799
 blk_trace_remove+0x1c/0x40 kernel/trace/blktrace.c:374
 sg_ioctl_common drivers/scsi/sg.c:1130 [inline]
 sg_ioctl+0x712/0x4be0 drivers/scsi/sg.c:1164
 vfs_ioctl fs/ioctl.c:51 [inline]
 __do_sys_ioctl fs/ioctl.c:870 [inline]
 __se_sys_ioctl+0x152/0x1f0 fs/ioctl.c:856
 do_syscall_x64 arch/x86/entry/common.c:51 [inline]
 do_syscall_64+0x4e/0xa0 arch/x86/entry/common.c:82
 entry_SYSCALL_64_after_hwframe+0x46/0xb0
RIP: 0033:0x47268d
RSP: 002b:00007fab57574be8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 000000000057d4a0 RCX: 000000000047268d
RDX: 0000000000000000 RSI: 0000000000001276 RDI: 0000000000000003
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000057d4a8
R13: 000000000057d4ac R14: 00007ffe9afe72f0 R15: 00007fab57574d80
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/40:
 #0: ffffffff92f1a3e0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
1 lock held by in:imklog/6420:
 #0: ffff88807d844368 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x3bf/0x530 fs/file.c:1036
4 locks held by syz-executor.0/13657:
1 lock held by syz-executor.0/13658:
 #0: ffff888022c78378 (&q->debugfs_mutex){+.+.}-{3:3}, at: blk_trace_remove+0x1c/0x40 kernel/trace/blktrace.c:374


^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2022-07-03  7:12 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-03-21  7:12 INFO: task hung in blk_trace_remove syzbot
2020-03-21  7:15 ` Dmitry Vyukov
2020-03-23 17:12   ` Todd Kjos
2022-07-03  4:57 Dae R. Jeong
2022-07-03  5:05 ` Dae R. Jeong
2022-07-03  7:12 ` Christoph Hellwig

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).