diff mbox series

[-next] ext4: fix bug_on in start_this_handle during umount filesystem

Message ID 20220322012419.725457-1-yebin10@huawei.com
State Awaiting Upstream
Headers show
Series [-next] ext4: fix bug_on in start_this_handle during umount filesystem | expand

Commit Message

yebin (H) March 22, 2022, 1:24 a.m. UTC 
We got issue as follows:
------------[ cut here ]------------
kernel BUG at fs/jbd2/transaction.c:389!
invalid opcode: 0000 [#1] PREEMPT SMP KASAN PTI
CPU: 9 PID: 131 Comm: kworker/9:1 Not tainted 5.17.0-862.14.0.6.x86_64-00001-g23f87daf7d74-dirty #197
Workqueue: events flush_stashed_error_work
RIP: 0010:start_this_handle+0x41c/0x1160
RSP: 0018:ffff888106b47c20 EFLAGS: 00010202
RAX: ffffed10251b8400 RBX: ffff888128dc204c RCX: ffffffffb52972ac
RDX: 0000000000000200 RSI: 0000000000000004 RDI: ffff888128dc2050
RBP: 0000000000000039 R08: 0000000000000001 R09: ffffed10251b840a
R10: ffff888128dc204f R11: ffffed10251b8409 R12: ffff888116d78000
R13: 0000000000000000 R14: dffffc0000000000 R15: ffff888128dc2000
FS:  0000000000000000(0000) GS:ffff88839d680000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000001620068 CR3: 0000000376c0e000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <TASK>
 jbd2__journal_start+0x38a/0x790
 jbd2_journal_start+0x19/0x20
 flush_stashed_error_work+0x110/0x2b3
 process_one_work+0x688/0x1080
 worker_thread+0x8b/0xc50
 kthread+0x26f/0x310
 ret_from_fork+0x22/0x30
 </TASK>
Modules linked in:
---[ end trace 0000000000000000 ]---

Above issue may happen as follows:
      umount            read procfs            error_work
ext4_put_super
  flush_work(&sbi->s_error_work);

                      ext4_mb_seq_groups_show
	                ext4_mb_load_buddy_gfp
			  ext4_mb_init_group
			    ext4_mb_init_cache
	                      ext4_read_block_bitmap_nowait
			        ext4_validate_block_bitmap
				  ext4_error
			            ext4_handle_error
			              schedule_work(&EXT4_SB(sb)->s_error_work);

  ext4_unregister_sysfs(sb);
  jbd2_journal_destroy(sbi->s_journal);
    journal_kill_thread
      journal->j_flags |= JBD2_UNMOUNT;

                                          flush_stashed_error_work
				            jbd2_journal_start
					      start_this_handle
					        BUG_ON(journal->j_flags & JBD2_UNMOUNT);

To solve this issue, we call 'ext4_unregister_sysfs' in 'ext4_put_super' firstly
like 'ext4_fill_super' error handle.

Signed-off-by: Ye Bin <yebin10@huawei.com>
---
 fs/ext4/super.c | 19 ++++++++++++-------
 1 file changed, 12 insertions(+), 7 deletions(-)

Comments

Ritesh Harjani March 22, 2022, 4:41 a.m. UTC | #1 
On 22/03/22 09:24AM, Ye Bin wrote:
> We got issue as follows:
> ------------[ cut here ]------------
> kernel BUG at fs/jbd2/transaction.c:389!
> invalid opcode: 0000 [#1] PREEMPT SMP KASAN PTI
> CPU: 9 PID: 131 Comm: kworker/9:1 Not tainted 5.17.0-862.14.0.6.x86_64-00001-g23f87daf7d74-dirty #197
> Workqueue: events flush_stashed_error_work
> RIP: 0010:start_this_handle+0x41c/0x1160
> RSP: 0018:ffff888106b47c20 EFLAGS: 00010202
> RAX: ffffed10251b8400 RBX: ffff888128dc204c RCX: ffffffffb52972ac
> RDX: 0000000000000200 RSI: 0000000000000004 RDI: ffff888128dc2050
> RBP: 0000000000000039 R08: 0000000000000001 R09: ffffed10251b840a
> R10: ffff888128dc204f R11: ffffed10251b8409 R12: ffff888116d78000
> R13: 0000000000000000 R14: dffffc0000000000 R15: ffff888128dc2000
> FS:  0000000000000000(0000) GS:ffff88839d680000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 0000000001620068 CR3: 0000000376c0e000 CR4: 00000000000006e0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Call Trace:
>  <TASK>
>  jbd2__journal_start+0x38a/0x790
>  jbd2_journal_start+0x19/0x20
>  flush_stashed_error_work+0x110/0x2b3
>  process_one_work+0x688/0x1080
>  worker_thread+0x8b/0xc50
>  kthread+0x26f/0x310
>  ret_from_fork+0x22/0x30
>  </TASK>
> Modules linked in:
> ---[ end trace 0000000000000000 ]---
>
> Above issue may happen as follows:
>       umount            read procfs            error_work
> ext4_put_super
>   flush_work(&sbi->s_error_work);
>
>                       ext4_mb_seq_groups_show
> 	                ext4_mb_load_buddy_gfp
> 			  ext4_mb_init_group
> 			    ext4_mb_init_cache
> 	                      ext4_read_block_bitmap_nowait
> 			        ext4_validate_block_bitmap
> 				  ext4_error
					^^^^^^^ I am guessing this occurred due to some error
injection framework? or was it a bad disk?

> 			            ext4_handle_error
> 			              schedule_work(&EXT4_SB(sb)->s_error_work);
>
>   ext4_unregister_sysfs(sb);
>   jbd2_journal_destroy(sbi->s_journal);
>     journal_kill_thread
>       journal->j_flags |= JBD2_UNMOUNT;
>
>                                           flush_stashed_error_work
> 				            jbd2_journal_start
> 					      start_this_handle
> 					        BUG_ON(journal->j_flags & JBD2_UNMOUNT);
>
> To solve this issue, we call 'ext4_unregister_sysfs' in 'ext4_put_super' firstly
> like 'ext4_fill_super' error handle.

I don't see a reason why not. In fact to simulate this more reliably and to add
a fstest around this - we could do following.
(If we are adding a fstest we might also explore checking other exported sysfs options
racing with umount/mount or module load/unload).
Like in past it was journal_task at [1]


Thread-1 												Thread-2
while [ 1 ]:  							   				while [ 1 ]:
  echo 1 > /sys/fs/ext4/<dev>/trigger_fs_error            umount /dev/<dev>
  sleep random 											  sleep random
  														  mount /dev/<dev> /mnt

Currently we call flush_work(&sbi->s_error_work) and then
ext4_unregister_sysfs(). So if someone triggered an fs error before
unregistering from sysfs, it will schedule_work() which might race similar
to jbd2_journal_destroy() like what you showed above.

So calling ext4_unregister_sysfs() as the first thing in ext4_put_super(),
looks good to me.

Reviewed-by: Ritesh Harjani <riteshh@linux.ibm.com>


[1]: https://lore.kernel.org/all/20200318061301.4320-1-riteshh@linux.ibm.com/


>
> Signed-off-by: Ye Bin <yebin10@huawei.com>
> ---
>  fs/ext4/super.c | 19 ++++++++++++-------
>  1 file changed, 12 insertions(+), 7 deletions(-)
>
> diff --git a/fs/ext4/super.c b/fs/ext4/super.c
> index 81749eaddf4c..a673012e35c8 100644
> --- a/fs/ext4/super.c
> +++ b/fs/ext4/super.c
> @@ -1199,20 +1199,25 @@ static void ext4_put_super(struct super_block *sb)
>  	int aborted = 0;
>  	int i, err;
>
> -	ext4_unregister_li_request(sb);
> -	ext4_quota_off_umount(sb);
> -
> -	flush_work(&sbi->s_error_work);
> -	destroy_workqueue(sbi->rsv_conversion_wq);
> -	ext4_release_orphan_info(sb);
> -
>  	/*
>  	 * Unregister sysfs before destroying jbd2 journal.
>  	 * Since we could still access attr_journal_task attribute via sysfs
>  	 * path which could have sbi->s_journal->j_task as NULL
> +	 * Unregister sysfs before flush sbi->s_error_work.
> +	 * Since user may read /proc/fs/ext4/xx/mb_groups during umount, If
> +	 * read metadata verify failed then will queue error work.
> +	 * flush_stashed_error_work will call start_this_handle may trigger
> +	 * BUG_ON.
>  	 */
>  	ext4_unregister_sysfs(sb);
>
> +	ext4_unregister_li_request(sb);
> +	ext4_quota_off_umount(sb);
> +
> +	flush_work(&sbi->s_error_work);
> +	destroy_workqueue(sbi->rsv_conversion_wq);
> +	ext4_release_orphan_info(sb);
> +
>  	if (sbi->s_journal) {
>  		aborted = is_journal_aborted(sbi->s_journal);
>  		err = jbd2_journal_destroy(sbi->s_journal);
> --
> 2.31.1
>
Jan Kara March 22, 2022, 10:48 a.m. UTC | #2 
On Tue 22-03-22 09:24:19, Ye Bin wrote:
> We got issue as follows:
> ------------[ cut here ]------------
> kernel BUG at fs/jbd2/transaction.c:389!
> invalid opcode: 0000 [#1] PREEMPT SMP KASAN PTI
> CPU: 9 PID: 131 Comm: kworker/9:1 Not tainted 5.17.0-862.14.0.6.x86_64-00001-g23f87daf7d74-dirty #197
> Workqueue: events flush_stashed_error_work
> RIP: 0010:start_this_handle+0x41c/0x1160
> RSP: 0018:ffff888106b47c20 EFLAGS: 00010202
> RAX: ffffed10251b8400 RBX: ffff888128dc204c RCX: ffffffffb52972ac
> RDX: 0000000000000200 RSI: 0000000000000004 RDI: ffff888128dc2050
> RBP: 0000000000000039 R08: 0000000000000001 R09: ffffed10251b840a
> R10: ffff888128dc204f R11: ffffed10251b8409 R12: ffff888116d78000
> R13: 0000000000000000 R14: dffffc0000000000 R15: ffff888128dc2000
> FS:  0000000000000000(0000) GS:ffff88839d680000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 0000000001620068 CR3: 0000000376c0e000 CR4: 00000000000006e0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Call Trace:
>  <TASK>
>  jbd2__journal_start+0x38a/0x790
>  jbd2_journal_start+0x19/0x20
>  flush_stashed_error_work+0x110/0x2b3
>  process_one_work+0x688/0x1080
>  worker_thread+0x8b/0xc50
>  kthread+0x26f/0x310
>  ret_from_fork+0x22/0x30
>  </TASK>
> Modules linked in:
> ---[ end trace 0000000000000000 ]---
> 
> Above issue may happen as follows:
>       umount            read procfs            error_work
> ext4_put_super
>   flush_work(&sbi->s_error_work);
> 
>                       ext4_mb_seq_groups_show
> 	                ext4_mb_load_buddy_gfp
> 			  ext4_mb_init_group
> 			    ext4_mb_init_cache
> 	                      ext4_read_block_bitmap_nowait
> 			        ext4_validate_block_bitmap
> 				  ext4_error
> 			            ext4_handle_error
> 			              schedule_work(&EXT4_SB(sb)->s_error_work);
> 
>   ext4_unregister_sysfs(sb);
>   jbd2_journal_destroy(sbi->s_journal);
>     journal_kill_thread
>       journal->j_flags |= JBD2_UNMOUNT;
> 
>                                           flush_stashed_error_work
> 				            jbd2_journal_start
> 					      start_this_handle
> 					        BUG_ON(journal->j_flags & JBD2_UNMOUNT);
> 
> To solve this issue, we call 'ext4_unregister_sysfs' in 'ext4_put_super' firstly
> like 'ext4_fill_super' error handle.
> 
> Signed-off-by: Ye Bin <yebin10@huawei.com>

Looks good. Thanks! Feel free to add:

Reviewed-by: Jan Kara <jack@suse.cz>

								Honza

> ---
>  fs/ext4/super.c | 19 ++++++++++++-------
>  1 file changed, 12 insertions(+), 7 deletions(-)
> 
> diff --git a/fs/ext4/super.c b/fs/ext4/super.c
> index 81749eaddf4c..a673012e35c8 100644
> --- a/fs/ext4/super.c
> +++ b/fs/ext4/super.c
> @@ -1199,20 +1199,25 @@ static void ext4_put_super(struct super_block *sb)
>  	int aborted = 0;
>  	int i, err;
>  
> -	ext4_unregister_li_request(sb);
> -	ext4_quota_off_umount(sb);
> -
> -	flush_work(&sbi->s_error_work);
> -	destroy_workqueue(sbi->rsv_conversion_wq);
> -	ext4_release_orphan_info(sb);
> -
>  	/*
>  	 * Unregister sysfs before destroying jbd2 journal.
>  	 * Since we could still access attr_journal_task attribute via sysfs
>  	 * path which could have sbi->s_journal->j_task as NULL
> +	 * Unregister sysfs before flush sbi->s_error_work.
> +	 * Since user may read /proc/fs/ext4/xx/mb_groups during umount, If
> +	 * read metadata verify failed then will queue error work.
> +	 * flush_stashed_error_work will call start_this_handle may trigger
> +	 * BUG_ON.
>  	 */
>  	ext4_unregister_sysfs(sb);
>  
> +	ext4_unregister_li_request(sb);
> +	ext4_quota_off_umount(sb);
> +
> +	flush_work(&sbi->s_error_work);
> +	destroy_workqueue(sbi->rsv_conversion_wq);
> +	ext4_release_orphan_info(sb);
> +
>  	if (sbi->s_journal) {
>  		aborted = is_journal_aborted(sbi->s_journal);
>  		err = jbd2_journal_destroy(sbi->s_journal);
> -- 
> 2.31.1
>
Theodore Ts'o April 3, 2022, 2:08 p.m. UTC | #3 
On Tue, 22 Mar 2022 09:24:19 +0800, Ye Bin wrote:
> We got issue as follows:
> ------------[ cut here ]------------
> kernel BUG at fs/jbd2/transaction.c:389!
> invalid opcode: 0000 [#1] PREEMPT SMP KASAN PTI
> CPU: 9 PID: 131 Comm: kworker/9:1 Not tainted 5.17.0-862.14.0.6.x86_64-00001-g23f87daf7d74-dirty #197
> Workqueue: events flush_stashed_error_work
> RIP: 0010:start_this_handle+0x41c/0x1160
> RSP: 0018:ffff888106b47c20 EFLAGS: 00010202
> RAX: ffffed10251b8400 RBX: ffff888128dc204c RCX: ffffffffb52972ac
> RDX: 0000000000000200 RSI: 0000000000000004 RDI: ffff888128dc2050
> RBP: 0000000000000039 R08: 0000000000000001 R09: ffffed10251b840a
> R10: ffff888128dc204f R11: ffffed10251b8409 R12: ffff888116d78000
> R13: 0000000000000000 R14: dffffc0000000000 R15: ffff888128dc2000
> FS:  0000000000000000(0000) GS:ffff88839d680000(0000) knlGS:0000000000000000
> CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> CR2: 0000000001620068 CR3: 0000000376c0e000 CR4: 00000000000006e0
> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Call Trace:
>  <TASK>
>  jbd2__journal_start+0x38a/0x790
>  jbd2_journal_start+0x19/0x20
>  flush_stashed_error_work+0x110/0x2b3
>  process_one_work+0x688/0x1080
>  worker_thread+0x8b/0xc50
>  kthread+0x26f/0x310
>  ret_from_fork+0x22/0x30
>  </TASK>
> Modules linked in:
> ---[ end trace 0000000000000000 ]---
> 
> [...]

Applied, thanks!

[1/1] ext4: fix bug_on in start_this_handle during umount filesystem
      commit: 20164749617e56d584313ad775d6dd3b7da40dc1

Best regards,
diff mbox series

Patch

diff --git a/fs/ext4/super.c b/fs/ext4/super.c
index 81749eaddf4c..a673012e35c8 100644
--- a/fs/ext4/super.c
+++ b/fs/ext4/super.c
@@ -1199,20 +1199,25 @@  static void ext4_put_super(struct super_block *sb)
 	int aborted = 0;
 	int i, err;
 
-	ext4_unregister_li_request(sb);
-	ext4_quota_off_umount(sb);
-
-	flush_work(&sbi->s_error_work);
-	destroy_workqueue(sbi->rsv_conversion_wq);
-	ext4_release_orphan_info(sb);
-
 	/*
 	 * Unregister sysfs before destroying jbd2 journal.
 	 * Since we could still access attr_journal_task attribute via sysfs
 	 * path which could have sbi->s_journal->j_task as NULL
+	 * Unregister sysfs before flush sbi->s_error_work.
+	 * Since user may read /proc/fs/ext4/xx/mb_groups during umount, If
+	 * read metadata verify failed then will queue error work.
+	 * flush_stashed_error_work will call start_this_handle may trigger
+	 * BUG_ON.
 	 */
 	ext4_unregister_sysfs(sb);
 
+	ext4_unregister_li_request(sb);
+	ext4_quota_off_umount(sb);
+
+	flush_work(&sbi->s_error_work);
+	destroy_workqueue(sbi->rsv_conversion_wq);
+	ext4_release_orphan_info(sb);
+
 	if (sbi->s_journal) {
 		aborted = is_journal_aborted(sbi->s_journal);
 		err = jbd2_journal_destroy(sbi->s_journal);