Re: [syzbot] WARNING in inc_nlink (3)

[syzbot <syzbot+2b3af42c0644df1e4da9@syzkaller.appspotmail.com>]

Hello,

syzbot tried to test the proposed patch but the build/boot failed:

  T40]  __wait_for_common+0x2af/0x360
[  293.773463][   T40]  ? usleep_range_state+0x1b0/0x1b0
[  293.779742][   T40]  ? bit_wait_io_timeout+0x160/0x160
[  293.785607][   T40]  ? mutex_lock_io_nested+0x1150/0x1150
[  293.791601][   T40]  cpuhp_issue_call+0x4c0/0x900
[  293.796921][   T40]  __cpuhp_setup_state_cpuslocked+0x362/0x8a0
[  293.805189][   T40]  ? nmi_panic_self_stop+0x13/0x20
[  293.810867][   T40]  ? nmi_panic_self_stop+0x20/0x20
[  293.816546][   T40]  ? msr_devnode+0x60/0x60
[  293.821286][   T40]  ? nmi_panic_self_stop+0x20/0x20
[  293.826805][   T40]  __cpuhp_setup_state+0x102/0x2e0
[  293.832648][   T40]  ? set_kbd_reboot+0x85/0x85
[  293.838219][   T40]  msr_init+0xba/0xf8
[  293.842603][   T40]  do_one_initcall+0x103/0x650
[  293.847647][   T40]  ? trace_event_raw_event_initcall_level+0x1f0/0x1f0
[  293.854724][   T40]  ? parameq+0xa0/0x170
[  293.859103][   T40]  kernel_init_freeable+0x6b1/0x73a
[  293.864814][   T40]  ? rest_init+0x3e0/0x3e0
[  293.869732][   T40]  kernel_init+0x1a/0x1d0
[  293.874300][   T40]  ? rest_init+0x3e0/0x3e0
[  293.878927][   T40]  ret_from_fork+0x1f/0x30
[  293.883729][   T40]  </TASK>
[  293.887649][   T40] INFO: task kworker/u17:1:14 blocked for more than 143 seconds.
[  293.898601][   T40]       Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  293.913284][   T40] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  293.924199][   T40] task:kworker/u17:1   state:D stack:25864 pid:   14 ppid:     2 flags:0x00004000
[  293.938171][   T40] Workqueue: events_unbound async_run_entry_fn
[  293.946835][   T40] Call Trace:
[  293.951616][   T40]  <TASK>
[  293.955924][   T40]  __schedule+0xa94/0x4910
[  293.962011][   T40]  ? rwsem_down_write_slowpath+0x4f0/0x1110
[  293.969574][   T40]  ? io_schedule_timeout+0x180/0x180
[  293.978333][   T40]  ? mark_held_locks+0x9f/0xe0
[  293.985859][   T40]  ? rwlock_bug.part.0+0x90/0x90
[  293.994578][   T40]  ? __sanitizer_cov_trace_const_cmp4+0x1c/0x70
[  294.003631][   T40]  schedule+0xd2/0x260
[  294.008912][   T40]  rwsem_down_write_slowpath+0x634/0x1110
[  294.016333][   T40]  ? rwsem_mark_wake+0x960/0x960
[  294.023246][   T40]  ? lock_release+0x720/0x720
[  294.031124][   T40]  down_write+0x135/0x150
[  294.037929][   T40]  ? down_write_killable_nested+0x180/0x180
[  294.046559][   T40]  ? __sanitizer_cov_trace_const_cmp4+0x1c/0x70
[  294.055336][   T40]  ? security_inode_mkdir+0xd6/0x100
[  294.062636][   T40]  vfs_mkdir+0x14e/0x480
[  294.068561][   T40]  ? security_path_mkdir+0x11b/0x160
[  294.076470][   T40]  init_mkdir+0x1cb/0x21d
[  294.083086][   T40]  ? init_unlink+0x1f/0x1f
[  294.089376][   T40]  ? eat+0x8/0x21
[  294.093573][   T40]  do_name+0x223/0x4e5
[  294.099942][   T40]  write_buffer+0x69/0x8c
[  294.106118][   T40]  unpack_to_rootfs+0x228/0x5ce
[  294.112290][   T40]  ? do_utime.isra.0+0xb1/0xb1
[  294.117526][   T40]  ? reserve_initrd_mem+0x31c/0x31c
[  294.122933][   T40]  do_populate_rootfs+0x8c/0x59b
[  294.127669][   T40]  ? reserve_initrd_mem+0x31c/0x31c
[  294.132963][   T40]  ? __sanitizer_cov_trace_cmp4+0x1c/0x70
[  294.138730][   T40]  ? ktime_get+0x30b/0x470
[  294.143235][   T40]  async_run_entry_fn+0x9d/0x550
[  294.148261][   T40]  process_one_work+0x9ac/0x1650
[  294.153403][   T40]  ? pwq_dec_nr_in_flight+0x2a0/0x2a0
[  294.158974][   T40]  ? rwlock_bug.part.0+0x90/0x90
[  294.163988][   T40]  ? _raw_spin_lock_irq+0x41/0x50
[  294.169102][   T40]  worker_thread+0x657/0x1110
[  294.174037][   T40]  ? process_one_work+0x1650/0x1650
[  294.179217][   T40]  kthread+0x2e9/0x3a0
[  294.183411][   T40]  ? kthread_complete_and_exit+0x40/0x40
[  294.189044][   T40]  ret_from_fork+0x1f/0x30
[  294.193523][   T40]  </TASK>
[  294.196714][   T40] INFO: task cpuhp/0:18 blocked for more than 143 seconds.
[  294.203827][   T40]       Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  294.212126][   T40] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  294.220975][   T40] task:cpuhp/0         state:D stack:28392 pid:   18 ppid:     2 flags:0x00004000
[  294.230370][   T40] Call Trace:
[  294.233816][   T40]  <TASK>
[  294.237042][   T40]  __schedule+0xa94/0x4910
[  294.242345][   T40]  ? io_schedule_timeout+0x180/0x180
[  294.248784][   T40]  ? lock_chain_count+0x20/0x20
[  294.254897][   T40]  ? update_load_avg+0x1361/0x1c80
[  294.261329][   T40]  schedule+0xd2/0x260
[  294.266092][   T40]  schedule_timeout+0x1db/0x2a0
[  294.271547][   T40]  ? usleep_range_state+0x1b0/0x1b0
[  294.277306][   T40]  ? __wait_for_common+0x2a6/0x360
[  294.284078][   T40]  ? mark_held_locks+0x9f/0xe0
[  294.289477][   T40]  ? rwlock_bug.part.0+0x90/0x90
[  294.295280][   T40]  ? _raw_spin_unlock_irq+0x1f/0x40
[  294.300495][   T40]  __wait_for_common+0x2af/0x360
[  294.305629][   T40]  ? usleep_range_state+0x1b0/0x1b0
[  294.310921][   T40]  ? bit_wait_io_timeout+0x160/0x160
[  294.316375][   T40]  ? do_raw_spin_lock+0x120/0x2b0
[  294.321595][   T40]  ? rwlock_bug.part.0+0x90/0x90
[  294.326517][   T40]  devtmpfs_submit_req+0xa8/0x100
[  294.331962][   T40]  devtmpfs_create_node+0x175/0x210
[  294.337434][   T40]  ? public_dev_mount+0xf0/0xf0
[  294.343540][   T40]  ? up_write+0x148/0x470
[  294.349334][   T40]  ? kernfs_activate+0x1c4/0x240
[  294.356054][   T40]  ? __sanitizer_cov_trace_const_cmp1+0x22/0x80
[  294.364067][   T40]  ? kernfs_put+0x31/0x50
[  294.369611][   T40]  ? __sanitizer_cov_trace_const_cmp8+0x1d/0x70
[  294.377377][   T40]  ? sysfs_do_create_link_sd+0xbb/0x140
[  294.383203][   T40]  ? sysfs_create_link+0x67/0xc0
[  294.388686][   T40]  device_add+0x1887/0x1e20
[  294.393846][   T40]  ? __fw_devlink_link_to_suppliers+0x2d0/0x2d0
[  294.400571][   T40]  ? rcu_read_lock_sched_held+0x3a/0x70
[  294.406387][   T40]  ? kfree+0x19e/0x2b0
[  294.410641][   T40]  device_create_groups_vargs+0x203/0x280
[  294.417000][   T40]  device_create+0xdf/0x120
[  294.421769][   T40]  ? device_create_groups_vargs+0x280/0x280
[  294.427907][   T40]  ? msr_devnode+0x60/0x60
[  294.432595][   T40]  ? trace_cpuhp_enter+0x1a0/0x240
[  294.438127][   T40]  ? msr_devnode+0x60/0x60
[  294.443645][   T40]  msr_device_create+0x22/0x40
[  294.448754][   T40]  cpuhp_invoke_callback+0x3b5/0x9a0
[  294.454362][   T40]  ? _raw_spin_unlock_irqrestore+0x50/0x70
[  294.460401][   T40]  cpuhp_thread_fun+0x477/0x6f0
[  294.465363][   T40]  ? cpuhp_invoke_callback+0x9a0/0x9a0
[  294.470781][   T40]  ? cpuhp_invoke_callback+0x9a0/0x9a0
[  294.476300][   T40]  smpboot_thread_fn+0x645/0x9c0
[  294.482127][   T40]  ? smpboot_register_percpu_thread+0x370/0x370
[  294.488774][   T40]  kthread+0x2e9/0x3a0
[  294.492910][   T40]  ? kthread_complete_and_exit+0x40/0x40
[  294.498827][   T40]  ret_from_fork+0x1f/0x30
[  294.503371][   T40]  </TASK>
[  294.506551][   T40] INFO: task kdevtmpfs:34 blocked for more than 144 seconds.
[  294.513994][   T40]       Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  294.522452][   T40] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  294.531256][   T40] task:kdevtmpfs       state:D stack:27864 pid:   34 ppid:     2 flags:0x00004000
[  294.540541][   T40] Call Trace:
[  294.543865][   T40]  <TASK>
[  294.546801][   T40]  __schedule+0xa94/0x4910
[  294.551370][   T40]  ? rwsem_down_write_slowpath+0x4f0/0x1110
[  294.557485][   T40]  ? io_schedule_timeout+0x180/0x180
[  294.564113][   T40]  ? mark_held_locks+0x9f/0xe0
[  294.569111][   T40]  ? rwlock_bug.part.0+0x90/0x90
[  294.574299][   T40]  schedule+0xd2/0x260
[  294.578540][   T40]  rwsem_down_write_slowpath+0x634/0x1110
[  294.585525][   T40]  ? rwsem_mark_wake+0x960/0x960
[  294.591953][   T40]  ? lock_release+0x720/0x720
[  294.597261][   T40]  down_write+0x135/0x150
[  294.602723][   T40]  ? down_write_killable_nested+0x180/0x180
[  294.609897][   T40]  ? __sanitizer_cov_trace_const_cmp4+0x1c/0x70
[  294.617453][   T40]  ? security_inode_mkdir+0xd6/0x100
[  294.624180][   T40]  vfs_mkdir+0x14e/0x480
[  294.628766][   T40]  handle_create+0x198/0x4b3
[  294.633669][   T40]  ? handle_remove+0x5fe/0x5fe
[  294.638746][   T40]  ? find_held_lock+0x2d/0x110
[  294.644918][   T40]  ? devtmpfsd+0xaa/0x2a3
[  294.650442][   T40]  ? lock_downgrade+0x6e0/0x6e0
[  294.656642][   T40]  ? do_raw_spin_lock+0x120/0x2b0
[  294.662888][   T40]  ? rwlock_bug.part.0+0x90/0x90
[  294.667815][   T40]  devtmpfsd+0x1a4/0x2a3
[  294.672413][   T40]  ? dmar_validate_one_drhd+0x24d/0x24d
[  294.678087][   T40]  kthread+0x2e9/0x3a0
[  294.682289][   T40]  ? kthread_complete_and_exit+0x40/0x40
[  294.688394][   T40]  ret_from_fork+0x1f/0x30
[  294.694162][   T40]  </TASK>
[  294.698633][   T40] INFO: task kworker/u17:2:72 blocked for more than 144 seconds.
[  294.707590][   T40]       Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  294.717373][   T40] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  294.728402][   T40] task:kworker/u17:2   state:D stack:30064 pid:   72 ppid:     2 flags:0x00004000
[  294.739692][   T40] Call Trace:
[  294.743823][   T40]  <TASK>
[  294.747163][   T40]  __schedule+0xa94/0x4910
[  294.751403][   T40]  ? io_schedule_timeout+0x180/0x180
[  294.756615][   T40]  ? _raw_spin_unlock_irqrestore+0x50/0x70
[  294.763671][   T40]  schedule+0xd2/0x260
[  294.768621][   T40]  async_synchronize_cookie_domain+0x1f9/0x270
[  294.776319][   T40]  ? lowest_in_progress+0xf0/0xf0
[  294.782484][   T40]  ? __put_cred+0x1ca/0x250
[  294.787920][   T40]  ? finish_wait+0x270/0x270
[  294.793531][   T40]  wait_for_initramfs+0x54/0x70
[  294.799402][   T40]  call_usermodehelper_exec_async+0x26f/0x580
[  294.805433][   T40]  ? umh_complete+0x90/0x90
[  294.811421][   T40]  ret_from_fork+0x1f/0x30
[  294.815924][   T40]  </TASK>
[  294.818784][   T40] INFO: task kworker/u17:2:73 blocked for more than 144 seconds.
[  294.828170][   T40]       Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  294.836590][   T40] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  294.847531][   T40] task:kworker/u17:2   state:D stack:30568 pid:   73 ppid:     2 flags:0x00004000
[  294.858846][   T40] Call Trace:
[  294.862986][   T40]  <TASK>
[  294.867040][   T40]  __schedule+0xa94/0x4910
[  294.872483][   T40]  ? io_schedule_timeout+0x180/0x180
[  294.878112][   T40]  ? _raw_spin_unlock_irqrestore+0x50/0x70
[  294.886377][   T40]  schedule+0xd2/0x260
[  294.891591][   T40]  async_synchronize_cookie_domain+0x1f9/0x270
[  294.898880][   T40]  ? lowest_in_progress+0xf0/0xf0
[  294.904378][   T40]  ? __put_cred+0x1ca/0x250
[  294.909096][   T40]  ? finish_wait+0x270/0x270
[  294.913629][   T40]  wait_for_initramfs+0x54/0x70
[  294.919093][   T40]  call_usermodehelper_exec_async+0x26f/0x580
[  294.925513][   T40]  ? umh_complete+0x90/0x90
[  294.929924][   T40]  ret_from_fork+0x1f/0x30
[  294.934401][   T40]  </TASK>
[  294.937561][   T40] INFO: task kworker/u17:3:74 blocked for more than 144 seconds.
[  294.945887][   T40]       Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  294.954060][   T40] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  294.963310][   T40] task:kworker/u17:3   state:D stack:30568 pid:   74 ppid:     2 flags:0x00004000
[  294.972248][   T40] Call Trace:
[  294.975488][   T40]  <TASK>
[  294.978265][   T40]  __schedule+0xa94/0x4910
[  294.983603][   T40]  ? io_schedule_timeout+0x180/0x180
[  294.989790][   T40]  ? _raw_spin_unlock_irqrestore+0x50/0x70
[  294.995642][   T40]  schedule+0xd2/0x260
[  294.999416][   T40]  async_synchronize_cookie_domain+0x1f9/0x270
[  295.005448][   T40]  ? lowest_in_progress+0xf0/0xf0
[  295.010336][   T40]  ? __put_cred+0x1ca/0x250
[  295.014764][   T40]  ? finish_wait+0x270/0x270
[  295.019451][   T40]  wait_for_initramfs+0x54/0x70
[  295.024262][   T40]  call_usermodehelper_exec_async+0x26f/0x580
[  295.030181][   T40]  ? umh_complete+0x90/0x90
[  295.034685][   T40]  ret_from_fork+0x1f/0x30
[  295.038963][   T40]  </TASK>
[  295.042042][   T40] INFO: task kworker/u17:3:75 blocked for more than 144 seconds.
[  295.049634][   T40]       Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  295.057755][   T40] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  295.068019][   T40] task:kworker/u17:3   state:D stack:30568 pid:   75 ppid:     2 flags:0x00004000
[  295.077460][   T40] Call Trace:
[  295.080693][   T40]  <TASK>
[  295.083643][   T40]  __schedule+0xa94/0x4910
[  295.087978][   T40]  ? io_schedule_timeout+0x180/0x180
[  295.094151][   T40]  ? _raw_spin_unlock_irqrestore+0x50/0x70
[  295.101291][   T40]  schedule+0xd2/0x260
[  295.106289][   T40]  async_synchronize_cookie_domain+0x1f9/0x270
[  295.113479][   T40]  ? lowest_in_progress+0xf0/0xf0
[  295.118558][   T40]  ? __put_cred+0x1ca/0x250
[  295.123338][   T40]  ? finish_wait+0x270/0x270
[  295.128015][   T40]  wait_for_initramfs+0x54/0x70
[  295.132899][   T40]  call_usermodehelper_exec_async+0x26f/0x580
[  295.139455][   T40]  ? umh_complete+0x90/0x90
[  295.144352][   T40]  ret_from_fork+0x1f/0x30
[  295.149168][   T40]  </TASK>
[  295.152281][   T40] 
[  295.152281][   T40] Showing all locks held in the system:
[  295.160764][   T40] 2 locks held by swapper/0/1:
[  295.165758][   T40]  #0: ffffffff8ba2dbd0 (cpu_hotplug_lock){++++}-{0:0}, at: msr_init+0xba/0xf8
[  295.174911][   T40]  #1: ffffffff8ba30168 (cpuhp_state_mutex){+.+.}-{3:3}, at: __cpuhp_setup_state_cpuslocked+0xfb/0x8a0
[  295.187105][   T40] 5 locks held by kworker/u17:1/14:
[  295.192488][   T40]  #0: ffff888010c75138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x890/0x1650
[  295.204173][   T40]  #1: ffffc9000061fdb8 ((work_completion)(&entry->work)){+.+.}-{0:0}, at: process_one_work+0x8c4/0x1650
[  295.216602][   T40]  #2: ffff888011650460 (sb_writers#2){.+.+}-{0:0}, at: filename_create+0xf3/0x480
[  295.226100][   T40]  #3: ffff888011004bb0 (&sb->s_type->i_mutex_key/1){+.+.}-{3:3}, at: filename_create+0x158/0x480
[  295.237689][   T40]  #4: ffff888011004bb0 (&sb->s_type->i_mutex_key){++++}-{3:3}, at: vfs_mkdir+0x14e/0x480
[  295.248214][   T40] 2 locks held by cpuhp/0/18:
[  295.253178][   T40]  #0: ffffffff8ba2dbd0 (cpu_hotplug_lock){++++}-{0:0}, at: cpuhp_thread_fun+0x113/0x6f0
[  295.263845][   T40]  #1: ffffffff8ba30220 (cpuhp_state-up){+.+.}-{0:0}, at: cpuhp_thread_fun+0x113/0x6f0
[  295.273729][   T40] 3 locks held by kdevtmpfs/34:
[  295.278876][   T40]  #0: ffff888011c2a460 (sb_writers){.+.+}-{0:0}, at: filename_create+0xf3/0x480
[  295.288685][   T40]  #1: ffff8880402fe2b8 (&type->i_mutex_dir_key/1){+.+.}-{3:3}, at: filename_create+0x158/0x480
[  295.299519][   T40]  #2: ffff8880402fe2b8 (&type->i_mutex_dir_key#2){++++}-{3:3}, at: vfs_mkdir+0x14e/0x480
[  295.309472][   T40] 1 lock held by khungtaskd/40:
[  295.314423][   T40]  #0: ffffffff8bb820a0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260
[  295.324434][   T40] 2 locks held by kworker/u17:3/71:
[  295.329391][   T40]  #0: ffff888010c75138 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work+0x890/0x1650
[  295.341345][   T40]  #1: ffffc90000c87db8 ((kfence_timer).work){+.+.}-{0:0}, at: process_one_work+0x8c4/0x1650
[  295.351499][   T40] 
[  295.353647][   T40] =============================================
[  295.353647][   T40] 
[  295.361947][   T40] Kernel panic - not syncing: hung_task: blocked tasks
[  295.368642][   T40] CPU: 0 PID: 40 Comm: khungtaskd Not tainted 5.17.0-rc7-syzkaller-00235-gaad611a868d1-dirty #0
[  295.371822][   T40] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.14.0-2 04/01/2014
[  295.371822][   T40] Call Trace:
[  295.371822][   T40]  <TASK>
[  295.371822][   T40]  dump_stack_lvl+0xcd/0x134
[  295.371822][   T40]  panic+0x2b0/0x6dd
[  295.371822][   T40]  ? __warn_printk+0xf3/0xf3
[  295.371822][   T40]  ? watchdog.cold+0x130/0x158
[  295.371822][   T40]  watchdog.cold+0x141/0x158
[  295.371822][   T40]  ? proc_dohung_task_timeout_secs+0x80/0x80
[  295.371822][   T40]  kthread+0x2e9/0x3a0
[  295.371822][   T40]  ? kthread_complete_and_exit+0x40/0x40
[  295.371822][   T40]  ret_from_fork+0x1f/0x30
[  295.371822][   T40]  </TASK>
[  295.371822][   T40] Kernel Offset: disabled
[  295.371822][   T40] Rebooting in 86400 seconds..


Error text is too large and was truncated, full error text is at:
https://syzkaller.appspot.com/x/error.txt?x=10b74233700000


Tested on:

commit:         aad611a8 Merge tag 'perf-tools-fixes-for-v5.17-2022-03..
git tree:       https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/
kernel config:  https://syzkaller.appspot.com/x/.config?x=aba0ab2928a512c2
dashboard link: https://syzkaller.appspot.com/bug?extid=2b3af42c0644df1e4da9
compiler:       gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2
patch:          https://syzkaller.appspot.com/x/patch.diff?x=1223085d700000