On 12/24/20 3:51 AM, Fengfei Xi wrote:
> We have encountered the following problems several times:
> 1、A raid slot or hardware problem causes block device loss.
> 2、Continue to issue IO requests to the problematic block device.
> 3、The system possibly crash after a few hours.
What kernel is this on?
> dmesg log as below:
> [15205901.268313] blk_partition_remap: fail for partition 1
I think this message has been gone since kernel v4.16...
If you're testing this on an old kernel, can you reproduce it on a
current kernel?
> [15205901.319309] blk_partition_remap: fail for partition 1
> [15205901.319341] blk_partition_remap: fail for partition 1
> [15205901.319873] sysctl (3998546): drop_caches: 3
What performed the drop_caches immediately before the BUG? Does
the BUG happen without drop_caches?
> [15205901.371379] BUG: unable to handle kernel NULL pointer dereference at
was something lost here? "dereference at" ... what?
> [15205901.372602] IP: xfs_buf_offset+0x32/0x60 [xfs]
> [15205901.373605] PGD 0 P4D 0
> [15205901.374690] Oops: 0000 [#1] SMP
> [15205901.375629] Modules linked in:
> [15205901.382445] CPU: 6 PID: 18545 Comm: xfsaild/sdh1 Kdump: loaded Tainted: G
> [15205901.384728] Hardware name:
> [15205901.385830] task: ffff885216939e80 task.stack: ffffb28ba9b38000
> [15205901.386974] RIP: 0010:xfs_buf_offset+0x32/0x60 [xfs]
> [15205901.388044] RSP: 0018:ffffb28ba9b3bc68 EFLAGS: 00010246
> [15205901.389021] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 000000000000000b
> [15205901.390016] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88627bebf000
> [15205901.391075] RBP: ffffb28ba9b3bc98 R08: ffff88627bebf000 R09: 00000001802a000d
> [15205901.392031] R10: ffff88521f3a0240 R11: ffff88627bebf000 R12: ffff88521041e000
> [15205901.392950] R13: 0000000000000020 R14: ffff88627bebf000 R15: 0000000000000000
> [15205901.393858] FS: 0000000000000000(0000) GS:ffff88521f380000(0000) knlGS:0000000000000000
> [15205901.394774] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [15205901.395756] CR2: 0000000000000000 CR3: 000000099bc09001 CR4: 00000000007606e0
> [15205901.396904] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [15205901.397869] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [15205901.398836] PKRU: 55555554
> [15205901.400111] Call Trace:
> [15205901.401058] ? xfs_inode_buf_verify+0x8e/0xf0 [xfs]
> [15205901.402069] ? xfs_buf_delwri_submit_buffers+0x16d/0x2b0 [xfs]
> [15205901.403060] xfs_inode_buf_write_verify+0x10/0x20 [xfs]
> [15205901.404017] _xfs_buf_ioapply+0x88/0x410 [xfs]
> [15205901.404990] ? xfs_buf_delwri_submit_buffers+0x16d/0x2b0 [xfs]
> [15205901.405929] xfs_buf_submit+0x63/0x200 [xfs]
> [15205901.406801] xfs_buf_delwri_submit_buffers+0x16d/0x2b0 [xfs]
> [15205901.407675] ? xfs_buf_delwri_submit_nowait+0x10/0x20 [xfs]
> [15205901.408540] ? xfs_inode_item_push+0xb7/0x190 [xfs]
> [15205901.409395] xfs_buf_delwri_submit_nowait+0x10/0x20 [xfs]
> [15205901.410249] xfsaild+0x29a/0x780 [xfs]
> [15205901.411121] kthread+0x109/0x140
> [15205901.411981] ? xfs_trans_ail_cursor_first+0x90/0x90 [xfs]
> [15205901.412785] ? kthread_park+0x60/0x60
> [15205901.413578] ret_from_fork+0x2a/0x40
>
> The "obvious" cause is that the bp->b_pages was NULL in function
> xfs_buf_offset. Analyzing vmcore, we found that b_pages=NULL but
> b_page_count=16, so b_pages is set to NULL for some reason.
this can happen, for example _xfs_buf_get_pages sets the count, but may
fail the allocation, and leave the count set while the pointer is NULL.
>
> crash> struct xfs_buf ffff88627bebf000 | less
> ...
> b_pages = 0x0,
> b_page_array = {0x0, 0x0},
> b_maps = 0xffff88627bebf118,
> __b_map = {
> bm_bn = 512,
> bm_len = 128
> },
> b_map_count = 1,
> b_io_length = 128,
> b_pin_count = {
> counter = 0
> },
> b_io_remaining = {
> counter = 1
> },
> b_page_count = 16,
> b_offset = 0,
> b_error = 0,
> ...
>
> To avoid system crash, we can add the check of 'bp->b_pages' to
> xfs_inode_buf_verify(). If b_pages == NULL, we mark the buffer
> as -EFSCORRUPTED and the IO will not dispatched.
>
> Signed-off-by: Fengfei Xi <xi.fengfei@xxxxxxx>
> Reviewed-by: Xianting Tian <tian.xianting@xxxxxxx>
> ---
> fs/xfs/libxfs/xfs_inode_buf.c | 11 +++++++++++
> 1 file changed, 11 insertions(+)
>
> diff --git a/fs/xfs/libxfs/xfs_inode_buf.c b/fs/xfs/libxfs/xfs_inode_buf.c
> index c667c63f2..5a485c51f 100644
> --- a/fs/xfs/libxfs/xfs_inode_buf.c
> +++ b/fs/xfs/libxfs/xfs_inode_buf.c
> @@ -45,6 +45,17 @@ xfs_inode_buf_verify(
> int i;
> int ni;
>
> + /*
> + * Don't crash and mark buffer EFSCORRUPTED when b_pages is NULL
> + */
> + if (!bp->b_pages) {
> + xfs_buf_ioerror(bp, -EFSCORRUPTED);
> + xfs_alert(mp,
> + "xfs_buf(%p) b_pages corruption detected at %pS\n",
> + bp, __return_address);
> + return;
> + }
This seems fairly ad hoc.
I think we need a better idea of how we got here; why should inode buffers
be uniquely impacted (or defensively protected?) Can you reproduce this
using virtual devices so the test can be scripted?
-Eric
