Message-ID: <CAO4mrfexzxeYwAkvWGfg=tEiczUWarO6y68KFD9EG9qZtGejng@mail.gmail.com>
Date:   Mon, 31 Oct 2022 22:18:02 +0800
From:   Wei Chen <harperchen1110@...il.com>
To:     tytso@....edu, jaegeuk@...nel.org, ebiggers@...nel.org
Cc:     linux-fscrypt@...r.kernel.org, linux-kernel@...r.kernel.org
Subject: Re: INFO: task hung in fscrypt_ioctl_set_policy

Dear Linux developers,

Here is the link to the reproducers.

C reproducer: https://drive.google.com/file/d/1mduYsYuoOKemH3qkvpDQwnAHAaaLUp0Y/view?usp=share_link
Syz reproducer:
https://drive.google.com/file/d/1mu-_w7dy_562vWRlQvTRbcBjG4_G7b2L/view?usp=share_link

The bug persists in the latest commit, v5.15.76 (4f5365f77018). I hope
it is helpful to you.

[ 1782.137186][   T30] INFO: task a.out:6910 blocked for more than 143 seconds.
[ 1782.139217][   T30]       Not tainted 5.15.76 #5
[ 1782.140388][   T30] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1782.142524][   T30] task:a.out           state:D stack:14296 pid:
6910 ppid:  6532 flags:0x00004004
[ 1782.144799][   T30] Call Trace:
[ 1782.145623][   T30]  <TASK>
[ 1782.146316][   T30]  __schedule+0x3e8/0x1850
[ 1782.152029][   T30]  ? mark_held_locks+0x49/0x70
[ 1782.153533][   T30]  ? mark_held_locks+0x10/0x70
[ 1782.154759][   T30]  ? __down_write_common.part.14+0x31f/0x7b0
[ 1782.156159][   T30]  schedule+0x4e/0xe0
[ 1782.158314][   T30]  __down_write_common.part.14+0x324/0x7b0
[ 1782.159704][   T30]  ? fscrypt_ioctl_set_policy+0xe0/0x200
[ 1782.161050][   T30]  fscrypt_ioctl_set_policy+0xe0/0x200
[ 1782.162330][   T30]  __f2fs_ioctl+0x9d6/0x45e0
[ 1782.163417][   T30]  f2fs_ioctl+0x64/0x240
[ 1782.164404][   T30]  ? __f2fs_ioctl+0x45e0/0x45e0
[ 1782.165554][   T30]  __x64_sys_ioctl+0xb6/0x100
[ 1782.166662][   T30]  do_syscall_64+0x34/0xb0
[ 1782.169947][   T30]  entry_SYSCALL_64_after_hwframe+0x61/0xcb
[ 1782.171348][   T30] RIP: 0033:0x7f55690bb469
[ 1782.172385][   T30] RSP: 002b:00007f556976aef8 EFLAGS: 00000246
ORIG_RAX: 0000000000000010
[ 1782.174344][   T30] RAX: ffffffffffffffda RBX: 0000000000000000
RCX: 00007f55690bb469
[ 1782.176198][   T30] RDX: 0000000020002900 RSI: 00000000800c6613
RDI: 0000000000000003
[ 1782.179056][   T30] RBP: 00007f556976af20 R08: 0000000000000000
R09: 0000000000000000
[ 1782.180945][   T30] R10: 0000000000000000 R11: 0000000000000246
R12: 00007ffee37a15ce
[ 1782.182812][   T30] R13: 00007ffee37a15cf R14: 00007f556974b000
R15: 0000000000000003
[ 1782.184690][   T30]  </TASK>
[ 1782.185445][   T30]
[ 1782.185445][   T30] Showing all locks held in the system:
[ 1782.189142][   T30] 1 lock held by khungtaskd/30:
[ 1782.190295][   T30]  #0: ffffffff85a1dc60
(rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0xe/0x1a0
[ 1782.192615][   T30] 1 lock held by in:imklog/6238:
[ 1782.193768][   T30]  #0: ffff88810a68f6f0
(&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x55/0x60
[ 1782.204980][   T30] 2 locks held by a.out/6900:
[ 1782.206094][   T30] 2 locks held by a.out/6910:
[ 1782.208314][   T30]  #0: ffff888011f73460
(sb_writers#14){.+.+}-{0:0}, at: fscrypt_ioctl_set_policy+0xc6/0x200
[ 1782.210728][   T30]  #1: ffff888013f49350
(&type->i_mutex_dir_key#8){+.+.}-{3:3}, at:
fscrypt_ioctl_set_policy+0xe0/0x200
[ 1782.213346][   T30]
[ 1782.213891][   T30] =============================================
[ 1782.213891][   T30]
[ 1782.215851][   T30] NMI backtrace for cpu 1
[ 1782.216913][   T30] CPU: 1 PID: 30 Comm: khungtaskd Not tainted 5.15.76 #5
[ 1782.218539][   T30] Hardware name: QEMU Standard PC (i440FX + PIIX,
1996), BIOS rel-1.13.0-48-gd9c812dda519-prebuilt.qemu.org 04/01/2014
[ 1782.221460][   T30] Call Trace:
[ 1782.222289][   T30]  <TASK>
[ 1782.223009][   T30]  dump_stack_lvl+0x8d/0xcf
[ 1782.224108][   T30]  nmi_cpu_backtrace+0x1e9/0x210
[ 1782.225309][   T30]  ? lapic_can_unplug_cpu+0x90/0x90
[ 1782.226550][   T30]  nmi_trigger_cpumask_backtrace+0x129/0x190
[ 1782.228048][   T30]  watchdog+0x4e1/0x970
[ 1782.229093][   T30]  ? hungtask_pm_notify+0x70/0x70
[ 1782.230337][   T30]  kthread+0x178/0x1b0
[ 1782.231359][   T30]  ? set_kthread_struct+0x50/0x50
[ 1782.232617][   T30]  ret_from_fork+0x1f/0x30
[ 1782.233731][   T30]  </TASK>
[ 1782.234606][   T30] Sending NMI from CPU 1 to CPUs 0:
[ 1782.235927][    C0] NMI backtrace for cpu 0
[ 1782.235933][    C0] CPU: 0 PID: 2974 Comm: systemd-journal Not
tainted 5.15.76 #5
[ 1782.235940][    C0] Hardware name: QEMU Standard PC (i440FX + PIIX,
1996), BIOS rel-1.13.0-48-gd9c812dda519-prebuilt.qemu.org 04/01/2014
[ 1782.235946][    C0] RIP: 0010:__lock_acquire+0x840/0x1d90
[ 1782.235958][    C0] Code: d2 75 17 e8 e2 26 ff 00 85 c0 74 0e 8b 05
60 e4 e1 04 85 c0 0f 84 29 02 00 00 31 c0 48 83 78 40 00 75 02 0f 0b
0f b7 44 24 28 <8b> 4c 24 30 c1 e0 0d 66 0b 44 24 20 98 2b 44 24 18 33
44 24 10 89
[ 1782.235965][    C0] RSP: 0018:ffffc9000080bdb0 EFLAGS: 00000082
[ 1782.235971][    C0] RAX: 0000000000000000 RBX: ffff88801024dd60
RCX: 0000000000000008
[ 1782.235975][    C0] RDX: 0000000000000008 RSI: 0000000000000000
RDI: 0000000000000000
[ 1782.235979][    C0] RBP: 00000000000000a4 R08: 0000000000000000
R09: 0000000000000001
[ 1782.235983][    C0] R10: 0000000000000000 R11: 0000000000000000
R12: 0000000000000001
[ 1782.235986][    C0] R13: ffff88801024d340 R14: ffff88801024dd60
R15: ffffffffffffffff
[ 1782.235991][    C0] FS:  00007f88e2cda8c0(0000)
GS:ffff88807dc00000(0000) knlGS:0000000000000000
[ 1782.235999][    C0] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1782.236003][    C0] CR2: 00007f88e0039008 CR3: 0000000011fc2000
CR4: 00000000003506f0
[ 1782.236007][    C0] DR0: 0000000000000000 DR1: 0000000000000000
DR2: 0000000000000000
[ 1782.236011][    C0] DR3: 0000000000000000 DR6: 00000000fffe0ff0
DR7: 0000000000000400
[ 1782.236015][    C0] Call Trace:
[ 1782.236017][    C0]  <TASK>
[ 1782.236022][    C0]  lock_acquire+0x294/0x350
[ 1782.236030][    C0]  ? __context_tracking_exit+0x88/0x1f0
[ 1782.236040][    C0]  ? __context_tracking_enter+0x100/0x210
[ 1782.236047][    C0]  vtime_user_exit+0x50/0xe0
[ 1782.236056][    C0]  ? __context_tracking_exit+0x88/0x1f0
[ 1782.236062][    C0]  __context_tracking_exit+0x88/0x1f0
[ 1782.236069][    C0]  syscall_enter_from_user_mode+0x4a/0x70
[ 1782.236077][    C0]  do_syscall_64+0x15/0xb0
[ 1782.236083][    C0]  entry_SYSCALL_64_after_hwframe+0x61/0xcb
[ 1782.236092][    C0] RIP: 0033:0x7f88e1f73f17
[ 1782.236098][    C0] Code: ff ff ff 48 8b 4d a0 0f b7 51 fe 48 8b 4d
a8 66 89 54 08 fe e9 1a ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 b8 27
00 00 00 0f 05 <c3> 0f 1f 84 00 00 00 00 00 b8 6e 00 00 00 0f 05 c3 0f
1f 84 00 00
[ 1782.236104][    C0] RSP: 002b:00007fff9ce26b28 EFLAGS: 00000202
ORIG_RAX: 0000000000000027
[ 1782.236110][    C0] RAX: ffffffffffffffda RBX: 000055d5d4d9d1e0
RCX: 00007f88e1f73f17
[ 1782.236114][    C0] RDX: 00000000ffffffff RSI: 00007fff9ce26bb0
RDI: 000055d5d4d9d1e0
[ 1782.236118][    C0] RBP: 0000000000000b9e R08: 00007fff9cedf080
R09: 00007fff9cedf080
[ 1782.236122][    C0] R10: 0000000000034d62 R11: 0000000000000202
R12: 00007fff9ce26bb0
[ 1782.236126][    C0] R13: 00007fff9ce26ba8 R14: 000055d5d3122958
R15: 0005ec5535de5711
[ 1782.236132][    C0]  </TASK>
[ 1782.267071][   T30] Kernel panic - not syncing: hung_task: blocked tasks
[ 1782.301186][   T30] CPU: 1 PID: 30 Comm: khungtaskd Not tainted 5.15.76 #5
[ 1782.302914][   T30] Hardware name: QEMU Standard PC (i440FX + PIIX,
1996), BIOS rel-1.13.0-48-gd9c812dda519-prebuilt.qemu.org 04/01/2014
[ 1782.305923][   T30] Call Trace:
[ 1782.306711][   T30]  <TASK>
[ 1782.307482][   T30]  dump_stack_lvl+0x8d/0xcf
[ 1782.308605][   T30]  panic+0x165/0x3ed
[ 1782.309572][   T30]  ? watchdog+0x4f8/0x970
[ 1782.310645][   T30]  watchdog+0x504/0x970
[ 1782.311670][   T30]  ? hungtask_pm_notify+0x70/0x70
[ 1782.312906][   T30]  kthread+0x178/0x1b0
[ 1782.313914][   T30]  ? set_kthread_struct+0x50/0x50
[ 1782.315142][   T30]  ret_from_fork+0x1f/0x30
[ 1782.316235][   T30]  </TASK>
[ 1782.317156][   T30] Kernel Offset: disabled
[ 1782.318271][   T30] Rebooting in 86400 seconds..

Best,
Wei


On Sun, 30 Oct 2022 at 18:40, Wei Chen <harperchen1110@...il.com> wrote:
>
> Dear Linux Developer,
>
> Recently when using our tool to fuzz kernel, the following crash was triggered:
>
> HEAD commit: 64570fbc14f8 Linux 5.15-rc5
> git tree: upstream
> compiler: gcc 8.0.1
> console output:
> https://drive.google.com/file/d/1QcXGrdd3Li0ylo1WBfswWukWV__QZS4h/view?usp=share_link
> kernel config: https://drive.google.com/file/d/1uDOeEYgJDcLiSOrx9W8v2bqZ6uOA_55t/view?usp=share_link
>
> 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: Wei Chen <harperchen1110@...il.com>
>
> INFO: task syz-executor.0:29056 blocked for more than 143 seconds.
>       Not tainted 5.15.0-rc5 #1
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor.0  state:D stack:14632 pid:29056 ppid:  6574 flags:0x00000004
> Call Trace:
>  __schedule+0x4a1/0x1720
>  schedule+0x36/0xe0
>  rwsem_down_write_slowpath+0x322/0x7a0
>  fscrypt_ioctl_set_policy+0x11f/0x2a0
>  __f2fs_ioctl+0x1a9f/0x5780
>  f2fs_ioctl+0x89/0x3a0
>  __x64_sys_ioctl+0xe8/0x140
>  do_syscall_64+0x34/0xb0
>  entry_SYSCALL_64_after_hwframe+0x44/0xae
> RIP: 0033:0x4692c9
> RSP: 002b:00007f9fecafbc38 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00000000004692c9
> RDX: 0000000020002900 RSI: 00000000800c6613 RDI: 0000000000000003
> RBP: 000000000119c1d8 R08: 0000000000000000 R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000246 R12: 000000000119c1d4
> R13: 0000000000000000 R14: 000000000119c1c8 R15: 00007fffbfabbc40
>
> Showing all locks held in the system:
> 1 lock held by khungtaskd/29:
>  #0: ffffffff8641dee0 (rcu_read_lock){....}-{1:2}, at:
> debug_show_all_locks+0x15/0x17a
> 1 lock held by kswapd0/269:
> 1 lock held by in:imklog/6194:
>  #0: ffff888100174ef0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x92/0xa0
> 1 lock held by systemd-udevd/16539:
> 3 locks held by syz-executor.0/29046:
> 2 locks held by syz-executor.0/29056:
>  #0: ffff88811912f460 (sb_writers#22){.+.+}-{0:0}, at:
> fscrypt_ioctl_set_policy+0xfc/0x2a0
>  #1: ffff88810a98e3f8 (&type->i_mutex_dir_key#12){++++}-{3:3}, at:
> fscrypt_ioctl_set_policy+0x11f/0x2a0
>
> =============================================
>
> NMI backtrace for cpu 1
> CPU: 1 PID: 29 Comm: khungtaskd Not tainted 5.15.0-rc5 #1
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> rel-1.13.0-48-gd9c812dda519-prebuilt.qemu.org 04/01/2014
> Call Trace:
>  dump_stack_lvl+0xcd/0x134
>  nmi_cpu_backtrace.cold.8+0xf3/0x118
>  nmi_trigger_cpumask_backtrace+0x18f/0x1c0
>  watchdog+0x9a0/0xb10
>  kthread+0x1a6/0x1e0
>  ret_from_fork+0x1f/0x30
> Sending NMI from CPU 1 to CPUs 0:
> NMI backtrace for cpu 0
> CPU: 0 PID: 2973 Comm: systemd-journal Not tainted 5.15.0-rc5 #1
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> rel-1.13.0-48-gd9c812dda519-prebuilt.qemu.org 04/01/2014
> RIP: 0010:lock_is_held_type+0xff/0x140
> Code: 10 00 00 ba ff ff ff ff 65 0f c1 15 cb 92 43 7b 83 fa 01 75 28
> 9c 58 f6 c4 02 75 3c 41 f7 c7 00 02 00 00 74 01 fb 48 83 c4 08 <44> 89
> e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 45 31 ed eb ba 0f 0b 48
> RSP: 0018:ffffc9000079bd80 EFLAGS: 00000292
> RAX: 0000000000000046 RBX: 0000000000000000 RCX: 0000000000000001
> RDX: 0000000000000001 RSI: 0000000000000000 RDI: 0000000000000000
> RBP: ffffffff8641dea0 R08: 0000000000000000 R09: 0000000000000001
> R10: ffffffff86462280 R11: 0000000000000000 R12: ffff8881050bd280
> R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000246
> FS:  00007f0a317238c0(0000) GS:ffff88807dc00000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 00007f0a2d3c2000 CR3: 0000000012f8f000 CR4: 00000000003506f0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Call Trace:
>  ___might_sleep+0x21/0x150
>  kmem_cache_alloc+0x279/0x310
>  getname_flags+0x5f/0x2c0
>  do_sys_openat2+0x3c8/0x6a0
>  do_sys_open+0x84/0xe0
>  do_syscall_64+0x34/0xb0
>  entry_SYSCALL_64_after_hwframe+0x44/0xae
> RIP: 0033:0x7f0a30cb385d
> Code: bb 20 00 00 75 10 b8 02 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31
> c3 48 83 ec 08 e8 1e f6 ff ff 48 89 04 24 b8 02 00 00 00 0f 05 <48> 8b
> 3c 24 48 89 c2 e8 67 f6 ff ff 48 89 d0 48 83 c4 08 48 3d 01
> RSP: 002b:00007fff8f43b630 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
> RAX: ffffffffffffffda RBX: 00007fff8f43b940 RCX: 00007f0a30cb385d
> RDX: 00000000000001a0 RSI: 0000000000080042 RDI: 0000555919efe460
> RBP: 000000000000000d R08: 000000000000ffc0 R09: 00000000ffffffff
> R10: 0000000000000069 R11: 0000000000000293 R12: 00000000ffffffff
> R13: 0000555919ef1040 R14: 00007fff8f43b900 R15: 0000555919efe280
> ----------------
> Code disassembly (best guess):
>    0: 10 00                adc    %al,(%rax)
>    2: 00 ba ff ff ff ff    add    %bh,-0x1(%rdx)
>    8: 65 0f c1 15 cb 92 43 xadd   %edx,%gs:0x7b4392cb(%rip)        # 0x7b4392db
>    f: 7b
>   10: 83 fa 01              cmp    $0x1,%edx
>   13: 75 28                jne    0x3d
>   15: 9c                    pushfq
>   16: 58                    pop    %rax
>   17: f6 c4 02              test   $0x2,%ah
>   1a: 75 3c                jne    0x58
>   1c: 41 f7 c7 00 02 00 00 test   $0x200,%r15d
>   23: 74 01                je     0x26
>   25: fb                    sti
>   26: 48 83 c4 08          add    $0x8,%rsp
> * 2a: 44 89 e8              mov    %r13d,%eax <-- trapping instruction
>   2d: 5b                    pop    %rbx
>   2e: 5d                    pop    %rbp
>   2f: 41 5c                pop    %r12
>   31: 41 5d                pop    %r13
>   33: 41 5e                pop    %r14
>   35: 41 5f                pop    %r15
>   37: c3                    retq
>   38: 45 31 ed              xor    %r13d,%r13d
>   3b: eb ba                jmp    0xfffffff7
>   3d: 0f 0b                ud2
>   3f: 48                    rex.W
>
> Best,
> Wei

Powered by blists - more mailing lists