[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

We found an INFO: task hung in blkdev_open bug



Hi,

We use our modified Syzkaller to fuzz the Linux kernel and find a bug in the network block device.

This bug can be reproduced on the Linux kernel version 5.10.179.
You can reset it from the master branch.

commit f1b32fda06d2cfb8eea9680b0ba7a8b0d5b81eeb (tag: v5.10.179, origin/linux-5.10.y)
Author: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Date:   Wed Apr 26 11:27:43 2023 +0200

    Linux 5.10.179

I compile the kernel with the .config provided. And booting the kernel, compiling, and running the binary in the guest, which leads to a hung task.

root@syzkaller:~# uname -a
Linux syzkaller 5.10.179 #1 SMP PREEMPT Thu Apr 27 16:22:48 CST 2023 x86_64 GNU/Linux
root@syzkaller:~# gcc poc_blkdev.c -o poc_blkdev
root@syzkaller:~# ./poc_blkdev
[  126.866571][ T1949] block nbd0: Possible stuck request 000000002439ca71: control (read@0,1024B). Runtime 30 seconds
[  126.867464][ T1949] block nbd0: Possible stuck request 000000003e3fb642: control (read@1024,1024B). Runtime 30 seconds
[  156.948517][ T1949] block nbd0: Possible stuck request 000000002439ca71: control (read@0,1024B). Runtime 60 seconds
[  156.949284][ T1949] block nbd0: Possible stuck request 000000003e3fb642: control (read@1024,1024B). Runtime 60 seconds
[  187.029585][ T1949] block nbd0: Possible stuck request 000000002439ca71: control (read@0,1024B). Runtime 90 seconds
[  187.030378][ T1949] block nbd0: Possible stuck request 000000003e3fb642: control (read@1024,1024B). Runtime 90 seconds
[  217.110282][ T1949] block nbd0: Possible stuck request 000000002439ca71: control (read@0,1024B). Runtime 120 seconds
[  217.110314][ T1949] block nbd0: Possible stuck request 000000003e3fb642: control (read@1024,1024B). Runtime 120 seconds
[  247.190786][ T1949] block nbd0: Possible stuck request 000000002439ca71: control (read@0,1024B). Runtime 150 seconds
[  247.191613][ T1949] block nbd0: Possible stuck request 000000003e3fb642: control (read@1024,1024B). Runtime 150 seconds
[  277.271159][ T1949] block nbd0: Possible stuck request 000000002439ca71: control (read@0,1024B). Runtime 180 seconds
[  277.271982][ T1949] block nbd0: Possible stuck request 000000003e3fb642: control (read@1024,1024B). Runtime 180 seconds
[  284.951335][ T1552] INFO: task systemd-udevd:7629 blocked for more than 143 seconds.
[  284.952044][ T1552]       Not tainted 5.10.179 #1
[  284.952368][ T1552] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  284.952928][ T1552] task:systemd-udevd   state:D stack:26160 pid: 7629 ppid:  4451 flags:0x00004304
[  284.953533][ T1552] Call Trace:
[  284.953766][ T1552]  __schedule+0xae4/0x1e10
[  284.954061][ T1552]  ? __sched_text_start+0x8/0x8
[  284.954400][ T1552]  ? preempt_schedule_thunk+0x16/0x18
[  284.954754][ T1552]  ? preempt_schedule_common+0x37/0xc0
[  284.955112][ T1552]  schedule+0xc3/0x270
[  284.955389][ T1552]  io_schedule+0x17/0x70
[  284.955671][ T1552]  wait_on_page_bit_common+0x542/0xcb0
[  284.956032][ T1552]  ? find_get_pages_range_tag+0xe40/0xe40
[  284.956407][ T1552]  ? bdev_disk_changed+0x3f0/0x3f0
[  284.956746][ T1552]  ? end_buffer_async_write+0x5c0/0x5c0
[  284.957112][ T1552]  ? find_get_pages_contig+0xc20/0xc20
[  284.957473][ T1552]  do_read_cache_page+0x66b/0x1000
[  284.957810][ T1552]  ? enable_ptr_key_workfn+0x30/0x30
[  284.958167][ T1552]  read_part_sector+0xf6/0x610
[  284.958486][ T1552]  ? adfspart_check_ADFS+0x800/0x800
[  284.958834][ T1552]  adfspart_check_ICS+0x9a/0xd00
[  284.959161][ T1552]  ? pointer+0x790/0x790
[  284.959442][ T1552]  ? adfspart_check_ADFS+0x800/0x800
[  284.959792][ T1552]  ? snprintf+0xae/0xe0
[  284.960067][ T1552]  ? vsprintf+0x30/0x30
[  284.960353][ T1552]  ? adfspart_check_ADFS+0x800/0x800
[  284.960700][ T1552]  blk_add_partitions+0x47a/0xe70
[  284.961035][ T1552]  bdev_disk_changed+0x249/0x3f0
[  284.961787][ T1552]  __blkdev_get+0xdb8/0x15b0
[  284.962139][ T1552]  ? rcu_read_lock_sched_held+0xd0/0xd0
[  284.962512][ T1552]  ? __blkdev_put+0x720/0x720
[  284.962826][ T1552]  ? devcgroup_check_permission+0x1ac/0x470
[  284.963209][ T1552]  blkdev_get+0xd1/0x250
[  284.963490][ T1552]  blkdev_open+0x20a/0x290
[  284.963783][ T1552]  do_dentry_open+0x69a/0x1240
[  284.964097][ T1552]  ? bd_acquire+0x2c0/0x2c0
[  284.964400][ T1552]  path_openat+0xd7d/0x2720
[  284.964701][ T1552]  ? path_lookupat.isra.41+0x560/0x560
[  284.965059][ T1552]  ? lock_downgrade+0x6a0/0x6a0
[  284.965379][ T1552]  ? alloc_set_pte+0x448/0x1b00
[  284.965697][ T1552]  ? xas_find+0x325/0x900
[  284.965986][ T1552]  ? find_held_lock+0x33/0x1c0
[  284.966316][ T1552]  do_filp_open+0x1a4/0x270
[  284.966617][ T1552]  ? may_open_dev+0xf0/0xf0
[  284.966921][ T1552]  ? rwlock_bug.part.1+0x90/0x90
[  284.967252][ T1552]  ? do_raw_spin_unlock+0x172/0x260
[  284.967595][ T1552]  ? __alloc_fd+0x2a9/0x620
[  284.967907][ T1552]  do_sys_openat2+0x5db/0x8c0
[  284.968218][ T1552]  ? file_open_root+0x400/0x400
[  284.968541][ T1552]  do_sys_open+0xca/0x140
[  284.968830][ T1552]  ? filp_open+0x70/0x70
[  284.969114][ T1552]  ? __secure_computing+0x100/0x360
[  284.969458][ T1552]  do_syscall_64+0x2d/0x70
[  284.969754][ T1552]  entry_SYSCALL_64_after_hwframe+0x61/0xc6
[  284.970146][ T1552] RIP: 0033:0x7fd2bc544840
[  284.970448][ T1552] RSP: 002b:00007ffe6f0c4778 EFLAGS: 00000246 ORIG_RAX: 0000000000000002
[  284.971550][ T1552] RAX: ffffffffffffffda RBX: 000055f0dc215e90 RCX: 00007fd2bc544840
[  284.972099][ T1552] RDX: 000055f0db45cfe3 RSI: 00000000000a0800 RDI: 000055f0dc229760
[  284.972622][ T1552] RBP: 00007ffe6f0c48f0 R08: 000055f0db45c670 R09: 0000000000000010
[  284.973143][ T1552] R10: 000055f0db45cd0c R11: 0000000000000246 R12: 00007ffe6f0c4840
[  284.973666][ T1552] R13: 000055f0dc22aa70 R14: 0000000000000003 R15: 000000000000000e
[  284.974207][ T1552]
[  284.974207][ T1552] Showing all locks held in the system:
[  284.974729][ T1552] 1 lock held by khungtaskd/1552:
[  284.975057][ T1552]  #0: ffffffff8ae9cea0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x52/0x29f
[  284.975721][ T1552] 2 locks held by kworker/u8:0/1940:
[  284.976066][ T1552]  #0: ffff888018636938 ((wq_completion)knbd0-recv){+.+.}-{0:0}, at: process_one_work+0x8e2/0x15d0
[  284.976782][ T1552]  #1: ffff8880110f7e00 ((work_completion)(&args->work)){+.+.}-{0:0}, at: process_one_work+0x917/0x15d0
[  284.977539][ T1552] 1 lock held by in:imklog/7416:
[  284.977860][ T1552]  #0: ffff888041b50ff0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xeb/0x110
[  284.978476][ T1552] 1 lock held by systemd-udevd/7629:
[  284.978819][ T1552]  #0: ffff88800f813480 (&bdev->bd_mutex){+.+.}-{3:3}, at: __blkdev_get+0x45e/0x15b0
[  284.979450][ T1552]
[  284.979606][ T1552] =============================================
[  284.979606][ T1552]
[  284.980153][ T1552] NMI backtrace for cpu 0
[  284.980443][ T1552] CPU: 0 PID: 1552 Comm: khungtaskd Not tainted 5.10.179 #1
[  284.980915][ T1552] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[  284.981513][ T1552] Call Trace:
[  284.981739][ T1552]  dump_stack+0x106/0x162
[  284.982026][ T1552]  nmi_cpu_backtrace.cold.8+0x44/0xd5
[  284.982382][ T1552]  ? lapic_can_unplug_cpu+0x70/0x70
[  284.982725][ T1552]  nmi_trigger_cpumask_backtrace+0x1aa/0x1e0
[  284.983117][ T1552]  watchdog+0xd5a/0xf80
[  284.983398][ T1552]  ? hungtask_pm_notify+0xa0/0xa0
[  284.983726][ T1552]  kthread+0x3aa/0x490
[  284.983994][ T1552]  ? __kthread_cancel_work+0x190/0x190
[  284.984358][ T1552]  ret_from_fork+0x1f/0x30
[  284.984703][ T1552] Sending NMI from CPU 0 to CPUs 1:
[  284.985306][    C1] NMI backtrace for cpu 1
[  284.985309][    C1] CPU: 1 PID: 7417 Comm: rs:main Q:Reg Not tainted 5.10.179 #1
[  284.985312][    C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[  284.985314][    C1] RIP: 0010:check_memory_region+0x11c/0x1e0
[  284.985318][    C1] Code: 00 fc ff df 49 01 d9 49 01 c0 eb 03 49 89 c0 4d 39 c8 0f 84 8a 00 00 00 41 80 38 00 49 8d 40 01 74 ea eb b0 41 bc 08 00 00 00 <45> 29 c4 4d 89 c8 4b 8d 1c 0c eb 0c 49 83 c0 01 48 89 d8 49 39 d8
[  284.985320][    C1] RSP: 0018:ffff888046fef988 EFLAGS: 00000202
4.9853
000000 M Ces1sa]ge  fRroAm Xsy: ffslfogfd@esydzk1al0le0r 9ca9at1 A4pr7 2 8 R07B:5X:0: 003600 0..0.
 K9 R CkeXrn:el :[f  ff28f4.f9fff8386b0654]d[ cT1255e2]
ernel[ p a ni2c 8- 4n.o985326][    C1] RDX: 0000000000000001 RSI: 00000000000005c2 RDI: ffff88804e548a3e
[  284.985328][    C1] RBP: ffffed1009ca9200 R08: 0000000000000007 R09: ffffed1009ca9147
[  284.985331][    C1] R10: ffff88804e548fff R11: ffffed1009ca91ff R12: 0000000000000008
[  284.985333][    C1] R13: 00007f74bc025152 R14: 0000000000000000 R15: 00000000000005c2
[  284.985335][    C1] FS:  00007f74c5e32700(0000) GS:ffff88807ec00000(0000) knlGS:0000000000000000
[  284.985337][    C1] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  284.985339][    C1] CR2: 00007f098c751008 CR3: 0000000049b08000 CR4: 0000000000350ee0
[  284.985341][    C1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  284.985343][    C1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[  284.985345][    C1] Call Trace:
[  284.985346][    C1]  copyin+0xde/0x110
[  284.985348][    C1]  iov_iter_copy_from_user_atomic+0x404/0xcf0
[  284.985349][    C1]  ? rcu_is_watching+0x11/0xb0
[  284.985351][    C1]  ? __mark_inode_dirty+0x13b/0xd90
[  284.985352][    C1]  ? current_time+0xb6/0x120
[  284.985354][    C1]  generic_perform_write+0x337/0x4d0
[  284.985356][    C1]  ? file_update_time+0xd0/0x470
[  284.985357][    C1]  ? filemap_check_errors+0x150/0x150
[  284.985359][    C1]  ? inode_update_time+0xb0/0xb0
[  284.985360][    C1]  ? down_write+0xdb/0x150
[  284.985362][    C1]  ext4_buffered_write_iter+0x20d/0x470
[  284.985363][    C1]  ext4_file_write_iter+0x426/0x1400
[  284.985365][    C1]  ? __lock_acquire+0x1839/0x5e90
[  284.985366][    C1]  ? lock_release+0x631/0x660
[  284.985368][    C1]  ? ext4_buffered_write_iter+0x470/0x470
[  284.985370][    C1]  ? lockdep_hardirqs_on_prepare+0x3f0/0x3f0
[  284.985371][    C1]  new_sync_write+0x491/0x660
[  284.985373][    C1]  ? new_sync_read+0x6e0/0x6e0
[  284.985374][    C1]  ? __fdget_pos+0xeb/0x110
[  284.985376][    C1]  ? rcu_read_lock_held+0xb0/0xb0
[  284.985377][    C1]  vfs_write+0x671/0xa90
[  284.985378][    C1]  ksys_write+0x11f/0x240
[  284.985380][    C1]  ? __ia32_sys_read+0xb0/0xb0
[  284.985381][    C1]  ? syscall_enter_from_user_mode+0x26/0x70
[  284.985383][    C1]  do_syscall_64+0x2d/0x70
[  284.985385][    C1]  entry_SYSCALL_64_after_hwframe+0x61/0xc6
[  284.985386][    C1] RIP: 0033:0x7f74c88761cd
[  284.985390][    C1] Code: c2 20 00 00 75 10 b8 01 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 ae fc ff ff 48 89 04 24 b8 01 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 f7 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
[  284.985392][    C1] RSP: 002b:00007f74c5e31590 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
[  284.985396][    C1] RAX: ffffffffffffffda RBX: 00007f74bc024b90 RCX: 00007f74c88761cd
[  284.985398][    C1] RDX: 0000000000000d21 RSI: 00007f74bc024b90 RDI: 0000000000000006
[  284.985400][    C1] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[  284.985403][    C1] R10: 0000000000000000 R11: 0000000000000293 R12: 00007f74bc024910
[  284.985405][    C1] R13: 00007f74c5e315b0 R14: 0000558be67cb360 R15: 0000000000000d21
[  284.986064][ T1552] Kernel panic - not syncing: hung_task: blocked tasks
[  285.008567][ T1552] CPU: 0 PID: 1552 Comm: khungtaskd Not tainted 5.10.179 #1
[  285.009039][ T1552] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[  285.009625][ T1552] Call Trace:
[  285.009848][ T1552]  dump_stack+0x106/0x162
[  285.010138][ T1552]  panic+0x2d8/0x6fb
[  285.010395][ T1552]  ? print_oops_end_marker.cold.9+0x15/0x15
[  285.010786][ T1552]  ? cpumask_next+0x3c/0x40
[  285.011079][ T1552]  ? printk_safe_flush+0xd7/0x120
[  285.011408][ T1552]  ? watchdog.cold.5+0x5/0x15f
[  285.011719][ T1552]  ? watchdog+0xb36/0xf80
[  285.012003][ T1552]  watchdog.cold.5+0x16/0x15f
[  285.012312][ T1552]  ? hungtask_pm_notify+0xa0/0xa0
[  285.012639][ T1552]  kthread+0x3aa/0x490
[  285.012912][ T1552]  ? __kthread_cancel_work+0x190/0x190
[  285.013269][ T1552]  ret_from_fork+0x1f/0x30
[  285.013915][ T1552] Kernel Offset: disabled
[  285.014241][ T1552] Rebooting in 86400 seconds..


Attachment: kernel_config
Description: Binary data

Attachment: c_poc
Description: Binary data

Attachment: syz_poc
Description: Binary data

Attachment: log
Description: Binary data


Reply to: