[PATCH 0/8] dyndbg: WIP diet plan
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
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
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
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
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
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
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
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
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
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)
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
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.
participants (3)
-
Greg KH -
Jim Cromie -
jim.cromie＠gmail.com