[PATCH 1/4] module: add modname being loaded to pr_debugs

[PATCH 1/4] module: add modname being loaded to pr_debugs

[Jim Cromie]

When enabled, pr_debugs in layout_sections() and move_module() write
~50 messages for each module loaded.  Add module name into the header
lines in that output.

no functional changes

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 kernel/module.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 30479355ab85..af2641b28d73 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2421,7 +2421,7 @@ static void layout_sections(struct module *mod, struct load_info *info)
 	for (i = 0; i < info->hdr->e_shnum; i++)
 		info->sechdrs[i].sh_entsize = ~0UL;
 
-	pr_debug("Core section allocation order:\n");
+	pr_debug("Core section allocation order for %s:\n", mod->name);
 	for (m = 0; m < ARRAY_SIZE(masks); ++m) {
 		for (i = 0; i < info->hdr->e_shnum; ++i) {
 			Elf_Shdr *s = &info->sechdrs[i];
@@ -2454,7 +2454,7 @@ static void layout_sections(struct module *mod, struct load_info *info)
 		}
 	}
 
-	pr_debug("Init section allocation order:\n");
+	pr_debug("Init section allocation order for %s:\n", mod->name);
 	for (m = 0; m < ARRAY_SIZE(masks); ++m) {
 		for (i = 0; i < info->hdr->e_shnum; ++i) {
 			Elf_Shdr *s = &info->sechdrs[i];
@@ -3375,7 +3375,7 @@ static int move_module(struct module *mod, struct load_info *info)
 		mod->init_layout.base = NULL;
 
 	/* Transfer each section which specifies SHF_ALLOC */
-	pr_debug("final section addresses:\n");
+	pr_debug("Final section addresses for %s:\n", mod->name);
 	for (i = 0; i < info->hdr->e_shnum; i++) {
 		void *dest;
 		Elf_Shdr *shdr = &info->sechdrs[i];
-- 
2.30.2

[PATCH 2/4] module: add symbol-name to pr_debug Absolute symbol

[Jim Cromie]

Symbol name is likely to be at least as useful as the value (which is
written, and is usually 0), if one is looking at these messages.

no functional changes

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 kernel/module.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index af2641b28d73..ab16b8da2555 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2300,8 +2300,8 @@ static int simplify_symbols(struct module *mod, const struct load_info *info)
 
 		case SHN_ABS:
 			/* Don't need to do anything */
-			pr_debug("Absolute symbol: 0x%08lx\n",
-			       (long)sym[i].st_value);
+			pr_debug("Absolute symbol: 0x%08lx %s\n",
+				 (long)sym[i].st_value, name);
 			break;
 
 		case SHN_LIVEPATCH:
-- 
2.30.2

[PATCH 3/4] module: add section-size to move_module pr_debug

[Jim Cromie]

move_module() prints "Final section addresses for $modname".
So lets add those section addresses to the pr_debug(section name)s.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 kernel/module.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index ab16b8da2555..c3333b45d812 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -3393,8 +3393,8 @@ static int move_module(struct module *mod, struct load_info *info)
 			memcpy(dest, (void *)shdr->sh_addr, shdr->sh_size);
 		/* Update sh_addr to point to copy in image. */
 		shdr->sh_addr = (unsigned long)dest;
-		pr_debug("\t0x%lx %s\n",
-			 (long)shdr->sh_addr, info->secstrings + shdr->sh_name);
+		pr_debug("\t0x%lx 0x%.8lx %s\n", (long)shdr->sh_addr,
+			 (long)shdr->sh_size, info->secstrings + shdr->sh_name);
 	}
 
 	return 0;
-- 
2.30.2

[PATCH 4/4] module: reduce already_uses pr_debug verbosity

[Jim Cromie]

already_uses() is unnecessarily chatty.  For example,
`modprobe i915` yields 491 messages like:

  [   64.108744] i915 uses drm!

This is a normal situation, and isn't worth all the log entries.  The
!found pr_debug is kept, its more of an exceptional condition, and
seems worth a pr_debug.  I haven't seen it happen.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 kernel/module.c | 4 +---
 1 file changed, 1 insertion(+), 3 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index c3333b45d812..dc1eda39ba96 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -772,10 +772,8 @@ static int already_uses(struct module *a, struct module *b)
 	struct module_use *use;
 
 	list_for_each_entry(use, &b->source_list, source_list) {
-		if (use->source == a) {
-			pr_debug("%s uses %s!\n", a->name, b->name);
+		if (use->source == a)
 			return 1;
-		}
 	}
 	pr_debug("%s does not use %s!\n", a->name, b->name);
 	return 0;
-- 
2.30.2

[PATCH 0/4] cosmetic fixes to module pr_debugs

[Jim Cromie]

Hi Luis,

These 4 patches alter pr_debug() messages for more info, and less
log-spam.

* add "for $modname:" to banners
  helpful for finding one of many

[   40.885922] main:layout_sections: Core section allocation order for test_dynamic_debug:
    	       ~20 lines of output
[   40.885967] main:move_module: Final section addresses for test_dynamic_debug:
    	       ~2 lines - .init.text/data

* add symbol name to "Absolute symbol: <value>"
  val ~== 0 - less interesting than name

[   40.886006] main:simplify_symbols: Absolute symbol: 0x00000000 test_dynamic_debug.c
[   40.886008] main:simplify_symbols: Absolute symbol: 0x00000000 test_dynamic_debug.mod.c

* add size to section report. gives more info.

[   40.885968] main:move_module: 	0xffffffffc0249000 0x0000035d .text
[   40.885971] main:move_module: 	0xffffffffc0252000 0x0000003c .init.text

* drop already_uses: pr_debug("$ uses $b!") messages

  echo module main +pmf >/proc/dynamic_debug/control
  modprobe i915

before:
  dmesg | grep already_uses | cut -c15- | wc
    673    2722   28641
  dmesg | grep already_uses | cut -c15- | sort -u | wc
     26     134    1237

after:
  dmesg | grep already_uses | cut -c15- | wc
     15      90     756
  dmesg | grep already_uses | cut -c15- | sort -u | wc
     15      90     756


Jim Cromie (4):
  module: in layout_sections, move_module: add the modname
  module: add symbol-name to pr_debug Absolute symbol
  module: add section-size to move_module pr_debug
  module: already_uses() - reduce pr_debug output volume

 kernel/module/main.c | 18 ++++++++----------
 1 file changed, 8 insertions(+), 10 deletions(-)

-- 
2.39.2

[PATCH 2/4] module: add symbol-name to pr_debug Absolute symbol

[Jim Cromie]

The pr_debug("Absolute symbol" ..) reports value, (which is usually
0), but not the name, which is more informative.  So add it.

no functional changes

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 kernel/module/main.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/module/main.c b/kernel/module/main.c
index 39f267c40286..e248a3697ffb 100644
--- a/kernel/module/main.c
+++ b/kernel/module/main.c
@@ -1350,8 +1350,8 @@ static int simplify_symbols(struct module *mod, const struct load_info *info)
 
 		case SHN_ABS:
 			/* Don't need to do anything */
-			pr_debug("Absolute symbol: 0x%08lx\n",
-			       (long)sym[i].st_value);
+			pr_debug("Absolute symbol: 0x%08lx %s\n",
+				 (long)sym[i].st_value, name);
 			break;
 
 		case SHN_LIVEPATCH:
-- 
2.39.2