| Message ID | 623750dd31aa3fe5e45c416be98ab37707e2c45d.camel@perches.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | memblock: Neaten logging | expand |
Hi Joe, On Wed, Sep 29, 2021 at 09:43:14PM -0700, Joe Perches wrote: > Use more typical kernel logging styles. > > o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt I don't see it as an improvement. On the contrary, the output becomes somewhat tautological: memblock: memblock_reserve: smp_scan_config+0xa5/0xe9: [0x00000000000f5a60-0x00000000000f5a6f] memblock: memblock_reserve: smp_scan_config+0xbc/0xe9: [0x00000000000f5a70-0x00000000000f5b83] memblock: memblock_reserve: setup_arch+0x5d8/0xbcd: [0x0000000002e00000-0x0000000002e10fff] memblock: memblock_add: e820__memblock_setup+0x5e/0x76: [0x0000000000001000-0x000000000009fbff] memblock: memblock_add: e820__memblock_setup+0x5e/0x76: [0x0000000000100000-0x00000000bffdcfff] memblock: memblock_add: e820__memblock_setup+0x5e/0x76: [0x0000000100000000-0x000000013fffffff] And the output of memblock_dump_all() is perfectly fine without the prefix. > o Neaten memblock_dbg to use %s: %pS: to output __func__ and caller > o Convert existing uses of pr_<level> and memblock_dbg appropriately > > Logging output is now always prefixed with 'memblock: ' > Debugging output is now prefixed with 'memblock: ', function and caller > > Signed-off-by: Joe Perches <joe@perches.com> > --- > mm/memblock.c | 59 ++++++++++++++++++++++++++--------------------------------- > 1 file changed, 26 insertions(+), 33 deletions(-) What is the base commit for this patch? It seems it missed a pr_warn in memblock_cap_memory_range()... > diff --git a/mm/memblock.c b/mm/memblock.c > index 184dcd2e5d99..405335c966a8 100644 > --- a/mm/memblock.c > +++ b/mm/memblock.c
On Thu, 2021-09-30 at 14:12 -0700, Mike Rapoport wrote: > Hi Joe, > > On Wed, Sep 29, 2021 at 09:43:14PM -0700, Joe Perches wrote: > > Use more typical kernel logging styles. > > > > o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt > > I don't see it as an improvement. On the contrary, the output becomes > somewhat tautological: And rather easier to grep as the prefix is constant. > What is the base commit for this patch? > It seems it missed a pr_warn in memblock_cap_memory_range()... linus' master.
On Thu, Sep 30, 2021 at 06:27:15PM -0700, Joe Perches wrote: > On Thu, 2021-09-30 at 14:12 -0700, Mike Rapoport wrote: > > Hi Joe, > > > > On Wed, Sep 29, 2021 at 09:43:14PM -0700, Joe Perches wrote: > > > Use more typical kernel logging styles. > > > > > > o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt > > > > I don't see it as an improvement. On the contrary, the output becomes > > somewhat tautological: > > And rather easier to grep as the prefix is constant. memblock_ is perfectly greppable
On Fri, 2021-10-01 at 09:37 -0700, Mike Rapoport wrote: > On Thu, Sep 30, 2021 at 06:27:15PM -0700, Joe Perches wrote: > > On Thu, 2021-09-30 at 14:12 -0700, Mike Rapoport wrote: > > > Hi Joe, > > > > > > On Wed, Sep 29, 2021 at 09:43:14PM -0700, Joe Perches wrote: > > > > Use more typical kernel logging styles. > > > > > > > > o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt > > > > > > I don't see it as an improvement. On the contrary, the output becomes > > > somewhat tautological: > > > > And rather easier to grep as the prefix is constant. > > memblock_ is perfectly greppable Of course, but only when it's there, 2 instances out of 9. $ git grep '\bpr_' mm/memblock.c mm/memblock.c: pr_info(fmt, ##__VA_ARGS__); \ mm/memblock.c: pr_warn("Could not allocate %pap bytes of mirrored memory\n", mm/memblock.c: pr_err("memblock: Failed to double %s array from %ld to %ld entries !\n", mm/memblock.c: pr_warn("Could not allocate %pap bytes of mirrored memory\n", mm/memblock.c: pr_warn("%s: No memory registered yet\n", __func__); mm/memblock.c: pr_info(" %s.cnt = 0x%lx\n", type->name, type->cnt); mm/memblock.c: pr_info(" %s[%#x]\t[%pa-%pa], %pa bytes%s flags: %#x\n", mm/memblock.c: pr_info("MEMBLOCK configuration:\n"); mm/memblock.c: pr_info(" memory size = %pa reserved size = %pa\n", cheers, Joe
On Fri, Oct 01, 2021 at 01:34:10PM -0700, Joe Perches wrote: > On Fri, 2021-10-01 at 09:37 -0700, Mike Rapoport wrote: > > On Thu, Sep 30, 2021 at 06:27:15PM -0700, Joe Perches wrote: > > > On Thu, 2021-09-30 at 14:12 -0700, Mike Rapoport wrote: > > > > Hi Joe, > > > > > > > > On Wed, Sep 29, 2021 at 09:43:14PM -0700, Joe Perches wrote: > > > > > Use more typical kernel logging styles. > > > > > > > > > > o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt > > > > > > > > I don't see it as an improvement. On the contrary, the output becomes > > > > somewhat tautological: > > > > > > And rather easier to grep as the prefix is constant. > > > > memblock_ is perfectly greppable > > Of course, but only when it's there, 2 instances out of 9. I didn't object to the patch as a whole. I just don't like the pr_fmt definition. > $ git grep '\bpr_' mm/memblock.c > mm/memblock.c: pr_warn("Could not allocate %pap bytes of mirrored memory\n", > mm/memblock.c: pr_err("memblock: Failed to double %s array from %ld to %ld entries !\n", > mm/memblock.c: pr_warn("Could not allocate %pap bytes of mirrored memory\n", These can have %s for __func__ as a prefix, > mm/memblock.c: pr_warn("%s: No memory registered yet\n", __func__); this one already has it, > mm/memblock.c: pr_info(" %s.cnt = 0x%lx\n", type->name, type->cnt); > mm/memblock.c: pr_info(" %s[%#x]\t[%pa-%pa], %pa bytes%s flags: %#x\n", > mm/memblock.c: pr_info("MEMBLOCK configuration:\n"); > mm/memblock.c: pr_info(" memory size = %pa reserved size = %pa\n", and these are just fine now even without the prefix.
On Fri, 2021-10-01 at 16:12 -0700, Mike Rapoport wrote: > On Fri, Oct 01, 2021 at 01:34:10PM -0700, Joe Perches wrote: > > On Fri, 2021-10-01 at 09:37 -0700, Mike Rapoport wrote: > > > On Thu, Sep 30, 2021 at 06:27:15PM -0700, Joe Perches wrote: > > > > On Thu, 2021-09-30 at 14:12 -0700, Mike Rapoport wrote: > > > > > Hi Joe, > > > > > > > > > > On Wed, Sep 29, 2021 at 09:43:14PM -0700, Joe Perches wrote: > > > > > > Use more typical kernel logging styles. > > > > > > > > > > > > o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt > > > > > > > > > > I don't see it as an improvement. On the contrary, the output becomes > > > > > somewhat tautological: > > > > > > > > And rather easier to grep as the prefix is constant. > > > > > > memblock_ is perfectly greppable > > > > Of course, but only when it's there, 2 instances out of 9. > > I didn't object to the patch as a whole. I just don't like the pr_fmt > definition. You should do what you like. I did what I like. cheers, Joe
On Fri, Oct 01, 2021 at 04:20:14PM -0700, Joe Perches wrote: > On Fri, 2021-10-01 at 16:12 -0700, Mike Rapoport wrote: > > On Fri, Oct 01, 2021 at 01:34:10PM -0700, Joe Perches wrote: > > > On Fri, 2021-10-01 at 09:37 -0700, Mike Rapoport wrote: > > > > On Thu, Sep 30, 2021 at 06:27:15PM -0700, Joe Perches wrote: > > > > > On Thu, 2021-09-30 at 14:12 -0700, Mike Rapoport wrote: > > > > > > Hi Joe, > > > > > > > > > > > > On Wed, Sep 29, 2021 at 09:43:14PM -0700, Joe Perches wrote: > > > > > > > Use more typical kernel logging styles. > > > > > > > > > > > > > > o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt > > > > > > > > > > > > I don't see it as an improvement. On the contrary, the output becomes > > > > > > somewhat tautological: > > > > > > > > > > And rather easier to grep as the prefix is constant. > > > > > > > > memblock_ is perfectly greppable > > > > > > Of course, but only when it's there, 2 instances out of 9. > > > > I didn't object to the patch as a whole. I just don't like the pr_fmt > > definition. > > You should do what you like. I did what I like. I'm perfectly fine with the current state.
diff --git a/mm/memblock.c b/mm/memblock.c index 184dcd2e5d99..405335c966a8 100644 --- a/mm/memblock.c +++ b/mm/memblock.c @@ -6,6 +6,8 @@ * Copyright (C) 2001 Peter Bergner. */ +#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt + #include <linux/kernel.h> #include <linux/slab.h> #include <linux/init.h> @@ -146,10 +148,12 @@ static __refdata struct memblock_type *memblock_memory = &memblock.memory; i++, rgn = &memblock_type->regions[i]) #define memblock_dbg(fmt, ...) \ - do { \ - if (memblock_debug) \ - pr_info(fmt, ##__VA_ARGS__); \ - } while (0) +do { \ + if (memblock_debug) \ + pr_info("%s: %pS: " fmt, \ + __func__, __builtin_return_address(0), \ + ##__VA_ARGS__); \ +} while (0) static int memblock_debug __initdata_memblock; static bool system_has_some_mirror __initdata_memblock = false; @@ -447,14 +451,14 @@ static int __init_memblock memblock_double_array(struct memblock_type *type, new_array = addr ? __va(addr) : NULL; } if (!addr) { - pr_err("memblock: Failed to double %s array from %ld to %ld entries !\n", + pr_err("Failed to double %s array from %ld to %ld entries !\n", type->name, type->max, type->max * 2); return -1; } new_end = addr + new_size - 1; - memblock_dbg("memblock: %s is doubled to %ld at [%pa-%pa]", - type->name, type->max * 2, &addr, &new_end); + memblock_dbg("%s is doubled to %ld at [%pa-%pa]\n", + type->name, type->max * 2, &addr, &new_end); /* * Found space, we now need to move the array over before we add the @@ -667,8 +671,7 @@ int __init_memblock memblock_add_node(phys_addr_t base, phys_addr_t size, { phys_addr_t end = base + size - 1; - memblock_dbg("%s: [%pa-%pa] nid=%d %pS\n", __func__, - &base, &end, nid, (void *)_RET_IP_); + memblock_dbg("[%pa-%pa] nid=%d\n", &base, &end, nid); return memblock_add_range(&memblock.memory, base, size, nid, 0); } @@ -688,8 +691,7 @@ int __init_memblock memblock_add(phys_addr_t base, phys_addr_t size) { phys_addr_t end = base + size - 1; - memblock_dbg("%s: [%pa-%pa] %pS\n", __func__, - &base, &end, (void *)_RET_IP_); + memblock_dbg("[%pa-%pa]\n", &base, &end); return memblock_add_range(&memblock.memory, base, size, MAX_NUMNODES, 0); } @@ -789,8 +791,7 @@ int __init_memblock memblock_remove(phys_addr_t base, phys_addr_t size) { phys_addr_t end = base + size - 1; - memblock_dbg("%s: [%pa-%pa] %pS\n", __func__, - &base, &end, (void *)_RET_IP_); + memblock_dbg("[%pa-%pa]\n", &base, &end); return memblock_remove_range(&memblock.memory, base, size); } @@ -821,8 +822,7 @@ int __init_memblock memblock_free(phys_addr_t base, phys_addr_t size) { phys_addr_t end = base + size - 1; - memblock_dbg("%s: [%pa-%pa] %pS\n", __func__, - &base, &end, (void *)_RET_IP_); + memblock_dbg("[%pa-%pa]\n", &base, &end); kmemleak_free_part_phys(base, size); return memblock_remove_range(&memblock.reserved, base, size); @@ -832,8 +832,7 @@ int __init_memblock memblock_reserve(phys_addr_t base, phys_addr_t size) { phys_addr_t end = base + size - 1; - memblock_dbg("%s: [%pa-%pa] %pS\n", __func__, - &base, &end, (void *)_RET_IP_); + memblock_dbg("[%pa-%pa]\n", &base, &end); return memblock_add_range(&memblock.reserved, base, size, MAX_NUMNODES, 0); } @@ -843,8 +842,7 @@ int __init_memblock memblock_physmem_add(phys_addr_t base, phys_addr_t size) { phys_addr_t end = base + size - 1; - memblock_dbg("%s: [%pa-%pa] %pS\n", __func__, - &base, &end, (void *)_RET_IP_); + memblock_dbg("[%pa-%pa]\n", &base, &end); return memblock_add_range(&physmem, base, size, MAX_NUMNODES, 0); } @@ -1409,9 +1407,8 @@ phys_addr_t __init memblock_phys_alloc_range(phys_addr_t size, phys_addr_t start, phys_addr_t end) { - memblock_dbg("%s: %llu bytes align=0x%llx from=%pa max_addr=%pa %pS\n", - __func__, (u64)size, (u64)align, &start, &end, - (void *)_RET_IP_); + memblock_dbg("%llu bytes align=0x%llx from=%pa max_addr=%pa\n", + (u64)size, (u64)align, &start, &end); return memblock_alloc_range_nid(size, align, start, end, NUMA_NO_NODE, false); } @@ -1510,9 +1507,8 @@ void * __init memblock_alloc_exact_nid_raw( phys_addr_t min_addr, phys_addr_t max_addr, int nid) { - memblock_dbg("%s: %llu bytes align=0x%llx nid=%d from=%pa max_addr=%pa %pS\n", - __func__, (u64)size, (u64)align, nid, &min_addr, - &max_addr, (void *)_RET_IP_); + memblock_dbg("%llu bytes align=0x%llx nid=%d from=%pa max_addr=%pa\n", + (u64)size, (u64)align, nid, &min_addr, &max_addr); return memblock_alloc_internal(size, align, min_addr, max_addr, nid, true); @@ -1542,9 +1538,8 @@ void * __init memblock_alloc_try_nid_raw( phys_addr_t min_addr, phys_addr_t max_addr, int nid) { - memblock_dbg("%s: %llu bytes align=0x%llx nid=%d from=%pa max_addr=%pa %pS\n", - __func__, (u64)size, (u64)align, nid, &min_addr, - &max_addr, (void *)_RET_IP_); + memblock_dbg("%llu bytes align=0x%llx nid=%d from=%pa max_addr=%pa\n", + (u64)size, (u64)align, nid, &min_addr, &max_addr); return memblock_alloc_internal(size, align, min_addr, max_addr, nid, false); @@ -1574,9 +1569,8 @@ void * __init memblock_alloc_try_nid( { void *ptr; - memblock_dbg("%s: %llu bytes align=0x%llx nid=%d from=%pa max_addr=%pa %pS\n", - __func__, (u64)size, (u64)align, nid, &min_addr, - &max_addr, (void *)_RET_IP_); + memblock_dbg("%llu bytes align=0x%llx nid=%d from=%pa max_addr=%pa\n", + (u64)size, (u64)align, nid, &min_addr, &max_addr); ptr = memblock_alloc_internal(size, align, min_addr, max_addr, nid, false); if (ptr) @@ -1599,8 +1593,7 @@ void __init __memblock_free_late(phys_addr_t base, phys_addr_t size) phys_addr_t cursor, end; end = base + size - 1; - memblock_dbg("%s: [%pa-%pa] %pS\n", - __func__, &base, &end, (void *)_RET_IP_); + memblock_dbg("[%pa-%pa]\n", &base, &end); kmemleak_free_part_phys(base, size); cursor = PFN_UP(base); end = PFN_DOWN(base + size);
Use more typical kernel logging styles. o Add and use #define pr_fmt KBUILD_MODNAME ": " fmt o Neaten memblock_dbg to use %s: %pS: to output __func__ and caller o Convert existing uses of pr_<level> and memblock_dbg appropriately Logging output is now always prefixed with 'memblock: ' Debugging output is now prefixed with 'memblock: ', function and caller Signed-off-by: Joe Perches <joe@perches.com> --- mm/memblock.c | 59 ++++++++++++++++++++++++++--------------------------------- 1 file changed, 26 insertions(+), 33 deletions(-)