On Wed 21-04-21 20:38:43, yebin wrote:
> On 2021/4/21 17:21, Jan Kara wrote:
> > On Tue 20-04-21 22:25:18, Ye Bin wrote:
> > > We got follow bug_on when run fsstress with injecting IO fault:
> > > [130747.323114] kernel BUG at fs/ext4/extents_status.c:762!
> > > [130747.323117] Internal error: Oops - BUG: 0 [#1] SMP
> > Which BUG_ON is that please? I don't see any relevant one near that line in
> > current upstream kernel...
> ext4_es_cache_extent:
> ......
> if (!len)
> return;
>
> BUG_ON(end < lblk); --> BUG_ON at here.
> ......
OK, thanks. But this means 'end' has actually overflown... Not that two
extents overlap.
> > > ......
> > > [130747.334329] Call trace:
> > > [130747.334553] ext4_es_cache_extent+0x150/0x168 [ext4]
> > > [130747.334975] ext4_cache_extents+0x64/0xe8 [ext4]
> > > [130747.335368] ext4_find_extent+0x300/0x330 [ext4]
> > > [130747.335759] ext4_ext_map_blocks+0x74/0x1178 [ext4]
> > > [130747.336179] ext4_map_blocks+0x2f4/0x5f0 [ext4]
> > > [130747.336567] ext4_mpage_readpages+0x4a8/0x7a8 [ext4]
> > > [130747.336995] ext4_readpage+0x54/0x100 [ext4]
> > > [130747.337359] generic_file_buffered_read+0x410/0xae8
> > > [130747.337767] generic_file_read_iter+0x114/0x190
> > > [130747.338152] ext4_file_read_iter+0x5c/0x140 [ext4]
> > > [130747.338556] __vfs_read+0x11c/0x188
> > > [130747.338851] vfs_read+0x94/0x150
> > > [130747.339110] ksys_read+0x74/0xf0
> > >
> > > If call ext4_ext_insert_extent failed but new extent already inserted, we just
> > > update "ex->ee_len = orig_ex.ee_len", this will lead to extent overlap, then
> > > cause bug on when cache extent.
> > > If call ext4_ext_insert_extent failed don't update ex->ee_len with old value.
> > > Maybe there will lead to block leak, but it can be fixed by fsck later.
> > Thanks for the analysis and the patch but the fact is that the extent tree
> > is going to be corrupted one way or the other. And I think other disk
> > corruptions can lead to similar problematic extent layout anyway. So I
> > rather think we need to make the code more robust to not take the kernel
> > down when seeing corrupted extent tree - and we've done work to make code
> > more robust in this sence in the past. Can you reproduce the issue with the
> > current upstream kernel? If yes, we are probably still missing extent tree
> > consistency checks on some path and we need to add them...
> >
> > Honza
> I will try to reproduce this issue with the current upstream kernel.
> Actually, the reason of this
> issue is obvious, as i reproduced this issue with kernel-4.19.95 and got
> follow information:
> We inject IO fault when runing fsstress, JBD detect IO error then trigger
> JBD abort. At the same time,
> if ext4_ext_insert_extent already insert new extent then call ext4_ext_dirty
> to dirty metadata , but
> JBD already aborted , ext4_ext_dirty will return error.
OK, upto this point things are as I've expected.
> In ext4_ext_dirty function call ext4_ext_check_inode check extent if ok, if
> not, trigger BUG_ON and
> also print extent detail information. I caught follow call trace and extent
> information:
But where does ext4_ext_dirty() call ext4_ext_check_inode()? I don't see it
neither in the current upstream nor in 4.19.y stable tree.
Honza
> =================================================================================
>
> [ 7597.436071] inode 1808 ext4_ext_check_inode
> [ 7597.436074] inode[1808]: [4] lblk=76 len=5 orig_len=32773 prev=0
> [ 7597.436077] inode[1808]: [3] lblk=81 len=25 orig_len=25 prev=81
> [ 7597.436080] inode[1808]: [2] lblk=106 len=130 orig_len=32898 prev=106
> [ 7597.436084] inode[1808]: [1] lblk=228 len=8 orig_len=32776 prev=236
> [ 7597.436181] ------------[ cut here ]------------
> [ 7597.436183] kernel BUG at fs/ext4/extents.c:221!
> [ 7597.436216] invalid opcode: 0000 [#1] SMP KASAN
> [ 7597.436219] Buffer I/O error on dev sda, logical block 131072, lost sync
> page write
> [ 7597.436224] CPU: 7 PID: 5157 Comm: kworker/u16:1 Not tainted
> 4.19.95-00020-gb095ded9163d-dirty #186
> [ 7597.436230] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
> ?-20190727_073836-buildvm-ppc64le-16.ppc.fedoraproject.org-3.fc31 04/01/2014
> [ 7597.436242] Workqueue: writeback wb_workfn (flush-8:16)
> [ 7597.436248] RIP: 0010:__ext4_ext_dirty.cold+0x2ee/0x308
> [ 7597.436251] Code: ff 48 89 df e8 c7 e1 d0 ff e9 48 ff ff ff 48 c7 c7 80
> d1 f7 ae e8 87 45 84 ff 48 83 05 ee 3b ca 07 01 48 83 05 c6 3c ca 07 01 <0f>
> 04
> [ 7597.436253] RSP: 0018:ffff88838bcaf050 EFLAGS: 00010202
> [ 7597.436256] RAX: 0000000000000000 RBX: ffff888364b67783 RCX:
> 0000000000000000
> [ 7597.436258] RDX: 0000000000000001 RSI: 0000000000000008 RDI:
> ffffed1071795dfd
> [ 7597.436259] RBP: 000000000000003b R08: 0000000000000000 R09:
> 0000000000000001
> [ 7597.436261] R10: ffffed10744fbd6e R11: ffff8883a27deb77 R12:
> dffffc0000000000
> [ 7597.436262] R13: dffffc0000000000 R14: ffff888364b673f0 R15:
> ffff888364b6730c
> [ 7597.436264] FS: 0000000000000000(0000) GS:ffff8883a27c0000(0000)
> knlGS:0000000000000000
> [ 7597.436266] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 7597.436267] CR2: 00007fca7a249000 CR3: 000000039ce75000 CR4:
> 00000000000006e0
> [ 7597.436270] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
> 0000000000000000
> [ 7597.436271] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7:
> 0000000000000400
> [ 7597.436275] JBD2: Error -5 detected when updating journal superblock for
> sda-8.
> [ 7597.436277] Call Trace:
> [ 7597.436294] ext4_split_extent_at+0x785/0xc80
> [ 7597.466767] ext4_split_extent.isra.0+0x2af/0x550
> [ 7597.472503] ext4_ext_convert_to_initialized+0x4b4/0x2510
> [ 7597.536999] ext4_ext_map_blocks+0x37ef/0x50c0
> [ 7597.542467] ext4_map_blocks+0x685/0x1910
> [ 7597.544107] ext4_writepages+0x1809/0x32f0
> [ 7597.547546] do_writepages+0x7f/0x1b0
> [ 7597.548619] __writeback_single_inode+0xc6/0xc40
> [ 7597.549203] writeback_sb_inodes+0x49f/0xd60
> [ 7597.550748] wb_writeback+0x252/0x9d0
> [ 7597.552335] wb_workfn+0x309/0xe60
> [ 7597.557029] process_one_work+0x70b/0x1610
> [ 7597.557566] worker_thread+0x5a9/0x1060
> [ 7597.559091] kthread+0x35e/0x430
> [ 7597.560601] ret_from_fork+0x1f/0x30
> =================================================================================
>
> Obviously, the follow extent is overlap:
> [ 7597.436080] inode[1808]: [2] lblk=106 len=130 orig_len=32898 prev=106
> [ 7597.436084] inode[1808]: [1] lblk=228 len=8 orig_len=32776 prev=236
> > > Signed-off-by: Ye Bin <yebin10@xxxxxxxxxx>
> > > ---
> > > fs/ext4/extents.c | 5 ++++-
> > > 1 file changed, 4 insertions(+), 1 deletion(-)
> > >
> > > diff --git a/fs/ext4/extents.c b/fs/ext4/extents.c
> > > index 77c84d6f1af6..6161db9c17c9 100644
> > > --- a/fs/ext4/extents.c
> > > +++ b/fs/ext4/extents.c
> > > @@ -3245,8 +3245,11 @@ static int ext4_split_extent_at(handle_t *handle,
> > > err = ext4_zeroout_es(inode, &zero_ex);
> > > goto out;
> > > - } else if (err)
> > > + } else if (err == -EROFS) {
> > > + return err;
> > > + } else {
> > > goto fix_extent_len;
> > > + }
> > > out:
> > > ext4_ext_show_leaf(inode, path);
> > > --
> > > 2.25.4
> > >
>
--
Jan Kara <jack@xxxxxxxx>
SUSE Labs, CR
