2022-04-27 11:40:23

by Naoya Horiguchi

[permalink] [raw]
Subject: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

From: Naoya Horiguchi <[email protected]>

The following VM_BUG_ON_FOLIO() is triggered when memory error event
happens on the (thp/folio) pages which are about to be freed:

[ 1160.232771] page:00000000b36a8a0f refcount:1 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
[ 1160.236916] page:00000000b36a8a0f refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
[ 1160.240684] flags: 0x57ffffc0800000(hwpoison|node=1|zone=2|lastcpupid=0x1fffff)
[ 1160.243458] raw: 0057ffffc0800000 dead000000000100 dead000000000122 0000000000000000
[ 1160.246268] raw: 0000000000000001 0000000000000000 00000000ffffffff 0000000000000000
[ 1160.249197] page dumped because: VM_BUG_ON_FOLIO(!folio_test_large(folio))
[ 1160.251815] ------------[ cut here ]------------
[ 1160.253438] kernel BUG at include/linux/mm.h:788!
[ 1160.256162] invalid opcode: 0000 [#1] PREEMPT SMP PTI
[ 1160.258172] CPU: 2 PID: 115368 Comm: mceinj.sh Tainted: G E 5.18.0-rc1-v5.18-rc1-220404-2353-005-g83111+ #3
[ 1160.262049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1.fc35 04/01/2014
[ 1160.265103] RIP: 0010:dump_page.cold+0x27e/0x2bd
[ 1160.266757] Code: fe ff ff 48 c7 c6 81 f1 5a 98 e9 4c fe ff ff 48 c7 c6 a1 95 59 98 e9 40 fe ff ff 48 c7 c6 50 bf 5a 98 48 89 ef e8 9d 04 6d ff <0f> 0b 41 f7 c4 ff 0f 00 00 0f 85 9f fd ff ff 49 8b 04 24 a9 00 00
[ 1160.273180] RSP: 0018:ffffaa2c4d59fd18 EFLAGS: 00010292
[ 1160.274969] RAX: 000000000000003e RBX: 0000000000000001 RCX: 0000000000000000
[ 1160.277263] RDX: 0000000000000001 RSI: ffffffff985995a1 RDI: 00000000ffffffff
[ 1160.279571] RBP: ffffdc9c45a80000 R08: 0000000000000000 R09: 00000000ffffdfff
[ 1160.281794] R10: ffffaa2c4d59fb08 R11: ffffffff98940d08 R12: ffffdc9c45a80000
[ 1160.283920] R13: ffffffff985b6f94 R14: 0000000000000000 R15: ffffdc9c45a80000
[ 1160.286641] FS: 00007eff54ce1740(0000) GS:ffff99c67bd00000(0000) knlGS:0000000000000000
[ 1160.289498] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1160.291106] CR2: 00005628381a5f68 CR3: 0000000104712003 CR4: 0000000000170ee0
[ 1160.293031] Call Trace:
[ 1160.293724] <TASK>
[ 1160.294334] get_hwpoison_page+0x47d/0x570
[ 1160.295474] memory_failure+0x106/0xaa0
[ 1160.296474] ? security_capable+0x36/0x50
[ 1160.297524] hard_offline_page_store+0x43/0x80
[ 1160.298684] kernfs_fop_write_iter+0x11c/0x1b0
[ 1160.299829] new_sync_write+0xf9/0x160
[ 1160.300810] vfs_write+0x209/0x290
[ 1160.301835] ksys_write+0x4f/0xc0
[ 1160.302718] do_syscall_64+0x3b/0x90
[ 1160.303664] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 1160.304981] RIP: 0033:0x7eff54b018b7

As shown in the RIP address, this VM_BUG_ON in folio_entire_mapcount() is
called from dump_page("hwpoison: unhandlable page") in get_any_page().
The below explains the mechanism of the race:

CPU 0 CPU 1

memory_failure
get_hwpoison_page
get_any_page
dump_page
compound = PageCompound
free_pages_prepare
page->flags &= ~PAGE_FLAGS_CHECK_AT_PREP
folio_entire_mapcount
VM_BUG_ON_FOLIO(!folio_test_large(folio))

So replace dump_page() with safer one, pr_err().

Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")
Signed-off-by: Naoya Horiguchi <[email protected]>
---
ChangeLog v1 -> v2:
- v1: https://lore.kernel.org/linux-mm/[email protected]/T/#u
- update caller side instead of changing dump_page().
---
mm/memory-failure.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/mm/memory-failure.c b/mm/memory-failure.c
index 35e11d6bea4a..0e1453514a2b 100644
--- a/mm/memory-failure.c
+++ b/mm/memory-failure.c
@@ -1270,7 +1270,7 @@ static int get_any_page(struct page *p, unsigned long flags)
}
out:
if (ret == -EIO)
- dump_page(p, "hwpoison: unhandlable page");
+ pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));

return ret;
}
--
2.25.1


2022-04-27 20:29:07

by Andrew Morton

[permalink] [raw]
Subject: Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On Wed, 27 Apr 2022 14:32:20 +0900 Naoya Horiguchi <[email protected]> wrote:

> From: Naoya Horiguchi <[email protected]>
>
> The following VM_BUG_ON_FOLIO() is triggered when memory error event
> happens on the (thp/folio) pages which are about to be freed:
>
> ...
>
> Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")

I added cc:stable to this, OK?


Subject: Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On Wed, Apr 27, 2022 at 12:15:17PM -0700, Andrew Morton wrote:
> On Wed, 27 Apr 2022 14:32:20 +0900 Naoya Horiguchi <[email protected]> wrote:
>
> > From: Naoya Horiguchi <[email protected]>
> >
> > The following VM_BUG_ON_FOLIO() is triggered when memory error event
> > happens on the (thp/folio) pages which are about to be freed:
> >
> > ...
> >
> > Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")
>
> I added cc:stable to this, OK?

Yes, that's fine. 74e8ee4708a8 is new, and only v5.17.z is the target tree.
Thank you.

- Naoya Horiguchi

2022-04-28 04:41:17

by John Hubbard

[permalink] [raw]
Subject: Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On 4/26/22 22:32, Naoya Horiguchi wrote:
> From: Naoya Horiguchi <[email protected]>
>
> The following VM_BUG_ON_FOLIO() is triggered when memory error event
> happens on the (thp/folio) pages which are about to be freed:
>
> [ 1160.232771] page:00000000b36a8a0f refcount:1 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> [ 1160.236916] page:00000000b36a8a0f refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> [ 1160.240684] flags: 0x57ffffc0800000(hwpoison|node=1|zone=2|lastcpupid=0x1fffff)
> [ 1160.243458] raw: 0057ffffc0800000 dead000000000100 dead000000000122 0000000000000000
> [ 1160.246268] raw: 0000000000000001 0000000000000000 00000000ffffffff 0000000000000000
> [ 1160.249197] page dumped because: VM_BUG_ON_FOLIO(!folio_test_large(folio))
> [ 1160.251815] ------------[ cut here ]------------
> [ 1160.253438] kernel BUG at include/linux/mm.h:788!
> [ 1160.256162] invalid opcode: 0000 [#1] PREEMPT SMP PTI
> [ 1160.258172] CPU: 2 PID: 115368 Comm: mceinj.sh Tainted: G E 5.18.0-rc1-v5.18-rc1-220404-2353-005-g83111+ #3
> [ 1160.262049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1.fc35 04/01/2014
> [ 1160.265103] RIP: 0010:dump_page.cold+0x27e/0x2bd
> [ 1160.266757] Code: fe ff ff 48 c7 c6 81 f1 5a 98 e9 4c fe ff ff 48 c7 c6 a1 95 59 98 e9 40 fe ff ff 48 c7 c6 50 bf 5a 98 48 89 ef e8 9d 04 6d ff <0f> 0b 41 f7 c4 ff 0f 00 00 0f 85 9f fd ff ff 49 8b 04 24 a9 00 00
> [ 1160.273180] RSP: 0018:ffffaa2c4d59fd18 EFLAGS: 00010292
> [ 1160.274969] RAX: 000000000000003e RBX: 0000000000000001 RCX: 0000000000000000
> [ 1160.277263] RDX: 0000000000000001 RSI: ffffffff985995a1 RDI: 00000000ffffffff
> [ 1160.279571] RBP: ffffdc9c45a80000 R08: 0000000000000000 R09: 00000000ffffdfff
> [ 1160.281794] R10: ffffaa2c4d59fb08 R11: ffffffff98940d08 R12: ffffdc9c45a80000
> [ 1160.283920] R13: ffffffff985b6f94 R14: 0000000000000000 R15: ffffdc9c45a80000
> [ 1160.286641] FS: 00007eff54ce1740(0000) GS:ffff99c67bd00000(0000) knlGS:0000000000000000
> [ 1160.289498] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1160.291106] CR2: 00005628381a5f68 CR3: 0000000104712003 CR4: 0000000000170ee0
> [ 1160.293031] Call Trace:
> [ 1160.293724] <TASK>
> [ 1160.294334] get_hwpoison_page+0x47d/0x570
> [ 1160.295474] memory_failure+0x106/0xaa0
> [ 1160.296474] ? security_capable+0x36/0x50
> [ 1160.297524] hard_offline_page_store+0x43/0x80
> [ 1160.298684] kernfs_fop_write_iter+0x11c/0x1b0
> [ 1160.299829] new_sync_write+0xf9/0x160
> [ 1160.300810] vfs_write+0x209/0x290
> [ 1160.301835] ksys_write+0x4f/0xc0
> [ 1160.302718] do_syscall_64+0x3b/0x90
> [ 1160.303664] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 1160.304981] RIP: 0033:0x7eff54b018b7
>
> As shown in the RIP address, this VM_BUG_ON in folio_entire_mapcount() is
> called from dump_page("hwpoison: unhandlable page") in get_any_page().
> The below explains the mechanism of the race:
>
> CPU 0 CPU 1
>
> memory_failure
> get_hwpoison_page
> get_any_page
> dump_page
> compound = PageCompound
> free_pages_prepare
> page->flags &= ~PAGE_FLAGS_CHECK_AT_PREP
> folio_entire_mapcount
> VM_BUG_ON_FOLIO(!folio_test_large(folio))
>
> So replace dump_page() with safer one, pr_err().
>
> Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")
> Signed-off-by: Naoya Horiguchi <[email protected]>
> ---
> ChangeLog v1 -> v2:
> - v1: https://lore.kernel.org/linux-mm/[email protected]/T/#u
> - update caller side instead of changing dump_page().
> ---
> mm/memory-failure.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/mm/memory-failure.c b/mm/memory-failure.c
> index 35e11d6bea4a..0e1453514a2b 100644
> --- a/mm/memory-failure.c
> +++ b/mm/memory-failure.c
> @@ -1270,7 +1270,7 @@ static int get_any_page(struct page *p, unsigned long flags)
> }
> out:
> if (ret == -EIO)
> - dump_page(p, "hwpoison: unhandlable page");
> + pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));
>
> return ret;
> }

Reviewed-by: John Hubbard <[email protected]>

thanks,
--
John Hubbard
NVIDIA

2022-04-29 12:51:16

by Miaohe Lin

[permalink] [raw]
Subject: Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On 2022/4/27 13:32, Naoya Horiguchi wrote:
> From: Naoya Horiguchi <[email protected]>
>
> The following VM_BUG_ON_FOLIO() is triggered when memory error event
> happens on the (thp/folio) pages which are about to be freed:
>
> [ 1160.232771] page:00000000b36a8a0f refcount:1 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> [ 1160.236916] page:00000000b36a8a0f refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> [ 1160.240684] flags: 0x57ffffc0800000(hwpoison|node=1|zone=2|lastcpupid=0x1fffff)
> [ 1160.243458] raw: 0057ffffc0800000 dead000000000100 dead000000000122 0000000000000000
> [ 1160.246268] raw: 0000000000000001 0000000000000000 00000000ffffffff 0000000000000000
> [ 1160.249197] page dumped because: VM_BUG_ON_FOLIO(!folio_test_large(folio))
> [ 1160.251815] ------------[ cut here ]------------
> [ 1160.253438] kernel BUG at include/linux/mm.h:788!
> [ 1160.256162] invalid opcode: 0000 [#1] PREEMPT SMP PTI
> [ 1160.258172] CPU: 2 PID: 115368 Comm: mceinj.sh Tainted: G E 5.18.0-rc1-v5.18-rc1-220404-2353-005-g83111+ #3
> [ 1160.262049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1.fc35 04/01/2014
> [ 1160.265103] RIP: 0010:dump_page.cold+0x27e/0x2bd
> [ 1160.266757] Code: fe ff ff 48 c7 c6 81 f1 5a 98 e9 4c fe ff ff 48 c7 c6 a1 95 59 98 e9 40 fe ff ff 48 c7 c6 50 bf 5a 98 48 89 ef e8 9d 04 6d ff <0f> 0b 41 f7 c4 ff 0f 00 00 0f 85 9f fd ff ff 49 8b 04 24 a9 00 00
> [ 1160.273180] RSP: 0018:ffffaa2c4d59fd18 EFLAGS: 00010292
> [ 1160.274969] RAX: 000000000000003e RBX: 0000000000000001 RCX: 0000000000000000
> [ 1160.277263] RDX: 0000000000000001 RSI: ffffffff985995a1 RDI: 00000000ffffffff
> [ 1160.279571] RBP: ffffdc9c45a80000 R08: 0000000000000000 R09: 00000000ffffdfff
> [ 1160.281794] R10: ffffaa2c4d59fb08 R11: ffffffff98940d08 R12: ffffdc9c45a80000
> [ 1160.283920] R13: ffffffff985b6f94 R14: 0000000000000000 R15: ffffdc9c45a80000
> [ 1160.286641] FS: 00007eff54ce1740(0000) GS:ffff99c67bd00000(0000) knlGS:0000000000000000
> [ 1160.289498] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1160.291106] CR2: 00005628381a5f68 CR3: 0000000104712003 CR4: 0000000000170ee0
> [ 1160.293031] Call Trace:
> [ 1160.293724] <TASK>
> [ 1160.294334] get_hwpoison_page+0x47d/0x570
> [ 1160.295474] memory_failure+0x106/0xaa0
> [ 1160.296474] ? security_capable+0x36/0x50
> [ 1160.297524] hard_offline_page_store+0x43/0x80
> [ 1160.298684] kernfs_fop_write_iter+0x11c/0x1b0
> [ 1160.299829] new_sync_write+0xf9/0x160
> [ 1160.300810] vfs_write+0x209/0x290
> [ 1160.301835] ksys_write+0x4f/0xc0
> [ 1160.302718] do_syscall_64+0x3b/0x90
> [ 1160.303664] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 1160.304981] RIP: 0033:0x7eff54b018b7
>
> As shown in the RIP address, this VM_BUG_ON in folio_entire_mapcount() is
> called from dump_page("hwpoison: unhandlable page") in get_any_page().
> The below explains the mechanism of the race:
>
> CPU 0 CPU 1
>
> memory_failure
> get_hwpoison_page
> get_any_page
> dump_page
> compound = PageCompound
> free_pages_prepare
> page->flags &= ~PAGE_FLAGS_CHECK_AT_PREP
> folio_entire_mapcount
> VM_BUG_ON_FOLIO(!folio_test_large(folio))
>
> So replace dump_page() with safer one, pr_err().
>
> Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")
> Signed-off-by: Naoya Horiguchi <[email protected]>

LGTM. Thanks!

Reviewed-by: Miaohe Lin <[email protected]>

> ---
> ChangeLog v1 -> v2:
> - v1: https://lore.kernel.org/linux-mm/[email protected]/T/#u
> - update caller side instead of changing dump_page().
> ---
> mm/memory-failure.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/mm/memory-failure.c b/mm/memory-failure.c
> index 35e11d6bea4a..0e1453514a2b 100644
> --- a/mm/memory-failure.c
> +++ b/mm/memory-failure.c
> @@ -1270,7 +1270,7 @@ static int get_any_page(struct page *p, unsigned long flags)
> }
> out:
> if (ret == -EIO)
> - dump_page(p, "hwpoison: unhandlable page");
> + pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));
>
> return ret;
> }
>

2022-04-29 19:39:17

by Yang Shi

[permalink] [raw]
Subject: Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On Tue, Apr 26, 2022 at 10:32 PM Naoya Horiguchi
<[email protected]> wrote:
>
> From: Naoya Horiguchi <[email protected]>
>
> The following VM_BUG_ON_FOLIO() is triggered when memory error event
> happens on the (thp/folio) pages which are about to be freed:
>
> [ 1160.232771] page:00000000b36a8a0f refcount:1 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> [ 1160.236916] page:00000000b36a8a0f refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> [ 1160.240684] flags: 0x57ffffc0800000(hwpoison|node=1|zone=2|lastcpupid=0x1fffff)
> [ 1160.243458] raw: 0057ffffc0800000 dead000000000100 dead000000000122 0000000000000000
> [ 1160.246268] raw: 0000000000000001 0000000000000000 00000000ffffffff 0000000000000000
> [ 1160.249197] page dumped because: VM_BUG_ON_FOLIO(!folio_test_large(folio))
> [ 1160.251815] ------------[ cut here ]------------
> [ 1160.253438] kernel BUG at include/linux/mm.h:788!
> [ 1160.256162] invalid opcode: 0000 [#1] PREEMPT SMP PTI
> [ 1160.258172] CPU: 2 PID: 115368 Comm: mceinj.sh Tainted: G E 5.18.0-rc1-v5.18-rc1-220404-2353-005-g83111+ #3
> [ 1160.262049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1.fc35 04/01/2014
> [ 1160.265103] RIP: 0010:dump_page.cold+0x27e/0x2bd
> [ 1160.266757] Code: fe ff ff 48 c7 c6 81 f1 5a 98 e9 4c fe ff ff 48 c7 c6 a1 95 59 98 e9 40 fe ff ff 48 c7 c6 50 bf 5a 98 48 89 ef e8 9d 04 6d ff <0f> 0b 41 f7 c4 ff 0f 00 00 0f 85 9f fd ff ff 49 8b 04 24 a9 00 00
> [ 1160.273180] RSP: 0018:ffffaa2c4d59fd18 EFLAGS: 00010292
> [ 1160.274969] RAX: 000000000000003e RBX: 0000000000000001 RCX: 0000000000000000
> [ 1160.277263] RDX: 0000000000000001 RSI: ffffffff985995a1 RDI: 00000000ffffffff
> [ 1160.279571] RBP: ffffdc9c45a80000 R08: 0000000000000000 R09: 00000000ffffdfff
> [ 1160.281794] R10: ffffaa2c4d59fb08 R11: ffffffff98940d08 R12: ffffdc9c45a80000
> [ 1160.283920] R13: ffffffff985b6f94 R14: 0000000000000000 R15: ffffdc9c45a80000
> [ 1160.286641] FS: 00007eff54ce1740(0000) GS:ffff99c67bd00000(0000) knlGS:0000000000000000
> [ 1160.289498] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1160.291106] CR2: 00005628381a5f68 CR3: 0000000104712003 CR4: 0000000000170ee0
> [ 1160.293031] Call Trace:
> [ 1160.293724] <TASK>
> [ 1160.294334] get_hwpoison_page+0x47d/0x570
> [ 1160.295474] memory_failure+0x106/0xaa0
> [ 1160.296474] ? security_capable+0x36/0x50
> [ 1160.297524] hard_offline_page_store+0x43/0x80
> [ 1160.298684] kernfs_fop_write_iter+0x11c/0x1b0
> [ 1160.299829] new_sync_write+0xf9/0x160
> [ 1160.300810] vfs_write+0x209/0x290
> [ 1160.301835] ksys_write+0x4f/0xc0
> [ 1160.302718] do_syscall_64+0x3b/0x90
> [ 1160.303664] entry_SYSCALL_64_after_hwframe+0x44/0xae
> [ 1160.304981] RIP: 0033:0x7eff54b018b7
>
> As shown in the RIP address, this VM_BUG_ON in folio_entire_mapcount() is
> called from dump_page("hwpoison: unhandlable page") in get_any_page().
> The below explains the mechanism of the race:
>
> CPU 0 CPU 1
>
> memory_failure
> get_hwpoison_page
> get_any_page
> dump_page
> compound = PageCompound
> free_pages_prepare
> page->flags &= ~PAGE_FLAGS_CHECK_AT_PREP
> folio_entire_mapcount
> VM_BUG_ON_FOLIO(!folio_test_large(folio))
>
> So replace dump_page() with safer one, pr_err().
>
> Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")
> Signed-off-by: Naoya Horiguchi <[email protected]>
> ---
> ChangeLog v1 -> v2:
> - v1: https://lore.kernel.org/linux-mm/[email protected]/T/#u
> - update caller side instead of changing dump_page().
> ---
> mm/memory-failure.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/mm/memory-failure.c b/mm/memory-failure.c
> index 35e11d6bea4a..0e1453514a2b 100644
> --- a/mm/memory-failure.c
> +++ b/mm/memory-failure.c
> @@ -1270,7 +1270,7 @@ static int get_any_page(struct page *p, unsigned long flags)
> }
> out:
> if (ret == -EIO)
> - dump_page(p, "hwpoison: unhandlable page");
> + pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));

I think dump_page() is helpful to tell the users more information
about the unhandlable page, I'm ok with this fix for now, but should
we consider having a memory failure safe dump_page() in the future?

>
> return ret;
> }
> --
> 2.25.1
>
>

Subject: Re: ##freemail## Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On Thu, Apr 28, 2022 at 10:25:33AM -0700, Yang Shi wrote:
> On Tue, Apr 26, 2022 at 10:32 PM Naoya Horiguchi
> <[email protected]> wrote:
> >
> > From: Naoya Horiguchi <[email protected]>
> >
> > The following VM_BUG_ON_FOLIO() is triggered when memory error event
> > happens on the (thp/folio) pages which are about to be freed:
> >
> > [ 1160.232771] page:00000000b36a8a0f refcount:1 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> > [ 1160.236916] page:00000000b36a8a0f refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> > [ 1160.240684] flags: 0x57ffffc0800000(hwpoison|node=1|zone=2|lastcpupid=0x1fffff)
> > [ 1160.243458] raw: 0057ffffc0800000 dead000000000100 dead000000000122 0000000000000000
> > [ 1160.246268] raw: 0000000000000001 0000000000000000 00000000ffffffff 0000000000000000
> > [ 1160.249197] page dumped because: VM_BUG_ON_FOLIO(!folio_test_large(folio))
> > [ 1160.251815] ------------[ cut here ]------------
> > [ 1160.253438] kernel BUG at include/linux/mm.h:788!
> > [ 1160.256162] invalid opcode: 0000 [#1] PREEMPT SMP PTI
> > [ 1160.258172] CPU: 2 PID: 115368 Comm: mceinj.sh Tainted: G E 5.18.0-rc1-v5.18-rc1-220404-2353-005-g83111+ #3
> > [ 1160.262049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1.fc35 04/01/2014
> > [ 1160.265103] RIP: 0010:dump_page.cold+0x27e/0x2bd
> > [ 1160.266757] Code: fe ff ff 48 c7 c6 81 f1 5a 98 e9 4c fe ff ff 48 c7 c6 a1 95 59 98 e9 40 fe ff ff 48 c7 c6 50 bf 5a 98 48 89 ef e8 9d 04 6d ff <0f> 0b 41 f7 c4 ff 0f 00 00 0f 85 9f fd ff ff 49 8b 04 24 a9 00 00
> > [ 1160.273180] RSP: 0018:ffffaa2c4d59fd18 EFLAGS: 00010292
> > [ 1160.274969] RAX: 000000000000003e RBX: 0000000000000001 RCX: 0000000000000000
> > [ 1160.277263] RDX: 0000000000000001 RSI: ffffffff985995a1 RDI: 00000000ffffffff
> > [ 1160.279571] RBP: ffffdc9c45a80000 R08: 0000000000000000 R09: 00000000ffffdfff
> > [ 1160.281794] R10: ffffaa2c4d59fb08 R11: ffffffff98940d08 R12: ffffdc9c45a80000
> > [ 1160.283920] R13: ffffffff985b6f94 R14: 0000000000000000 R15: ffffdc9c45a80000
> > [ 1160.286641] FS: 00007eff54ce1740(0000) GS:ffff99c67bd00000(0000) knlGS:0000000000000000
> > [ 1160.289498] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 1160.291106] CR2: 00005628381a5f68 CR3: 0000000104712003 CR4: 0000000000170ee0
> > [ 1160.293031] Call Trace:
> > [ 1160.293724] <TASK>
> > [ 1160.294334] get_hwpoison_page+0x47d/0x570
> > [ 1160.295474] memory_failure+0x106/0xaa0
> > [ 1160.296474] ? security_capable+0x36/0x50
> > [ 1160.297524] hard_offline_page_store+0x43/0x80
> > [ 1160.298684] kernfs_fop_write_iter+0x11c/0x1b0
> > [ 1160.299829] new_sync_write+0xf9/0x160
> > [ 1160.300810] vfs_write+0x209/0x290
> > [ 1160.301835] ksys_write+0x4f/0xc0
> > [ 1160.302718] do_syscall_64+0x3b/0x90
> > [ 1160.303664] entry_SYSCALL_64_after_hwframe+0x44/0xae
> > [ 1160.304981] RIP: 0033:0x7eff54b018b7
> >
> > As shown in the RIP address, this VM_BUG_ON in folio_entire_mapcount() is
> > called from dump_page("hwpoison: unhandlable page") in get_any_page().
> > The below explains the mechanism of the race:
> >
> > CPU 0 CPU 1
> >
> > memory_failure
> > get_hwpoison_page
> > get_any_page
> > dump_page
> > compound = PageCompound
> > free_pages_prepare
> > page->flags &= ~PAGE_FLAGS_CHECK_AT_PREP
> > folio_entire_mapcount
> > VM_BUG_ON_FOLIO(!folio_test_large(folio))
> >
> > So replace dump_page() with safer one, pr_err().
> >
> > Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")
> > Signed-off-by: Naoya Horiguchi <[email protected]>
> > ---
> > ChangeLog v1 -> v2:
> > - v1: https://lore.kernel.org/linux-mm/[email protected]/T/#u
> > - update caller side instead of changing dump_page().
> > ---
> > mm/memory-failure.c | 2 +-
> > 1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/mm/memory-failure.c b/mm/memory-failure.c
> > index 35e11d6bea4a..0e1453514a2b 100644
> > --- a/mm/memory-failure.c
> > +++ b/mm/memory-failure.c
> > @@ -1270,7 +1270,7 @@ static int get_any_page(struct page *p, unsigned long flags)
> > }
> > out:
> > if (ret == -EIO)
> > - dump_page(p, "hwpoison: unhandlable page");
> > + pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));
>
> I think dump_page() is helpful to tell the users more information
> about the unhandlable page, I'm ok with this fix for now, but should
> we consider having a memory failure safe dump_page() in the future?

Yes, maybe that would be helpful not only in this unhandlable case, so sounds
good to me. But how do we handle folio's case? And I'm not sure that the full
info in dump_page() is needed in a memory_failure-specific variant.

Thanks,
Naoya Horiguchi

2022-05-10 10:15:38

by Yang Shi

[permalink] [raw]
Subject: Re: ##freemail## Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On Mon, May 9, 2022 at 12:14 AM HORIGUCHI NAOYA(堀口 直也)
<[email protected]> wrote:
>
> On Thu, Apr 28, 2022 at 10:25:33AM -0700, Yang Shi wrote:
> > On Tue, Apr 26, 2022 at 10:32 PM Naoya Horiguchi
> > <[email protected]> wrote:
> > >
> > > From: Naoya Horiguchi <[email protected]>
> > >
> > > The following VM_BUG_ON_FOLIO() is triggered when memory error event
> > > happens on the (thp/folio) pages which are about to be freed:
> > >
> > > [ 1160.232771] page:00000000b36a8a0f refcount:1 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> > > [ 1160.236916] page:00000000b36a8a0f refcount:0 mapcount:0 mapping:0000000000000000 index:0x1 pfn:0x16a000
> > > [ 1160.240684] flags: 0x57ffffc0800000(hwpoison|node=1|zone=2|lastcpupid=0x1fffff)
> > > [ 1160.243458] raw: 0057ffffc0800000 dead000000000100 dead000000000122 0000000000000000
> > > [ 1160.246268] raw: 0000000000000001 0000000000000000 00000000ffffffff 0000000000000000
> > > [ 1160.249197] page dumped because: VM_BUG_ON_FOLIO(!folio_test_large(folio))
> > > [ 1160.251815] ------------[ cut here ]------------
> > > [ 1160.253438] kernel BUG at include/linux/mm.h:788!
> > > [ 1160.256162] invalid opcode: 0000 [#1] PREEMPT SMP PTI
> > > [ 1160.258172] CPU: 2 PID: 115368 Comm: mceinj.sh Tainted: G E 5.18.0-rc1-v5.18-rc1-220404-2353-005-g83111+ #3
> > > [ 1160.262049] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1.fc35 04/01/2014
> > > [ 1160.265103] RIP: 0010:dump_page.cold+0x27e/0x2bd
> > > [ 1160.266757] Code: fe ff ff 48 c7 c6 81 f1 5a 98 e9 4c fe ff ff 48 c7 c6 a1 95 59 98 e9 40 fe ff ff 48 c7 c6 50 bf 5a 98 48 89 ef e8 9d 04 6d ff <0f> 0b 41 f7 c4 ff 0f 00 00 0f 85 9f fd ff ff 49 8b 04 24 a9 00 00
> > > [ 1160.273180] RSP: 0018:ffffaa2c4d59fd18 EFLAGS: 00010292
> > > [ 1160.274969] RAX: 000000000000003e RBX: 0000000000000001 RCX: 0000000000000000
> > > [ 1160.277263] RDX: 0000000000000001 RSI: ffffffff985995a1 RDI: 00000000ffffffff
> > > [ 1160.279571] RBP: ffffdc9c45a80000 R08: 0000000000000000 R09: 00000000ffffdfff
> > > [ 1160.281794] R10: ffffaa2c4d59fb08 R11: ffffffff98940d08 R12: ffffdc9c45a80000
> > > [ 1160.283920] R13: ffffffff985b6f94 R14: 0000000000000000 R15: ffffdc9c45a80000
> > > [ 1160.286641] FS: 00007eff54ce1740(0000) GS:ffff99c67bd00000(0000) knlGS:0000000000000000
> > > [ 1160.289498] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [ 1160.291106] CR2: 00005628381a5f68 CR3: 0000000104712003 CR4: 0000000000170ee0
> > > [ 1160.293031] Call Trace:
> > > [ 1160.293724] <TASK>
> > > [ 1160.294334] get_hwpoison_page+0x47d/0x570
> > > [ 1160.295474] memory_failure+0x106/0xaa0
> > > [ 1160.296474] ? security_capable+0x36/0x50
> > > [ 1160.297524] hard_offline_page_store+0x43/0x80
> > > [ 1160.298684] kernfs_fop_write_iter+0x11c/0x1b0
> > > [ 1160.299829] new_sync_write+0xf9/0x160
> > > [ 1160.300810] vfs_write+0x209/0x290
> > > [ 1160.301835] ksys_write+0x4f/0xc0
> > > [ 1160.302718] do_syscall_64+0x3b/0x90
> > > [ 1160.303664] entry_SYSCALL_64_after_hwframe+0x44/0xae
> > > [ 1160.304981] RIP: 0033:0x7eff54b018b7
> > >
> > > As shown in the RIP address, this VM_BUG_ON in folio_entire_mapcount() is
> > > called from dump_page("hwpoison: unhandlable page") in get_any_page().
> > > The below explains the mechanism of the race:
> > >
> > > CPU 0 CPU 1
> > >
> > > memory_failure
> > > get_hwpoison_page
> > > get_any_page
> > > dump_page
> > > compound = PageCompound
> > > free_pages_prepare
> > > page->flags &= ~PAGE_FLAGS_CHECK_AT_PREP
> > > folio_entire_mapcount
> > > VM_BUG_ON_FOLIO(!folio_test_large(folio))
> > >
> > > So replace dump_page() with safer one, pr_err().
> > >
> > > Fixes: 74e8ee4708a8 ("mm: Turn head_compound_mapcount() into folio_entire_mapcount()")
> > > Signed-off-by: Naoya Horiguchi <[email protected]>
> > > ---
> > > ChangeLog v1 -> v2:
> > > - v1: https://lore.kernel.org/linux-mm/[email protected]/T/#u
> > > - update caller side instead of changing dump_page().
> > > ---
> > > mm/memory-failure.c | 2 +-
> > > 1 file changed, 1 insertion(+), 1 deletion(-)
> > >
> > > diff --git a/mm/memory-failure.c b/mm/memory-failure.c
> > > index 35e11d6bea4a..0e1453514a2b 100644
> > > --- a/mm/memory-failure.c
> > > +++ b/mm/memory-failure.c
> > > @@ -1270,7 +1270,7 @@ static int get_any_page(struct page *p, unsigned long flags)
> > > }
> > > out:
> > > if (ret == -EIO)
> > > - dump_page(p, "hwpoison: unhandlable page");
> > > + pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));
> >
> > I think dump_page() is helpful to tell the users more information
> > about the unhandlable page, I'm ok with this fix for now, but should
> > we consider having a memory failure safe dump_page() in the future?
>
> Yes, maybe that would be helpful not only in this unhandlable case, so sounds
> good to me. But how do we handle folio's case? And I'm not sure that the full
> info in dump_page() is needed in a memory_failure-specific variant.

Off the top of my head, we just dump the raw information of the page
and the head page if it belongs to a large folio at the moment? This
may be just slightly different from dump_page().

>
> Thanks,
> Naoya Horiguchi

2022-05-10 10:58:19

by Matthew Wilcox

[permalink] [raw]
Subject: Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On Wed, Apr 27, 2022 at 02:32:20PM +0900, Naoya Horiguchi wrote:
> From: Naoya Horiguchi <[email protected]>
>
> The following VM_BUG_ON_FOLIO() is triggered when memory error event
> happens on the (thp/folio) pages which are about to be freed:

So the real problem is that we're calling dump_page() when we don't
have a reference to the page, right? Otherwise it wouldn't be freed.

> out:
> if (ret == -EIO)
> - dump_page(p, "hwpoison: unhandlable page");
> + pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));

It would be nice to get some more information out of the page than that
,.. but taking a refcount inside dump_page() conflicts with the other
"would be nice", which is for dump_page() to take a const struct page *
so we can (eg) make folio_test_uptodate() take a const struct folio *.

We've had some other problems with inconsistent pages being printed in
dump_page(). It can be quite confusing when debugging. I still don't
have a good solution to that either.

I do have a proposal for reforming mapcount which will solve this
particular problem, but I'm not quite sure when I'll get to it.
This patch is probably the best thing to do for now.

Subject: Re: [PATCH v2] mm/hwpoison: use pr_err() instead of dump_page() in get_any_page()

On Tue, May 10, 2022 at 03:28:05AM +0100, Matthew Wilcox wrote:
> On Wed, Apr 27, 2022 at 02:32:20PM +0900, Naoya Horiguchi wrote:
> > From: Naoya Horiguchi <[email protected]>
> >
> > The following VM_BUG_ON_FOLIO() is triggered when memory error event
> > happens on the (thp/folio) pages which are about to be freed:
>
> So the real problem is that we're calling dump_page() when we don't
> have a reference to the page, right? Otherwise it wouldn't be freed.

Right, that's the problem.

>
> > out:
> > if (ret == -EIO)
> > - dump_page(p, "hwpoison: unhandlable page");
> > + pr_err("Memory failure: %#lx: unhandlable page.\n", page_to_pfn(p));
>
> It would be nice to get some more information out of the page than that
> ,.. but taking a refcount inside dump_page() conflicts with the other
> "would be nice", which is for dump_page() to take a const struct page *
> so we can (eg) make folio_test_uptodate() take a const struct folio *.
>
> We've had some other problems with inconsistent pages being printed in
> dump_page(). It can be quite confusing when debugging. I still don't
> have a good solution to that either.
>
> I do have a proposal for reforming mapcount which will solve this
> particular problem, but I'm not quite sure when I'll get to it.
> This patch is probably the best thing to do for now.

Thank you for the comment. So I leave this code simple (or some
hwpoison specific dump_page() if someone have good ideas) until some
ultimate solution is ready for upstream.

Thanks,
Naoya Horiguchi