[PATCH 0/8] dyndbg: WIP diet plan

[PATCH 0/8] dyndbg: WIP diet plan

[Jim Cromie]

dynamic-debug metadata is bloated; the __dyndbg linker section is
effectively an array of struct _ddebugs, its 1st 3 members are highly
repetetive, with 90%, 84%, 45% repeats.  Total reported usage ~150kb
for ~2600 callsites on my laptop config.

This patchset is one diet plan. it all holds together nicely until the
"cache" commit, when it blows up starting init (or right after freeing
unused kernel image, which Im hoping to do...).  The following commit
tweaks locking in an attempt to recover, but fails.


[    0.737936] Freeing unused kernel image (initmem) memory: 1196K
[    0.740173] Write protecting the kernel read-only data: 22528k
[    0.743555] Freeing unused kernel image (text/rodata gap) memory: 2040K
[    0.744984] Freeing unused kernel image (rodata/data gap) memory: 256K
[    0.757777] Run /bin/sh as init process
q[    1.029548] Kernel panic - not syncing: Requested init /bin/sh failed (error -14).
[    1.034582] CPU: 0 PID: 1 Comm: sh Not tainted 5.8.0-00026-g9a06159192d6 #14
[    1.036068] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.13.0-2.fc32 04/01/2014
[    1.037885] Call Trace:
[    1.038444]  dump_stack+0x5e/0x7a
[    1.039172]  ? memcpy_orig+0x100/0x10f
[    1.039917]  panic+0xf6/0x2b7
[    1.040573]  ? rest_init+0xa0/0xa0
[    1.041314]  kernel_init+0xaa/0x100
[    1.041956]  ret_from_fork+0x22/0x30
[    1.042668] Kernel Offset: disabled
[    1.043216] ---[ end Kernel panic - not syncing: Requested init /bin/sh failed (error -14). ]---
QEMU 4.2.1 monitor - type 'help' for more information
(qemu) q

Im sending to kernelnewbies 1st, to see if theres any low-speed
test-crashes I can get post-mortems of, before I take it to the races.

Id appreciate any reviews, tests, or opinions you all might offer (in
that order).  I built for and tested on a virtme instance, 4/5 configs
build and test sane as described, the 5th is probly dead from too many
hacks.

if you use git, and wanna just try it, you can find it here:
  git remote add .. # u dont need full clone
  https://github.com/jimc/linux.git  dyndbg-diet branch

I had good success with virtme, -q=-s -q=-S, and gdb target remote,
all newbies should try it.

These are on top of 5.8.0 +18 others, which GregKH added to his
char-misc-testing &next trees.


Jim Cromie (8):
  dyndbg: give %3u width in pr-format, cosmetic only
  dyndbg: motivate a diet plan
  dyndbg: select ZPOOL in Kconfig.debug
  dyndbg: split struct _ddebug in 2, creating _ddebug_callsite
  dyndbg: WIP replace __dyndbg_callsite section with a zs-pool copy.
  dyndbg: ddebug_zpool_remove
  dyndbg: enable 'cache' of active pr_debug callsites
  dyndbg: add locking around zpool-add loop in zpool-init

 include/asm-generic/vmlinux.lds.h |   4 +
 include/linux/dynamic_debug.h     |  39 ++++--
 lib/Kconfig.debug                 |   1 +
 lib/dynamic_debug.c               | 223 +++++++++++++++++++++++++-----
 4 files changed, 223 insertions(+), 44 deletions(-)

-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 1/8] dyndbg: give %3u width in pr-format, cosmetic only

[Jim Cromie]

Specify the print-width so log entries line up nicely.

no functional changes.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 1d012e597cc3..01b7d0210412 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -947,7 +947,7 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
 	list_add(&dt->link, &ddebug_tables);
 	mutex_unlock(&ddebug_lock);
 
-	v2pr_info("%u debug prints in module %s\n", n, dt->mod_name);
+	v2pr_info("%3u debug prints in module %s\n", n, dt->mod_name);
 	return 0;
 }
 
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 2/8] dyndbg: motivate a diet plan

[Jim Cromie]

this throwaway patch demonstrates the extra weight:

 dyndbg: 2605 entries. repeated entries: 2369 module 2231 file 1147 func

Thats (91%, 86%, 44%) repeated values in those pointers/columns.

This simple test also shows that a similarly simple run-length encoder
on those 3 columns would compress this table dramatically.

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

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 01b7d0210412..691e79826fc2 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -1059,11 +1059,12 @@ static int __init dynamic_debug_init_control(void)
 
 static int __init dynamic_debug_init(void)
 {
-	struct _ddebug *iter, *iter_start;
+	struct _ddebug *iter, *iter_start, *prev = 0;
 	const char *modname = NULL;
 	char *cmdline;
 	int ret = 0;
 	int n = 0, entries = 0, modct = 0;
+	int modreps = 0, funcreps = 0, filereps = 0;
 
 	if (&__start___dyndbg == &__stop___dyndbg) {
 		if (IS_ENABLED(CONFIG_DYNAMIC_DEBUG)) {
@@ -1077,7 +1078,16 @@ static int __init dynamic_debug_init(void)
 	iter = __start___dyndbg;
 	modname = iter->modname;
 	iter_start = iter;
-	for (; iter < __stop___dyndbg; iter++) {
+	for (prev = iter; iter < __stop___dyndbg; iter++) {
+		if (entries) {
+			if (prev->site->modname == iter->site->modname)
+				modreps++;
+			if (prev->site->function == iter->site->function)
+				funcreps++;
+			if (prev->site->filename == iter->site->filename)
+				filereps++;
+			prev++; /* one behind iter */
+		}
 		entries++;
 		if (strcmp(modname, iter->modname)) {
 			modct++;
@@ -1099,6 +1109,9 @@ static int __init dynamic_debug_init(void)
 		 modct, entries, (int)(modct * sizeof(struct ddebug_table)),
 		 (int)(entries * sizeof(struct _ddebug)));
 
+	vpr_info("%d entries. repeated entries: %d module %d file %d func\n",
+		 entries, modreps, filereps, funcreps);
+
 	/* apply ddebug_query boot param, dont unload tables on err */
 	if (ddebug_setup_string[0] != '\0') {
 		pr_warn("ddebug_query param name is deprecated, change it to dyndbg\n");
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 3/8] dyndbg: select ZPOOL in Kconfig.debug

[Jim Cromie]

dyndbg will next need zs_malloc and friends, so add config reqs now,
to avoid touching make-deps late in a patch-set.

I used select in order not to hide dyndbg inadvertently.
I want to say recommends, since it could be an optional feature.
Whats the best way ?

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/Kconfig.debug | 1 +
 1 file changed, 1 insertion(+)

diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 9ad9210d70a1..a7973063baf0 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -100,6 +100,7 @@ config DYNAMIC_DEBUG
 	depends on PRINTK
 	depends on (DEBUG_FS || PROC_FS)
 	select DYNAMIC_DEBUG_CORE
+	select ZPOOL
 	help
 
 	  Compiles debug level messages into the kernel, which would not
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 4/8] dyndbg: split struct _ddebug in 2, creating _ddebug_callsite

[Jim Cromie]

Split the struct into 2 linked parts (head & body) so that next,
struct _ddebug_callsite can be off-lined to zram, and only mapped in
as needed.  The split increases overall memory use by 1 pointer per
callsite, but 4 pointers and a short are now 99% likely to be off-line
(once implemented).

 dyndbg: 264 modules, 2541 entries and 10560 bytes in ddebug tables,\
   81312 bytes in __dyndbg section, 101640 bytes in __dyndbg_callsites section

zram should give us some compression on the _ddebug_callsite data, and
if it doesn't, a simple run-length-encoder would be effective enough,
given the repetition on (modname,filename,function) of (90%,84%,45%)
and the highly ordered contents of the __ddebug_callsites section.

I wanted to also put the key field into _ddebug_callsite, since its
use is super rare; it is only used when enabling/disabling a callsite,
ie only when >control is being actively exersized.  But that blew up
with asm goto errors, so I punted.

So struct _ddebug_callsite is all const, RO data. Maybe thats
advantageous later, but with key there too, we can shrink the online
struct _ddebug further.

details of how:

dynamic_debug.h:

I literally cut struct _ddebug in half, renamed top-half, kept
__align(8) on both, added forward decl for unified comment (not needed
by compiler), and a site pointer from _ddebug to _ddebug_callsite, and
a few "->site" additions.

DECLARE_DYNAMIC_DEBUG_METADATA does the rest; it declares and
initializes both static struct vars together, and refs one to the
other.  Note: this may conflict with new guards against cross-linked
sections, but __init work on __initdata seems a fair loophole.

dynamic_debug.c:

dynamic_debug_init() gets "->site" added everywhere needed.

Other 3 runtime users get a new _ddebug_callsite *dc pointer,
initialized with a single dp->site deref, and s/dp/dc/ as needed.
These one per func dp->site derefs are a setup for the next commit.

vmlinux.lds.h:

add __ddebug_callsites section, with the same align(8) and KEEP as
used in the __ddebug section.  I suspect keep may go as a part of
causing the section reclaim.

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 include/asm-generic/vmlinux.lds.h |  4 +++
 include/linux/dynamic_debug.h     | 38 ++++++++++++++++------
 lib/dynamic_debug.c               | 52 +++++++++++++++++--------------
 3 files changed, 60 insertions(+), 34 deletions(-)

diff --git a/include/asm-generic/vmlinux.lds.h b/include/asm-generic/vmlinux.lds.h
index c78629ec79b6..c874216c01f5 100644
--- a/include/asm-generic/vmlinux.lds.h
+++ b/include/asm-generic/vmlinux.lds.h
@@ -320,6 +320,10 @@
 	*(__tracepoints)						\
 	/* implement dynamic printk debug */				\
 	. = ALIGN(8);							\
+	__start___dyndbg_callsites = .;					\
+	KEEP(*(__dyndbg_callsites))					\
+	__stop___dyndbg_callsites = .;					\
+	. = ALIGN(8);							\
 	__start___dyndbg = .;						\
 	KEEP(*(__dyndbg))						\
 	__stop___dyndbg = .;						\
diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index aa9ff9e1c0b3..1bf52952df69 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -7,11 +7,15 @@
 #endif
 
 /*
- * An instance of this structure is created in a special
- * ELF section at every dynamic debug callsite.  At runtime,
- * the special section is treated as an array of these.
+ * a pair of these structs are created in 2 special ELF sections
+ * (__dyndbg, __dyndbg_callsites) for every dynamic debug callsite.
+ * During init, __dyndbg_callsites is copied to zram, and links to
+ * them in _ddebug are updated.  At runtime, the __dyndbg section is
+ * treated as an array of struct _ddebugs.
  */
-struct _ddebug {
+struct _ddebug;
+struct _ddebug_callsite {
+
 	/*
 	 * These fields are used to drive the user interface
 	 * for selecting and displaying debug callsites.
@@ -20,7 +24,12 @@ struct _ddebug {
 	const char *function;
 	const char *filename;
 	const char *format;
-	unsigned int lineno:18;
+	const unsigned int lineno:16;
+} __aligned(8);
+
+struct _ddebug {
+	struct _ddebug_callsite *site;
+
 	/*
 	 * The flags field controls the behaviour at the callsite.
 	 * The bits here are changed dynamically when the user
@@ -32,21 +41,26 @@ struct _ddebug {
 #define _DPRINTK_FLAGS_INCL_FUNCNAME	(1<<2)
 #define _DPRINTK_FLAGS_INCL_LINENO	(1<<3)
 #define _DPRINTK_FLAGS_INCL_TID		(1<<4)
+#define _DPRINTK_FLAGS_MAPPED		(1<<7) /* reserved */
 #if defined DEBUG
 #define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT
 #else
 #define _DPRINTK_FLAGS_DEFAULT 0
 #endif
 	unsigned int flags:8;
+	/*
+	 * TODO: key probably should be in _callsite, based upon how
+	 * little it is used (only on callsite enable/disable).  But
+	 * that gave weird asm goto errors in jump_label.h and I
+	 * punted.
+	 */
 #ifdef CONFIG_JUMP_LABEL
 	union {
 		struct static_key_true dd_key_true;
 		struct static_key_false dd_key_false;
 	} key;
 #endif
-} __attribute__((aligned(8)));
-
-
+} __aligned(8);
 
 #if defined(CONFIG_DYNAMIC_DEBUG_CORE)
 int ddebug_add_module(struct _ddebug *tab, unsigned int n,
@@ -79,13 +93,17 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
 			 const char *fmt, ...);
 
 #define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt)		\
-	static struct _ddebug  __aligned(8)			\
-	__section(__dyndbg) name = {				\
+	static struct _ddebug_callsite  __aligned(8)		\
+	__section(__dyndbg_callsites) name##_site = {		\
 		.modname = KBUILD_MODNAME,			\
 		.function = __func__,				\
 		.filename = __FILE__,				\
 		.format = (fmt),				\
 		.lineno = __LINE__,				\
+	};							\
+	static struct _ddebug  __aligned(8)			\
+	__section(__dyndbg) name = {				\
+		.site = &name##_site,				\
 		.flags = _DPRINTK_FLAGS_DEFAULT,		\
 		_DPRINTK_KEY_INIT				\
 	}
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 691e79826fc2..9161f345e3c9 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -165,19 +165,20 @@ static int ddebug_change(const struct ddebug_query *query,
 
 		for (i = 0; i < dt->num_ddebugs; i++) {
 			struct _ddebug *dp = &dt->ddebugs[i];
+			struct _ddebug_callsite *dc = dp->site;
 
 			/* match against the source filename */
 			if (query->filename &&
-			    !match_wildcard(query->filename, dp->filename) &&
+			    !match_wildcard(query->filename, dc->filename) &&
 			    !match_wildcard(query->filename,
-					   kbasename(dp->filename)) &&
+					   kbasename(dc->filename)) &&
 			    !match_wildcard(query->filename,
-					   trim_prefix(dp->filename)))
+					   trim_prefix(dc->filename)))
 				continue;
 
 			/* match against the function */
 			if (query->function &&
-			    !match_wildcard(query->function, dp->function))
+			    !match_wildcard(query->function, dc->function))
 				continue;
 
 			/* match against the format */
@@ -185,19 +186,19 @@ static int ddebug_change(const struct ddebug_query *query,
 				if (*query->format == '^') {
 					char *p;
 					/* anchored search. match must be at beginning */
-					p = strstr(dp->format, query->format+1);
-					if (p != dp->format)
+					p = strstr(dc->format, query->format+1);
+					if (p != dc->format)
 						continue;
-				} else if (!strstr(dp->format, query->format))
+				} else if (!strstr(dc->format, query->format))
 					continue;
 			}
 
 			/* match against the line number range */
 			if (query->first_lineno &&
-			    dp->lineno < query->first_lineno)
+			    dc->lineno < query->first_lineno)
 				continue;
 			if (query->last_lineno &&
-			    dp->lineno > query->last_lineno)
+			    dc->lineno > query->last_lineno)
 				continue;
 
 			nfound++;
@@ -214,8 +215,8 @@ static int ddebug_change(const struct ddebug_query *query,
 #endif
 			dp->flags = newflags;
 			v2pr_info("changed %s:%d [%s]%s =%s\n",
-				 trim_prefix(dp->filename), dp->lineno,
-				 dt->mod_name, dp->function,
+				 trim_prefix(dc->filename), dc->lineno,
+				 dt->mod_name, dc->function,
 				 ddebug_describe_flags(dp->flags, &fbuf));
 		}
 	}
@@ -568,14 +569,15 @@ static int remaining(int wrote)
 	return 0;
 }
 
-static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
+static char *dynamic_emit_prefix(const struct _ddebug *dp, char *buf)
 {
 	int pos_after_tid;
 	int pos = 0;
+	const struct _ddebug_callsite *desc = dp->site;
 
 	*buf = '\0';
 
-	if (desc->flags & _DPRINTK_FLAGS_INCL_TID) {
+	if (dp->flags & _DPRINTK_FLAGS_INCL_TID) {
 		if (in_interrupt())
 			pos += snprintf(buf + pos, remaining(pos), "<intr> ");
 		else
@@ -583,13 +585,13 @@ static char *dynamic_emit_prefix(const struct _ddebug *desc, char *buf)
 					task_pid_vnr(current));
 	}
 	pos_after_tid = pos;
-	if (desc->flags & _DPRINTK_FLAGS_INCL_MODNAME)
+	if (dp->flags & _DPRINTK_FLAGS_INCL_MODNAME)
 		pos += snprintf(buf + pos, remaining(pos), "%s:",
 				desc->modname);
-	if (desc->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
+	if (dp->flags & _DPRINTK_FLAGS_INCL_FUNCNAME)
 		pos += snprintf(buf + pos, remaining(pos), "%s:",
 				desc->function);
-	if (desc->flags & _DPRINTK_FLAGS_INCL_LINENO)
+	if (dp->flags & _DPRINTK_FLAGS_INCL_LINENO)
 		pos += snprintf(buf + pos, remaining(pos), "%d:",
 				desc->lineno);
 	if (pos - pos_after_tid)
@@ -861,6 +863,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 {
 	struct ddebug_iter *iter = m->private;
 	struct _ddebug *dp = p;
+	struct _ddebug_callsite *dc = dp->site;
 	struct flagsbuf flags;
 
 	if (p == SEQ_START_TOKEN) {
@@ -870,10 +873,10 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 	}
 
 	seq_printf(m, "%s:%u [%s]%s =%s \"",
-		   trim_prefix(dp->filename), dp->lineno,
-		   iter->table->mod_name, dp->function,
+		   trim_prefix(dc->filename), dc->lineno,
+		   iter->table->mod_name, dc->function,
 		   ddebug_describe_flags(dp->flags, &flags));
-	seq_escape(m, dp->format, "\t\r\n\"");
+	seq_escape(m, dc->format, "\t\r\n\"");
 	seq_puts(m, "\"\n");
 
 	return 0;
@@ -1076,7 +1079,7 @@ static int __init dynamic_debug_init(void)
 		return 0;
 	}
 	iter = __start___dyndbg;
-	modname = iter->modname;
+	modname = iter->site->modname;
 	iter_start = iter;
 	for (prev = iter; iter < __stop___dyndbg; iter++) {
 		if (entries) {
@@ -1089,13 +1092,13 @@ static int __init dynamic_debug_init(void)
 			prev++; /* one behind iter */
 		}
 		entries++;
-		if (strcmp(modname, iter->modname)) {
+		if (strcmp(modname, iter->site->modname)) {
 			modct++;
 			ret = ddebug_add_module(iter_start, n, modname);
 			if (ret)
 				goto out_err;
 			n = 0;
-			modname = iter->modname;
+			modname = iter->site->modname;
 			iter_start = iter;
 		}
 		n++;
@@ -1105,9 +1108,10 @@ static int __init dynamic_debug_init(void)
 		goto out_err;
 
 	ddebug_init_success = 1;
-	vpr_info("%d modules, %d entries and %d bytes in ddebug tables, %d bytes in __dyndbg section\n",
+	vpr_info("%d modules, %d entries and %d bytes in ddebug tables, %d bytes in __dyndbg section, %d bytes in __dyndbg_callsites section\n",
 		 modct, entries, (int)(modct * sizeof(struct ddebug_table)),
-		 (int)(entries * sizeof(struct _ddebug)));
+		 (int)(entries * sizeof(struct _ddebug)),
+		 (int)(entries * sizeof(struct _ddebug_callsite)));
 
 	vpr_info("%d entries. repeated entries: %d module %d file %d func\n",
 		 entries, modreps, filereps, funcreps);
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 5/8] dyndbg: WIP replace __dyndbg_callsite section with a zs-pool copy.

[Jim Cromie]

HEAD~1 split struct _ddebugs into heads & bodies, linked accross 2 ELF
sections.  Lets now store copies of the bodies into a zs_pool, and
relink head to the new body.  This should allow recycling the section
soon.

The strategy is to let a compression algo handle the repetition, and
map individual records in when needed.  If that works, we only need
one record at a time, so the 3:1 zram compression applys to 99.9% of
callsites, ie to 98120 bytes below:

 dyndbg: 259 modules, 2453 entries and 10360 bytes in ddebug tables, 98120 bytes in __dyndbg section, 98120 bytes in __dyndbg_callsites section
 dyndbg: 2453 entries. repeated entries: 2193 module 2058 file 981 func

Since dynamic_debug is nice to have but rarely used, paying more for
active logging to save in-kernel memory might be a worthwhile tradeoff.

This is how:

ddebug_zpool_init(), at late_initcall time, creates the zpool.

Existing ddebug_add_module() now also calls ddebug_zpool_add(), which
copies the module's _ddebug records into the zpool, once it is ready.
For builtins, added early, the pool is not ready yet.

So ddebug_zpool_init() also calls ddebug_zpool_add() for all those
builtin modules already _add()ed.

ddebug_zpool_add() does, foreach _ddebug:
 - zs_mallocs and saves to .zhandle,
 - zs_maps and saves .site to it
 - zs_unmaps it, triggering write to zram
 - .site=0, detaching __dyndbg_callsites[item]
   which later triggers zs_map

So we leave late-init with a full zram copy,
and __dyndbg_callsites ready to reclaim.

run-time access for 3 existing users is entirely via helpers;
ddebug_callsite_get(), ddebug_callsite_put().  These 3 uses are all
with ddebug_lock held.

_get() returns .site 1st, or maps zrec to it and returns it.
_put() always unmaps, minimizing online ram (see 1 below)

ddebug_change() also gets s/continue/goto skipsite/g to cleanly unmap
the record at the bottom of the loop.

Next steps:

1. dont always unmap in _put(), leave enabled pr_debugs mapped.

This would make the set of zs_mapped recs work like a cache, reducing
zs_mappings to a trickle, and only for <>control.

2. adapt struct _ddebug to unionize .site and .zhandle

We currently use !!.site and !!.zhandle tests to keep state, we have
bits available in flags to replace these tests, making union possible.

A crazy alt is to create a "restricted" zpool, which limits pool size
to 2**N handles, and returned handles to an (N+ck)-bit number, which
would fit beside our 8-bit flags, inside an 8-byte pointer.  This
would be cool, but isnt necessary, since union looks practical.

3. move key from struct _ddebug into _ddebug_callsite

key doesnt exactly fit semantically (and its not RO), but its use is
super rare, and is never needed without also needing all the other
callsite data.  Getting it out of head saves on-line ram.  But it
broke in HEAD~1 when I tried it, with asm goto errors.

4. linker question

DECLARE_DYNAMIC_DEBUG_METADATA macro fills 2 sections simultaneously.
If we can rely on the linker to keep those records in identical order,
we can 'index' both _dyndbg & _callsites (& keys) with [N-opaque] and
drop the .site pointer.

5. improve compression ?

Im seeing 3:1 pages_per_zspage:

 # cut -c1-12,40-77,85-90 $SKD/zsmalloc/dyndbg_callsites/classes | head -n3
 class  sizebj_allocated   obj_used pages_used pagzspage
     0    32           0          0          0         1
     1    48        2816       2605         33         3

Since the __dyndbg_callsite section is well sorted, a simple
run-length encoding on 3 RO members (modname, file, function) could
reclaim most of the (90%, 84%, 45%) repeated values.  That said, a
standard compressor should be able to compete, and there are several
to try.

Lastly, this whole zram block is RO after late-init (maybe, if we
split into 2 zpools, for builtins and loadable modules).  So
compression can be biased towards costly but excellent compression
(esp for RO zpool) and good small block decompression for random-ish
access.

6. we could add a ram_reclaim(), to walk the dt-list, check each
_ddebug, and unmap the mapped ones.  This presumes 1. is done, and
there are sometimes memory pressures to respond to.

Potential benefits:
- convert in-kernel mem to zram/etc
- zram compression
- eventually swap it out entirely
- map in the enabled callsites only

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 include/linux/dynamic_debug.h |   1 +
 lib/dynamic_debug.c           | 140 +++++++++++++++++++++++++++++++---
 2 files changed, 129 insertions(+), 12 deletions(-)

diff --git a/include/linux/dynamic_debug.h b/include/linux/dynamic_debug.h
index 1bf52952df69..693911920a32 100644
--- a/include/linux/dynamic_debug.h
+++ b/include/linux/dynamic_debug.h
@@ -29,6 +29,7 @@ struct _ddebug_callsite {
 
 struct _ddebug {
 	struct _ddebug_callsite *site;
+	long unsigned int zhandle;
 
 	/*
 	 * The flags field controls the behaviour at the callsite.
diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 9161f345e3c9..049299027fb3 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -36,6 +36,7 @@
 #include <linux/sched.h>
 #include <linux/device.h>
 #include <linux/netdevice.h>
+#include <linux/zsmalloc.h>
 
 #include <rdma/ib_verbs.h>
 
@@ -72,6 +73,8 @@ static LIST_HEAD(ddebug_tables);
 static int verbose;
 module_param(verbose, int, 0644);
 
+static struct zs_pool *dd_callsite_zpool;
+
 /* Return the path relative to source root */
 static inline const char *trim_prefix(const char *path)
 {
@@ -118,6 +121,8 @@ do {								\
 
 #define vpr_info(fmt, ...)	vnpr_info(1, fmt, ##__VA_ARGS__)
 #define v2pr_info(fmt, ...)	vnpr_info(2, fmt, ##__VA_ARGS__)
+#define v3pr_info(fmt, ...)	vnpr_info(3, fmt, ##__VA_ARGS__)
+#define v4pr_info(fmt, ...)	vnpr_info(4, fmt, ##__VA_ARGS__)
 
 static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
 {
@@ -139,6 +144,41 @@ static void vpr_info_dq(const struct ddebug_query *query, const char *msg)
 		 query->first_lineno, query->last_lineno);
 }
 
+/*
+ * Lifecycle of struct _ddebug's .site and .zhandle:
+ *
+ * At early-init, .site points into __dyndbg_callsite[], .zhandle=0
+ *
+ * At late-init, zpool_add(callsite)s copies into zram, saves ref in
+ * .zhandle, and forgets .site, allowing __dyndbg_callsite[] to be
+ * reclaimed.  After this, we restore .site from .zhandle when needed.
+ * We default to minimal mapping, load on demand.
+ *
+ * _get() returns .site preferentially, and updates it when needed.
+ * this works for early-prints and minimal mapped records strategy.
+ */
+static struct _ddebug_callsite* ddebug_callsite_get(struct _ddebug *dp)
+{
+	if (dp->site)
+		return dp->site;
+
+	dp->site = (struct _ddebug_callsite*)
+		zs_map_object(dd_callsite_zpool, dp->zhandle, ZS_MM_RO);
+
+	return dp->site;
+}
+
+static void ddebug_callsite_put(struct _ddebug *dp)
+{
+	if (!dp->site || !dp->zhandle)
+		/* no site to unmap, or no means to restore */
+		return;
+
+	/* always unmap for now. if !pr-debug was too hard */
+	zs_unmap_object(dd_callsite_zpool, dp->zhandle);
+	dp->site = NULL;
+}
+
 /*
  * Search the tables for _ddebug's which match the given `query' and
  * apply the `flags' and `mask' to them.  Returns number of matching
@@ -165,7 +205,8 @@ static int ddebug_change(const struct ddebug_query *query,
 
 		for (i = 0; i < dt->num_ddebugs; i++) {
 			struct _ddebug *dp = &dt->ddebugs[i];
-			struct _ddebug_callsite *dc = dp->site;
+			struct _ddebug_callsite *dc;
+			dc = ddebug_callsite_get(dp);
 
 			/* match against the source filename */
 			if (query->filename &&
@@ -174,12 +215,12 @@ static int ddebug_change(const struct ddebug_query *query,
 					   kbasename(dc->filename)) &&
 			    !match_wildcard(query->filename,
 					   trim_prefix(dc->filename)))
-				continue;
+				goto skipsite;
 
 			/* match against the function */
 			if (query->function &&
 			    !match_wildcard(query->function, dc->function))
-				continue;
+				goto skipsite;
 
 			/* match against the format */
 			if (query->format) {
@@ -188,24 +229,24 @@ static int ddebug_change(const struct ddebug_query *query,
 					/* anchored search. match must be at beginning */
 					p = strstr(dc->format, query->format+1);
 					if (p != dc->format)
-						continue;
+						goto skipsite;
 				} else if (!strstr(dc->format, query->format))
-					continue;
+					goto skipsite;
 			}
 
 			/* match against the line number range */
 			if (query->first_lineno &&
 			    dc->lineno < query->first_lineno)
-				continue;
+				goto skipsite;
 			if (query->last_lineno &&
 			    dc->lineno > query->last_lineno)
-				continue;
+				goto skipsite;
 
 			nfound++;
 
 			newflags = (dp->flags & modifiers->mask) | modifiers->flags;
 			if (newflags == dp->flags)
-				continue;
+				goto skipsite;
 #ifdef CONFIG_JUMP_LABEL
 			if (dp->flags & _DPRINTK_FLAGS_PRINT) {
 				if (!(modifiers->flags & _DPRINTK_FLAGS_PRINT))
@@ -218,6 +259,9 @@ static int ddebug_change(const struct ddebug_query *query,
 				 trim_prefix(dc->filename), dc->lineno,
 				 dt->mod_name, dc->function,
 				 ddebug_describe_flags(dp->flags, &fbuf));
+
+		skipsite:
+			ddebug_callsite_put(dp);
 		}
 	}
 	mutex_unlock(&ddebug_lock);
@@ -569,14 +613,16 @@ static int remaining(int wrote)
 	return 0;
 }
 
-static char *dynamic_emit_prefix(const struct _ddebug *dp, char *buf)
+static char *dynamic_emit_prefix(struct _ddebug *dp, char *buf)
 {
 	int pos_after_tid;
 	int pos = 0;
-	const struct _ddebug_callsite *desc = dp->site;
+	const struct _ddebug_callsite *desc;
 
 	*buf = '\0';
 
+	desc = ddebug_callsite_get(dp);
+
 	if (dp->flags & _DPRINTK_FLAGS_INCL_TID) {
 		if (in_interrupt())
 			pos += snprintf(buf + pos, remaining(pos), "<intr> ");
@@ -599,6 +645,8 @@ static char *dynamic_emit_prefix(const struct _ddebug *dp, char *buf)
 	if (pos >= PREFIX_SIZE)
 		buf[PREFIX_SIZE - 1] = '\0';
 
+	ddebug_callsite_put(dp);
+
 	return buf;
 }
 
@@ -863,7 +911,7 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 {
 	struct ddebug_iter *iter = m->private;
 	struct _ddebug *dp = p;
-	struct _ddebug_callsite *dc = dp->site;
+	struct _ddebug_callsite *dc;
 	struct flagsbuf flags;
 
 	if (p == SEQ_START_TOKEN) {
@@ -872,6 +920,8 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 		return 0;
 	}
 
+	dc = ddebug_callsite_get(dp);
+
 	seq_printf(m, "%s:%u [%s]%s =%s \"",
 		   trim_prefix(dc->filename), dc->lineno,
 		   iter->table->mod_name, dc->function,
@@ -879,6 +929,8 @@ static int ddebug_proc_show(struct seq_file *m, void *p)
 	seq_escape(m, dc->format, "\t\r\n\"");
 	seq_puts(m, "\"\n");
 
+	ddebug_callsite_put(dp);
+
 	return 0;
 }
 
@@ -922,6 +974,39 @@ static const struct proc_ops proc_fops = {
 	.proc_write = ddebug_proc_write
 };
 
+/*
+ * copy struct _ddebug records into the zpool, and remember zhandle in
+ * the struct.  This is close to what we'll want to unionize the
+ * handle and the struct
+ */
+static void ddebug_zpool_add(struct _ddebug *dp)
+{
+	unsigned long handle;
+	struct _ddebug_callsite *cursor;
+
+	handle = zs_malloc(dd_callsite_zpool, sizeof(struct _ddebug_callsite),
+			   GFP_KERNEL);
+	if (!handle) {
+		pr_err("pool malloc failed on %s\n", dp->site->function);
+		return;
+	}
+	BUG_ON(handle % 2); /* zs-malloc handles are even ! */
+	dp->zhandle = handle;
+
+	cursor = (struct _ddebug_callsite *)
+		zs_map_object(dd_callsite_zpool, handle, ZS_MM_WO);
+
+	if (!cursor) {
+		pr_err("zs-map failed\n");
+		return;
+	}
+	memcpy(cursor, dp->site, sizeof(struct _ddebug_callsite));
+
+	/* forget __dyndbg_callsites[] so we can reclaim it */
+	dp->site = NULL;
+	zs_unmap_object(dd_callsite_zpool, handle);
+}
+
 /*
  * Allocate a new ddebug_table for the given module
  * and add it to the global list.
@@ -947,10 +1032,15 @@ int ddebug_add_module(struct _ddebug *tab, unsigned int n,
 	dt->ddebugs = tab;
 
 	mutex_lock(&ddebug_lock);
+	if (dd_callsite_zpool)
+		/* zpool is ready for filling late */
+		for (; n; n--, tab++)
+			ddebug_zpool_add(tab);
+
 	list_add(&dt->link, &ddebug_tables);
 	mutex_unlock(&ddebug_lock);
 
-	v2pr_info("%3u debug prints in module %s\n", n, dt->mod_name);
+	v2pr_info("%3u debug prints in module %s\n", dt->num_ddebugs, dt->mod_name);
 	return 0;
 }
 
@@ -1060,6 +1150,31 @@ static int __init dynamic_debug_init_control(void)
 	return 0;
 }
 
+/*
+ * initialize the zpool, and fill it with copies of struct _ddebug
+ * records in the __verbose/__dyndbg section.
+ */
+static void __init ddebug_zpool_init(void)
+{
+	struct _ddebug *iter;
+
+	/* tbd- no corresponding destroy */
+	dd_callsite_zpool = zs_create_pool("dyndbg_callsites");
+	if (!dd_callsite_zpool) {
+		pr_err("create pool failed\n");
+		return;
+	}
+
+	/* add-module normally does this, but not in time for builtins */
+	for (iter = __start___dyndbg; iter < __stop___dyndbg; iter++)
+		ddebug_zpool_add(iter);
+
+	v2pr_info("total pages: %lu compaction: %lu\n",
+		  zs_get_total_pages(dd_callsite_zpool),
+		  zs_compact(dd_callsite_zpool));
+}
+late_initcall(ddebug_zpool_init);
+
 static int __init dynamic_debug_init(void)
 {
 	struct _ddebug *iter, *iter_start, *prev = 0;
@@ -1149,3 +1264,4 @@ early_initcall(dynamic_debug_init);
 
 /* Debugfs setup must be done later */
 fs_initcall(dynamic_debug_init_control);
+
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 6/8] dyndbg: ddebug_zpool_remove

[Jim Cromie]

add ddebug_zpool_remove() to undo ddebug_zpool_add(), and call it from
ddebug_remove_module().

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c | 19 +++++++++++++++++++
 1 file changed, 19 insertions(+)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 049299027fb3..102f47b2a439 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -1007,6 +1007,18 @@ static void ddebug_zpool_add(struct _ddebug *dp)
 	zs_unmap_object(dd_callsite_zpool, handle);
 }
 
+static void ddebug_zpool_remove(struct _ddebug *dp)
+{
+	if (dp->site) {
+		pr_warn("zhandle shouldnt be mapped now\n");
+		zs_unmap_object(dd_callsite_zpool, dp->zhandle);
+	}
+	if (!dp->zhandle)
+		pr_err("zhandle already cleared !\n");
+	else
+		zs_free(dd_callsite_zpool, dp->zhandle);
+}
+
 /*
  * Allocate a new ddebug_table for the given module
  * and add it to the global list.
@@ -1104,6 +1116,13 @@ int ddebug_remove_module(const char *mod_name)
 	mutex_lock(&ddebug_lock);
 	list_for_each_entry_safe(dt, nextdt, &ddebug_tables, link) {
 		if (dt->mod_name == mod_name) {
+
+			unsigned int n = dt->num_ddebugs;
+			struct _ddebug *dp = dt->ddebugs;
+
+			for (; n; n--, dp++)
+				ddebug_zpool_remove(dp);
+
 			ddebug_table_free(dt);
 			ret = 0;
 			break;
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 7/8] dyndbg: enable 'cache' of active pr_debug callsites

[Jim Cromie]

in ddebug_zpool_put() dont zs_unmap the callsite, if it is enabled for
printing.  This will eliminate possibly repeated un-maps then re-maps
of enabled and invoked pr-debug callsites, and will promptly retire
all other uses.

Unfortunately this causes mysterious problems:
(needs more editing down)

[jimc@frodo build-v2]$ gdb -x cmds vmlinux
GNU gdb (GDB) Fedora 9.1-5.fc32
...
Reading symbols from vmlinux...
0x000000000000fff0 in exception_stacks ()
Hardware assisted breakpoint 1 at 0xffffffff82c2de50: file ../lib/dynamic_debug.c, line 1164.

Breakpoint 1, ddebug_zpool_init () at ../lib/dynamic_debug.c:1164
1164		dd_callsite_zpool = zs_create_pool("dyndbg_callsites");
    at ../include/linux/compiler.h:352
--Type <RET> for more, q to quit, c to continue without paging--
Num     Type           Disp Enb Address            What
1       hw breakpoint  keep y   0xffffffff82c2de50 in ddebug_zpool_init at ../lib/dynamic_debug.c:1164
	breakpoint already hit 1 time
(gdb) l
1159	static void __init ddebug_zpool_init(void)
1160	{
1161		struct _ddebug *iter;
1162
1163		/* tbd- no corresponding destroy */
1164		dd_callsite_zpool = zs_create_pool("dyndbg_callsites");
1165		if (!dd_callsite_zpool) {
1166			pr_err("create pool failed\n");
1167			return;
1168		}
(gdb) l
1169
1170		/* add-module normally does this, but not in time for builtins */
1171		for (iter = __start___dyndbg; iter < __stop___dyndbg; iter++)
1172			ddebug_zpool_add(iter);
1173
1174		v2pr_info("total pages: %lu compaction: %lu\n",
1175			  zs_get_total_pages(dd_callsite_zpool),
1176			  zs_compact(dd_callsite_zpool));
1177	}
1178	late_initcall(ddebug_zpool_init);
(gdb) b 1174
Breakpoint 2 at 0xffffffff82c2de9b: file ../lib/dynamic_debug.c, line 1174.
(gdb) c
Continuing.

Breakpoint 2, ddebug_zpool_init () at ../lib/dynamic_debug.c:1174
1174		v2pr_info("total pages: %lu compaction: %lu\n",
(gdb) n
do_one_initcall (fn=0xffffffff82c2de50 <ddebug_zpool_init>) at ../init/main.c:1200
1200		do_trace_initcall_finish(fn, ret);
(gdb)
1204		if (preempt_count() != count) {
(gdb)
26		return raw_cpu_read_4(__preempt_count) & ~PREEMPT_NEED_RESCHED;
(gdb)
1208		if (irqs_disabled()) {
(gdb)
164		return !(flags & X86_EFLAGS_IF);
(gdb)
1212		WARN(msgbuf[0], "initcall %pS returned with %s\n", fn, msgbuf);
(gdb)
do_initcall_level (command_line=<optimized out>, level=<optimized out>) at ../init/main.c:1271
(gdb) info break
Num     Type           Disp Enb Address            What
1       hw breakpoint  keep y   0xffffffff82c2de50 in ddebug_zpool_init at ../lib/dynamic_debug.c:1164
	breakpoint already hit 1 time
2       breakpoint     keep y   0xffffffff82c2de9b in ddebug_zpool_init at ../lib/dynamic_debug.c:1174
	breakpoint already hit 1 time
(gdb) bt
(gdb) up
1288			do_initcall_level(level, command_line);
(gdb) up
1308		do_initcalls();
(gdb) return
Can not force return from an inlined function.
(gdb) b
Breakpoint 3 at 0xffffffff82bfe1c6: file ../include/linux/compiler.h, line 352.
(gdb) c
Continuing.

Breakpoint 3, offset_to_ptr (off=<optimized out>) at ../include/linux/compiler.h:352
352		return (void *)((unsigned long)off + *off);
(gdb) n
do_initcall_level (command_line=<optimized out>, level=<optimized out>) at ../init/main.c:1271
1271		for (fn = initcall_levels[level]; fn < initcall_levels[level+1]; fn++)
(gdb)

Breakpoint 3, offset_to_ptr (off=<optimized out>) at ../include/linux/compiler.h:352
352		return (void *)((unsigned long)off + *off);
(gdb)
do_initcall_level (command_line=<optimized out>, level=<optimized out>) at ../init/main.c:1271
1271		for (fn = initcall_levels[level]; fn < initcall_levels[level+1]; fn++)
(gdb)

Breakpoint 3, offset_to_ptr (off=<optimized out>) at ../include/linux/compiler.h:352
352		return (void *)((unsigned long)off + *off);
(gdb)
do_initcall_level (command_line=<optimized out>, level=<optimized out>) at ../init/main.c:1271
1271		for (fn = initcall_levels[level]; fn < initcall_levels[level+1]; fn++)
(gdb)
do_initcalls () at ../init/main.c:1285
1285		for (level = 0; level < ARRAY_SIZE(initcall_levels) - 1; level++) {
(gdb)
1291		kfree(command_line);
(gdb)
kernel_init_freeable () at ../init/main.c:1507
1507		console_on_rootfs();
(gdb)
1514		if (!ramdisk_execute_command)
(gdb)
1515			ramdisk_execute_command = "/init";
(gdb)
1517		if (ksys_access((const char __user *)
(gdb)
1519			ramdisk_execute_command = NULL;
(gdb)
1520			prepare_namespace();
(gdb)

1532		integrity_load_keys();
(gdb)

kernel_init (unused=<optimized out>) at ../init/main.c:1401
1401		async_synchronize_full();
(gdb)
1403		free_initmem();
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1404		mark_readonly();
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1410		pti_finalize();
(gdb) bt
(gdb) info break
Num     Type           Disp Enb Address            What
1       hw breakpoint  keep y   0xffffffff82c2de50 in ddebug_zpool_init at ../lib/dynamic_debug.c:1164
	breakpoint already hit 1 time
2       breakpoint     keep y   0xffffffff82c2de9b in ddebug_zpool_init at ../lib/dynamic_debug.c:1174
	breakpoint already hit 1 time
3       breakpoint     keep y   0xffffffff82bfe1c6 ../include/linux/compiler.h:352
	breakpoint already hit 7 times
(gdb) info break 3
Num     Type           Disp Enb Address            What
3       breakpoint     keep y   0xffffffff82bfe1c6 ../include/linux/compiler.h:352
	breakpoint already hit 7 times
(gdb) n
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1412		system_state = SYSTEM_RUNNING;
(gdb) n
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1413		numa_default_policy();
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1415		rcu_end_inkernel_boot();
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1417		do_sysctl_args();
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1419		if (ramdisk_execute_command) {
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1433		if (execute_command) {
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1434			ret = run_init_process(execute_command);
(gdb) l
1429		 *
1430		 * The Bourne shell can be used instead of init if we are
1431		 * trying to recover a really broken machine.
1432		 */
1433		if (execute_command) {
1434			ret = run_init_process(execute_command);
1435			if (!ret)
1436				return 0;
1437			panic("Requested init %s failed (error %d).",
1438			      execute_command, ret);
(gdb) s
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
run_init_process (init_filename=0xffff888007fd6525 "/bin/sh") at ../init/main.c:1324
1324		argv_init[0] = init_filename;
(gdb) n
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1325		pr_info("Run %s as init process\n", init_filename);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1326		pr_debug("  with arguments:\n");
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1327		for (p = argv_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1328			pr_debug("    %s\n", *p);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1327		for (p = argv_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1328			pr_debug("    %s\n", *p);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1327		for (p = argv_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1328			pr_debug("    %s\n", *p);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1327		for (p = argv_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1329		pr_debug("  with environment:\n");
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1330		for (p = envp_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1331			pr_debug("    %s\n", *p);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1330		for (p = envp_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1331			pr_debug("    %s\n", *p);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1330		for (p = envp_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1331			pr_debug("    %s\n", *p);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1330		for (p = envp_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1331			pr_debug("    %s\n", *p);
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1330		for (p = envp_init; *p; p++)
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1332		return do_execve(getname_kernel(init_filename),
(gdb)
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
kernel_init (unused=<optimized out>) at ../init/main.c:1435
1435			if (!ret)
(gdb) n
Cannot remove breakpoints because program is no longer writable.
Further execution is probably impossible.
1437			panic("Requested init %s failed (error %d).",
(gdb)

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 102f47b2a439..9c51f24a9c66 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -174,7 +174,9 @@ static void ddebug_callsite_put(struct _ddebug *dp)
 		/* no site to unmap, or no means to restore */
 		return;
 
-	/* always unmap for now. if !pr-debug was too hard */
+	if (dp->flags & _DPRINTK_FLAGS_PRINT)
+		return; /* keep maps of enabled pr_debugs */
+
 	zs_unmap_object(dd_callsite_zpool, dp->zhandle);
 	dp->site = NULL;
 }
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

[PATCH 8/8] dyndbg: add locking around zpool-add loop in zpool-init

[Jim Cromie]

summary: no fix here.

Locking review:

ddebug_zpool_init(), like other *_init() routines, does not run under
a lock (that we control).  Unlike them, it runs later, at late_init.
I dont know whether this is pertinent to the kernel panic.

ddebug_callsite_get/put() are called as a pair under mutex-lock for
all 3 callsite users; dynamic_emit_prefix() does its own ABBA-ish LGPU
(Lock-Get-Put-Unlock), as does ddebug_change().

ddebug_proc_show() does GP, ddebug_proc_start|stop() wrap it with LU.

ddebug_add_module() does LU to protect list_add(), HEAD~x added
ddebug_zpool_add() inside that protection.

This commit adds locking to ddebug_zpool_init(), around the loop of
ddebug_zpool_add(), to match the locking in ddebug_add_module().

Signed-off-by: Jim Cromie <jim.cromie@gmail.com>
---
 lib/dynamic_debug.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index 9c51f24a9c66..716231a98910 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -1187,8 +1187,10 @@ static void __init ddebug_zpool_init(void)
 	}
 
 	/* add-module normally does this, but not in time for builtins */
+	mutex_lock(&ddebug_lock);
 	for (iter = __start___dyndbg; iter < __stop___dyndbg; iter++)
 		ddebug_zpool_add(iter);
+	mutex_unlock(&ddebug_lock);
 
 	v2pr_info("total pages: %lu compaction: %lu\n",
 		  zs_get_total_pages(dd_callsite_zpool),
@@ -1285,4 +1287,3 @@ early_initcall(dynamic_debug_init);
 
 /* Debugfs setup must be done later */
 fs_initcall(dynamic_debug_init_control);
-
-- 
2.26.2


_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

Re: [PATCH 0/8] dyndbg: WIP diet plan

[jim.cromie]

> Im sending to kernelnewbies 1st, to see if theres any low-speed
> test-crashes I can get post-mortems of, before I take it to the races.
>
>

So, I might as well narrate a bit here, see if I can get to a
compelling story ..

$ gdb -x ../cmds vmlinux

$ more ../cmds
target remote :1234
# hbreak ddebug_zpool_init
# c
# return

hbreak run_init_process
break dynamic_emit_prefix
break __dynamic_pr_debug
c


OK, so in the middle of stepping / nexting I get into apic-* stuff

its hard to read w/o the colorized context..

ddebug_callsite_put (dp=<optimized out>) at ../lib/dynamic_debug.c:650
650 ddebug_callsite_put(dp);
(gdb) s
177 if (dp->flags & _DPRINTK_FLAGS_PRINT)
(gdb)
dynamic_emit_prefix (dp=0xffffffff827a7458 <__UNIQUE_ID_ddebug356.11>,
    buf=0xffffc90000013ea0 "main:run_init_process: ") at
../lib/dynamic_debug.c:652
652 return buf;
(gdb)
printk (fmt=0xffffffff824773b6 "\001\067%s%pV") at
../kernel/printk/printk.c:2069
2069 va_start(args, fmt);
(gdb)
2070 r = vprintk_func(fmt, args);
(gdb)
vprintk_func (fmt=0xffffffff824773b6 "\001\067%s%pV", args=0xffffc90000013e18)
    at ../kernel/printk/printk_safe.c:374
374 if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) &&



(gdb) bt
#0  vprintk_func (fmt=0xffffffff824773b6 "\001\067%s%pV",
args=0xffffc90000013e18)
    at ../kernel/printk/printk_safe.c:374
#1  0xffffffff811475bc in printk (fmt=<optimized out>) at
../kernel/printk/printk.c:2070
#2  0xffffffff814aec2a in __dynamic_pr_debug (descriptor=<optimized
out>, fmt=<optimized out>)
    at ../lib/dynamic_debug.c:669
#3  0xffffffff810010a1 in run_init_process
(init_filename=0xffff888007fd6545 "/bin/sh")
    at ../init/main.c:1326
#4  0xffffffff81c64741 in kernel_init (unused=<optimized out>) at
../init/main.c:1434
#5  0xffffffff81001f62 in ret_from_fork () at ../arch/x86/entry/entry_64.S:293
#6  0x0000000000000000 in ?? ()
(gdb) ret
Make vprintk_func return now? (y or n) y
#0  printk (fmt=<optimized out>) at ../kernel/printk/printk.c:2073
2073 return r;

HERE, I NEXT INTO LAPIC, SHUTDOWN mumble.
is there anything I can unconfigure to avoid
how can I avoid these kind of things ?
is there something I can un-configure for a virtual kernel

(gdb) n
lapic_timer_shutdown (evt=<optimized out>) at ../arch/x86/kernel/apic/apic.c:490
490 apic_write(APIC_LVTT, v);
(gdb) n
491 apic_write(APIC_TMICT, 0);
(gdb)
492 return 0;
(gdb)
clockevents_switch_state (dev=0xffff888007a174c0,
state=CLOCK_EVT_STATE_ONESHOT_STOPPED)
    at ../kernel/time/clockevents.c:154
154 clockevent_set_state(dev, state);
(gdb)
152 return dev->state_use_accessors == CLOCK_EVT_STATE_ONESHOT;
(gdb)
tick_program_event (expires=9223372036854775807, force=<optimized out>)
    at ../kernel/time/tick-oneshot.c:32
32 dev->next_event = KTIME_MAX;
(gdb)
33 return 0;
(gdb)
remove_hrtimer (restart=<optimized out>, base=<optimized out>,
timer=<optimized out>)
    at ../kernel/time/hrtimer.c:1038
1038 return 1;
(gdb)
__hrtimer_start_range_ns (timer=0xffff888007a1e5c0, tim=1101350314, delta_ns=0,
    mode=<optimized out>, base=0xffff888007a1e0c0) at
../kernel/time/hrtimer.c:1093
1093 if (mode & HRTIMER_MODE_REL)
(gdb)
1098 hrtimer_set_expires_range_ns(timer, tim, delta_ns);
(gdb)
1101 new_base = switch_hrtimer_base(timer, base, mode & HRTIMER_MODE_PINNED);
(gdb)
334 return res;
(gdb)
1101 new_base = switch_hrtimer_base(timer, base, mode & HRTIMER_MODE_PINNED);
(gdb)
1103 return enqueue_hrtimer(timer, new_base, mode);
(gdb)
hrtimer_start_range_ns (timer=0xffff888007a1e5c0, tim=1101350314,
delta_ns=<optimized out>,
    mode=HRTIMER_MODE_ABS_PINNED_HARD) at ../kernel/time/hrtimer.c:1134
1134 hrtimer_reprogram(timer, true);
(gdb)
1136 unlock_hrtimer_base(timer, &flags);
(gdb)
898 raw_spin_unlock_irqrestore(&timer->base->cpu_base->lock, *flags);
(gdb)
__tick_nohz_idle_stop_tick (ts=<optimized out>) at
../kernel/time/tick-sched.c:978
978 if (!was_stopped && ts->tick_stopped) {
(gdb)
979 ts->idle_jiffies = ts->last_jiffies;
(gdb)
980 nohz_balance_enter_idle(cpu);
(gdb)
cpuidle_idle_call () at ../kernel/sched/idle.c:161
161 rcu_idle_enter();
(gdb)
163 default_idle_call();
(gdb)
164 goto exit_idle;
(gdb)

_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

Re: [PATCH 0/8] dyndbg: WIP diet plan

[Greg KH]

On Wed, Aug 05, 2020 at 12:30:15PM -0600, Jim Cromie wrote:
> dynamic-debug metadata is bloated; the __dyndbg linker section is
> effectively an array of struct _ddebugs, its 1st 3 members are highly
> repetetive, with 90%, 84%, 45% repeats.  Total reported usage ~150kb
> for ~2600 callsites on my laptop config.
> 
> This patchset is one diet plan. it all holds together nicely until the
> "cache" commit, when it blows up starting init (or right after freeing
> unused kernel image, which Im hoping to do...).  The following commit
> tweaks locking in an attempt to recover, but fails.

<snip>

Any reason this went to kernelnewbies, and not lkml so that other
developers could see it?

thanks,

greg k-h

_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

Re: [PATCH 0/8] dyndbg: WIP diet plan

[jim.cromie]

On Thu, Aug 6, 2020 at 4:40 AM Greg KH <greg@kroah.com> wrote:
>
> On Wed, Aug 05, 2020 at 12:30:15PM -0600, Jim Cromie wrote:
> > dynamic-debug metadata is bloated; the __dyndbg linker section is
> > effectively an array of struct _ddebugs, its 1st 3 members are highly
> > repetetive, with 90%, 84%, 45% repeats.  Total reported usage ~150kb
> > for ~2600 callsites on my laptop config.
> >
> > This patchset is one diet plan. it all holds together nicely until the
> > "cache" commit, when it blows up starting init (or right after freeing
> > unused kernel image, which Im hoping to do...).  The following commit
> > tweaks locking in an attempt to recover, but fails.
>
> <snip>
>
> Any reason this went to kernelnewbies, and not lkml so that other
> developers could see it?
>
> thanks,
>
> greg k-h


Mostly cuz its broken.
and I feel like I have dumb questions
I was hoping to repair the stupid errors before going to LKML
trade dumb questions for considered answers,
and hopefully reply with progress

But I'll take your question as advice.

_______________________________________________
Kernelnewbies mailing list
Kernelnewbies@kernelnewbies.org
https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies