2021-10-18 06:59:02

by Faiyaz Mohammed

[permalink] [raw]
Subject: [PATCH v4] mm: page_alloc: Add debug log in free_reserved_area for static memory

For INITRD and initmem memory is reserved through "memblock_reserve"
during boot up but it is free via "free_reserved_area" instead
of "memblock_free".
For example:
[ 0.294848] Freeing initrd memory: 12K.
[ 0.696688] Freeing unused kernel memory: 4096K.

To get the start and end address of the above freed memory and to account
proper memblock added pr_debug log in "free_reserved_area".
After adding log:
[ 0.294837] 0x00000083600000-0x00000083603000 free_initrd_mem+0x20/0x28
[ 0.294848] Freeing initrd memory: 12K.
[ 0.695246] 0x00000081600000-0x00000081a00000 free_initmem+0x70/0xc8
[ 0.696688] Freeing unused kernel memory: 4096K.

Signed-off-by: Faiyaz Mohammed <[email protected]>
---
changes in v4:
- Use correctly _RET_IP_ macro.
changes in v3:
- Update the format specifier.
changes in v2:
- To avoid confusion, remove the memblock_dbg print and drop the
memblock_free string, now using pr_debug to print the address ranges.

mm/page_alloc.c | 7 ++++++-
1 file changed, 6 insertions(+), 1 deletion(-)

diff --git a/mm/page_alloc.c b/mm/page_alloc.c
index b37435c..19ca193 100644
--- a/mm/page_alloc.c
+++ b/mm/page_alloc.c
@@ -8097,6 +8097,8 @@ EXPORT_SYMBOL(adjust_managed_page_count);

unsigned long free_reserved_area(void *start, void *end, int poison, const char *s)
{
+ const phys_addr_t pstart = __pa(start);
+ const phys_addr_t pend = __pa(end);
void *pos;
unsigned long pages = 0;

@@ -8125,9 +8127,12 @@ unsigned long free_reserved_area(void *start, void *end, int poison, const char
free_reserved_page(page);
}

- if (pages && s)
+ if (pages && s) {
pr_info("Freeing %s memory: %ldK\n",
s, pages << (PAGE_SHIFT - 10));
+ pr_debug("[%pa-%pa] %pS\n", &pstart, &pend,
+ (void *)_RET_IP_);
+ }

return pages;
}
--
QUALCOMM INDIA, on behalf of Qualcomm Innovation Center, Inc. is a
member of the Code Aurora Forum, hosted by The Linux Foundation


2021-10-18 18:01:22

by Andrew Morton

[permalink] [raw]
Subject: Re: [PATCH v4] mm: page_alloc: Add debug log in free_reserved_area for static memory

On Mon, 18 Oct 2021 12:24:13 +0530 Faiyaz Mohammed <[email protected]> wrote:

> For INITRD and initmem memory is reserved through "memblock_reserve"
> during boot up but it is free via "free_reserved_area" instead
> of "memblock_free".
> For example:
> [ 0.294848] Freeing initrd memory: 12K.
> [ 0.696688] Freeing unused kernel memory: 4096K.
>
> To get the start and end address of the above freed memory and to account
> proper memblock added pr_debug log in "free_reserved_area".
> After adding log:
> [ 0.294837] 0x00000083600000-0x00000083603000 free_initrd_mem+0x20/0x28
> [ 0.294848] Freeing initrd memory: 12K.
> [ 0.695246] 0x00000081600000-0x00000081a00000 free_initmem+0x70/0xc8
> [ 0.696688] Freeing unused kernel memory: 4096K.

The above log appears to have things backwards. I assume you meant

> [ 0.294848] Freeing initrd memory: 12K.
> [ 0.294837] 0x00000083600000-0x00000083603000 free_initrd_mem+0x20/0x28
> [ 0.696688] Freeing unused kernel memory: 4096K.
> [ 0.695246] 0x00000081600000-0x00000081a00000 free_initmem+0x70/0xc8


2021-10-19 02:36:09

by kernel test robot

[permalink] [raw]
Subject: [mm] f859d2a494: kernel_BUG_at_arch/x86/mm/physaddr.c



Greeting,

FYI, we noticed the following commit (built with clang-14):

commit: f859d2a494648d9e9903bf46d4c27f88b2c53ab0 ("[PATCH v4] mm: page_alloc: Add debug log in free_reserved_area for static memory")
url: https://github.com/0day-ci/linux/commits/Faiyaz-Mohammed/mm-page_alloc-Add-debug-log-in-free_reserved_area-for-static-memory/20211018-145621


in testcase: trinity
version:
with following parameters:

number: 99999
group: group-04

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+--------------------------------------------------------------------------+-----------+------------+
| | v5.15-rc6 | f859d2a494 |
+--------------------------------------------------------------------------+-----------+------------+
| kernel_BUG_at_arch/x86/mm/physaddr.c | 0 | 35 |
| invalid_opcode:#[##] | 0 | 35 |
| EIP:__phys_addr | 0 | 35 |
+--------------------------------------------------------------------------+-----------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>



[ 3.615599][ T5] Unpacking initramfs...
[ 4.464112][ T5] ------------[ cut here ]------------
[ 4.465044][ T5] kernel BUG at arch/x86/mm/physaddr.c:81!
[ 4.466084][ T5] invalid opcode: 0000 [#1]
[ 4.466746][ T5] CPU: 0 PID: 5 Comm: kworker/u2:0 Not tainted 5.15.0-rc6-00001-gf859d2a49464 #5 21680ec59cac6f17b63f4ff3a76cd498fdf11f87
[ 4.468387][ T5] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 4.469812][ T5] Workqueue: events_unbound async_run_entry_fn
[ 4.469995][ T5] EIP: __phys_addr+0x50/0x60
[ 4.469995][ T5] Code: 90 cb 8f c3 85 c0 74 16 89 f1 c1 e9 0c 39 c1 77 17 89 f8 e8 72 20 00 00 31 f0 09 d0 75 0c 89 f0 5e 5f 5d c3 0f 0b 0f 0b 0f 0b <0f> 0b 90
90 90 90 90 90 90 90 90 90 90 90 90 90 55 89 e5 56 3d 00
[ 4.469995][ T5] EAX: 36dfe000 EBX: f6175000 ECX: 00000000 EDX: 00000000
[ 4.469995][ T5] ESI: 36dfe000 EDI: f6dfe000 EBP: c3cdfeac ESP: c3cdfea4
[ 4.469995][ T5] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00010206
[ 4.469995][ T5] CR0: 80050033 CR2: 00000000 CR3: 031ce000 CR4: 000406f0
[ 4.469995][ T5] Call Trace:
[ 4.469995][ T5] free_reserved_area+0x1c/0x1c0
[ 4.469995][ T5] ? set_memory_rw+0x1d/0x30
[ 4.469995][ T5] free_init_pages+0x55/0x70
[ 4.469995][ T5] free_initrd_mem+0x1e/0x21
[ 4.469995][ T5] do_populate_rootfs+0x92/0x9f
[ 4.469995][ T5] async_run_entry_fn+0x1c/0xa0
[ 4.469995][ T5] process_one_work+0x208/0x400
[ 4.469995][ T5] worker_thread+0x22a/0x400
[ 4.469995][ T5] kthread+0x133/0x150
[ 4.469995][ T5] ? pool_mayday_timeout+0x180/0x180
[ 4.469995][ T5] ? kthread_blkcg+0x30/0x30
[ 4.469995][ T5] ret_from_fork+0x19/0x24
[ 4.469995][ T5] Modules linked in:
[ 4.487712][ T5] ---[ end trace e05e1d4a3febc36d ]---
[ 4.488527][ T5] EIP: __phys_addr+0x50/0x60
[ 4.489244][ T5] Code: 90 cb 8f c3 85 c0 74 16 89 f1 c1 e9 0c 39 c1 77 17 89 f8 e8 72 20 00 00 31 f0 09 d0 75 0c 89 f0 5e 5f 5d c3 0f 0b 0f 0b 0f 0b <0f> 0b 90 90 90 90 90 90 90 90 90 90 90 90 90 90 55 89 e5 56 3d 00
[ 4.492036][ T5] EAX: 36dfe000 EBX: f6175000 ECX: 00000000 EDX: 00000000
[ 4.493068][ T5] ESI: 36dfe000 EDI: f6dfe000 EBP: c3cdfeac ESP: c3cdfea4
[ 4.494202][ T5] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00010206
[ 4.495349][ T5] CR0: 80050033 CR2: 00000000 CR3: 031ce000 CR4: 000406f0
[ 4.496328][ T5] Kernel panic - not syncing: Fatal exception



To reproduce:

# build kernel
cd linux
cp config-5.15.0-rc6-00001-gf859d2a49464 .config
make HOSTCC=clang-14 CC=clang-14 ARCH=i386 olddefconfig prepare modules_prepare bzImage

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email

# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.



---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation

Thanks,
Oliver Sang


Attachments:
(No filename) (4.75 kB)
config-5.15.0-rc6-00001-gf859d2a49464 (148.70 kB)
job-script (4.61 kB)
dmesg.xz (7.94 kB)
Download all attachments