syzbot


INFO: task hung in vzalloc

Status: auto-closed as invalid on 2021/03/09 11:16
Reported-by: syzbot+dd502f3dda92daabc873@syzkaller.appspotmail.com
First crash: 1262d, last: 1262d

Sample crash report:
UDF-fs: Scanning with blocksize 512 failed
INFO: task kworker/1:4:9304 blocked for more than 140 seconds.
      Not tainted 4.19.155-syzkaller #0
syz-executor.4 cpuset=/ mems_allowed=0-1
UDF-fs: warning (device loop2): udf_load_vrs: No VRS found
CPU: 0 PID: 19307 Comm: syz-executor.4 Not tainted 4.19.155-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
 warn_alloc.cold+0x7b/0x18f mm/page_alloc.c:3457
 __vmalloc_node_range mm/vmalloc.c:1775 [inline]
 __vmalloc_node mm/vmalloc.c:1804 [inline]
 __vmalloc_node_flags mm/vmalloc.c:1818 [inline]
 vzalloc+0x15c/0x1a0 mm/vmalloc.c:1857
 ip_set_alloc+0x8a/0xd0 net/netfilter/ipset/ip_set_core.c:265
 hash_ip_create+0x4e2/0xf00 net/netfilter/ipset/ip_set_hash_gen.h:1296
 ip_set_create+0x6b4/0x1370 net/netfilter/ipset/ip_set_core.c:940
 nfnetlink_rcv_msg+0xc4f/0xf60 net/netfilter/nfnetlink.c:233
 netlink_rcv_skb+0x160/0x440 net/netlink/af_netlink.c:2455
 nfnetlink_rcv+0x1b2/0x41b net/netfilter/nfnetlink.c:565
 netlink_unicast_kernel net/netlink/af_netlink.c:1318 [inline]
 netlink_unicast+0x4d5/0x690 net/netlink/af_netlink.c:1344
 netlink_sendmsg+0x6bb/0xc40 net/netlink/af_netlink.c:1909
 sock_sendmsg_nosec net/socket.c:622 [inline]
 sock_sendmsg+0xc3/0x120 net/socket.c:632
 ___sys_sendmsg+0x7bb/0x8e0 net/socket.c:2115
 __sys_sendmsg net/socket.c:2153 [inline]
 __do_sys_sendmsg net/socket.c:2162 [inline]
 __se_sys_sendmsg net/socket.c:2160 [inline]
 __x64_sys_sendmsg+0x132/0x220 net/socket.c:2160
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45deb9
Code: 0d b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 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 0f 83 db b3 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0b5fe94c78 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
RAX: ffffffffffffffda RBX: 0000000000029bc0 RCX: 000000000045deb9
RDX: 0000000000000000 RSI: 00000000200000c0 RDI: 0000000000000003
RBP: 000000000118bf60 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007ffe0cb53acf R14: 00007f0b5fe959c0 R15: 000000000118bf2c
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
UDF-fs: Scanning with blocksize 1024 failed
kworker/1:4     D25760  9304      2 0x80000000
Workqueue: usb_hub_wq hub_event
UDF-fs: warning (device loop2): udf_load_vrs: No VRS found
Call Trace:
 context_switch kernel/sched/core.c:2828 [inline]
 __schedule+0x887/0x2040 kernel/sched/core.c:3517
UDF-fs: Scanning with blocksize 2048 failed
UDF-fs: warning (device loop2): udf_load_vrs: No VRS found
UDF-fs: Scanning with blocksize 4096 failed
 schedule+0x8d/0x1b0 kernel/sched/core.c:3561
netlink: 28 bytes leftover after parsing attributes in process `syz-executor.0'.
 usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697
 usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692
 usb_start_wait_urb+0x252/0x4c0 drivers/usb/core/message.c:63
warn_alloc_show_mem: 1 callbacks suppressed
Mem-Info:
active_anon:147225 inactive_anon:4755 isolated_anon:0
 active_file:11666 inactive_file:97739 isolated_file:0
 unevictable:0 dirty:157 writeback:0 unstable:0
 slab_reclaimable:24066 slab_unreclaimable:114826
 mapped:61963 shmem:5989 pagetables:1763 bounce:0
 free:1226579 free_pcp:534 free_cma:0
 usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
 usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152
Node 0 active_anon:588900kB inactive_anon:19020kB active_file:46520kB inactive_file:390956kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:247852kB dirty:624kB writeback:0kB shmem:23956kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 260096kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
Node 1 active_anon:0kB inactive_anon:0kB active_file:144kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:0kB dirty:4kB writeback:0kB shmem:0kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
Node 0 DMA free:15908kB min:204kB low:252kB high:300kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15908kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
 hub_port_init+0x12d9/0x2fa0 drivers/usb/core/hub.c:4654
 hub_port_connect drivers/usb/core/hub.c:5020 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 port_event drivers/usb/core/hub.c:5311 [inline]
 hub_event+0x1cf8/0x43f0 drivers/usb/core/hub.c:5391
lowmem_reserve[]: 0 2693 2695 2695 2695
 process_one_work+0x864/0x1570 kernel/workqueue.c:2155
 worker_thread+0x64c/0x1130 kernel/workqueue.c:2298
 kthread+0x33f/0x460 kernel/kthread.c:259
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

Showing all locks held in the system:
Node 0 DMA32 free:850916kB min:35996kB low:44992kB high:53988kB active_anon:588900kB inactive_anon:19020kB active_file:46520kB inactive_file:390956kB unevictable:0kB writepending:624kB present:3129332kB managed:2763508kB mlocked:0kB kernel_stack:8768kB pagetables:7052kB bounce:0kB free_pcp:2032kB local_pcp:1244kB free_cma:0kB
4 locks held by kworker/u4:4/1008:
lowmem_reserve[]: 0 0 1 1 1
Node 0 Normal free:28kB min:24kB low:28kB high:32kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:1048576kB managed:2000kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
1 lock held by khungtaskd/1567:
lowmem_reserve[]: 0 0 0 0 0
Node 1 Normal free:4040096kB min:53876kB low:67344kB high:80812kB active_anon:0kB inactive_anon:0kB active_file:144kB inactive_file:0kB unevictable:0kB writepending:4kB present:4194304kB managed:4128248kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
 #0: 0000000098bafcd7 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4440
lowmem_reserve[]: 0 0 0 0 0
1 lock held by in:imklog/7855:
 #0: 00000000f72d0885 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
Node 0 DMA: 1*4kB (U) 0*8kB 0*16kB 1*32kB (U) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15908kB
5 locks held by kworker/1:4/9304:
 #0: 00000000525b112f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 000000009f37e83d ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 0000000004890386 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 0000000004890386 (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
 #3: 0000000040ebb289 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 0000000040ebb289 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 0000000040ebb289 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 0000000040ebb289 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 0000000040ebb289 (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
 #4: 00000000a64acad7 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
1 lock held by syz-executor.4/19307:
1 lock held by syz-executor.4/19313:
Node 0 DMA32: 2072*4kB (UM) 1187*8kB (UME) 1578*16kB (UME) 873*32kB (UM) 312*64kB (UM) 94*128kB (UM) 17*256kB (UME) 12*512kB (UM) 10*1024kB (UM) 20*2048kB (M) 168*4096kB (M) = 852792kB
 #0: 000000008cef180f (&table[i].mutex){+.+.}, at: nfnl_lock net/netfilter/nfnetlink.c:62 [inline]
 #0: 000000008cef180f (&table[i].mutex){+.+.}, at: nfnetlink_rcv_msg+0x98d/0xf60 net/netfilter/nfnetlink.c:228

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

NMI backtrace for cpu 1
CPU: 1 PID: 1567 Comm: khungtaskd Not tainted 4.19.155-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1fc/0x2fe lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x63/0xa2 lib/nmi_backtrace.c:101
Node 0 Normal: 1*4kB (U) 3*8kB (U) 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 28kB
 nmi_trigger_cpumask_backtrace+0x1a6/0x1eb lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
 watchdog+0x991/0xe60 kernel/hung_task.c:287
 kthread+0x33f/0x460 kernel/kthread.c:259
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Node 1 Normal: 92*4kB (UE) 372*8kB (UE) 281*16kB (UME) 82*32kB (UME) 37*64kB (UME) 13*128kB (UME) 11*256kB (UM) 7*512kB (UME) 3*1024kB (UM) 1*2048kB (U) 980*4096kB (M) = 4040096kB
Sending NMI from CPU 1 to CPUs 0:
Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
NMI backtrace for cpu 0
CPU: 0 PID: 19307 Comm: syz-executor.4 Not tainted 4.19.155-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:check_kcov_mode kernel/kcov.c:67 [inline]
RIP: 0010:__sanitizer_cov_trace_pc+0x14/0x50 kernel/kcov.c:101
Code: e8 f0 f9 ea ff 48 c7 05 36 4b bf 0b 00 00 00 00 e9 39 ec ff ff 90 48 8b 34 24 65 48 8b 04 25 80 df 01 00 65 8b 15 6c 10 9d 7e <81> e2 00 01 1f 00 75 2b 8b 90 d8 12 00 00 83 fa 02 75 20 48 8b 88
RSP: 0018:ffff888056726a30 EFLAGS: 00000012
RAX: ffff8880497ca1c0 RBX: ffff888056726af8 RCX: ffffffff8810d2dc
RDX: 0000000080000002 RSI: ffffffff8810d2ea RDI: 0000000000000005
RBP: 0000000000000160 R08: 0000000000000009 R09: 0000000000000063
R10: 0000000000000005 R11: 0000000000000000 R12: 0000000000000160
R13: 0000000000000000 R14: ffffffffffffffff R15: ffffffff8d1f92e1
FS:  00007f0b5fe95700(0000) GS:ffff8880ba000000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f5332148000 CR3: 0000000056d3b000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 put_dec_trunc8+0x2a/0x2f0 lib/vsprintf.c:191
 number+0x9cc/0xa90 lib/vsprintf.c:467
 vsnprintf+0xf07/0x14f0 lib/vsprintf.c:2359
 sprintf+0xc0/0x100 lib/vsprintf.c:2495
 print_time kernel/printk/printk.c:1264 [inline]
 print_prefix+0x265/0x3f0 kernel/printk/printk.c:1287
 msg_print_text+0xcd/0x1c0 kernel/printk/printk.c:1314
 console_unlock+0x321/0x1110 kernel/printk/printk.c:2434
 vprintk_emit+0x2d1/0x740 kernel/printk/printk.c:1965
 vprintk_func+0x79/0x17e kernel/printk/printk_safe.c:397
 printk+0xba/0xed kernel/printk/printk.c:2040
 hugetlb_show_meminfo.cold+0xe7/0x139 mm/hugetlb.c:3063
 show_free_areas+0xc43/0xfb0 mm/page_alloc.c:5062
 show_mem+0x34/0x195 lib/show_mem.c:18
 warn_alloc_show_mem mm/page_alloc.c:3434 [inline]
 warn_alloc.cold+0x123/0x18f mm/page_alloc.c:3458
 __vmalloc_node_range mm/vmalloc.c:1775 [inline]
 __vmalloc_node mm/vmalloc.c:1804 [inline]
 __vmalloc_node_flags mm/vmalloc.c:1818 [inline]
 vzalloc+0x15c/0x1a0 mm/vmalloc.c:1857
 ip_set_alloc+0x8a/0xd0 net/netfilter/ipset/ip_set_core.c:265
 hash_ip_create+0x4e2/0xf00 net/netfilter/ipset/ip_set_hash_gen.h:1296
 ip_set_create+0x6b4/0x1370 net/netfilter/ipset/ip_set_core.c:940
 nfnetlink_rcv_msg+0xc4f/0xf60 net/netfilter/nfnetlink.c:233
 netlink_rcv_skb+0x160/0x440 net/netlink/af_netlink.c:2455
 nfnetlink_rcv+0x1b2/0x41b net/netfilter/nfnetlink.c:565
 netlink_unicast_kernel net/netlink/af_netlink.c:1318 [inline]
 netlink_unicast+0x4d5/0x690 net/netlink/af_netlink.c:1344
 netlink_sendmsg+0x6bb/0xc40 net/netlink/af_netlink.c:1909
 sock_sendmsg_nosec net/socket.c:622 [inline]
 sock_sendmsg+0xc3/0x120 net/socket.c:632
 ___sys_sendmsg+0x7bb/0x8e0 net/socket.c:2115
 __sys_sendmsg net/socket.c:2153 [inline]
 __do_sys_sendmsg net/socket.c:2162 [inline]
 __se_sys_sendmsg net/socket.c:2160 [inline]
 __x64_sys_sendmsg+0x132/0x220 net/socket.c:2160
 do_syscall_64+0xf9/0x620 arch/x86/entry/common.c:293
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45deb9
Code: 0d b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 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 0f 83 db b3 fb ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007f0b5fe94c78 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
RAX: ffffffffffffffda RBX: 0000000000029bc0 RCX: 000000000045deb9
RDX: 0000000000000000 RSI: 00000000200000c0 RDI: 0000000000000003
RBP: 000000000118bf60 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118bf2c
R13: 00007ffe0cb53acf R14: 00007f0b5fe959c0 R15: 000000000118bf2c

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/11/09 11:15 linux-4.19.y b94de4d19498 cba33199 .config console log report info ci2-linux-4-19
* Struck through repros no longer work on HEAD.