dynamic debug - core infrastructure

This is the core patch that implements a new dynamic debug infrastructure.

+int dynamic_printk_enabled[NR_CPUS];

Quoted 2 lines · Jason Baron

This is the core patch that implements a new dynamic debug infrastructure.

Some general and specific comments.

Quoted 1 line

+int dynamic_printk_enabled[NR_CPUS];

I don't understand why you use NR_CPUS.

Also, I think the major use cases are 1 or 2 modules enabled, no modules enabled, or all modules enabled, so the hashing of module names is particularly not useful.

Any pr_debug or dev_dbg is in a slow path.

I think a list and a direct comparison to KBUILD_MODNAME would be simpler and as fast as necessary.

lib/Kconfig.debug config FIREWIRE_OHCI_REMOTE_DMA · line 690

Quoted 4 lines

lib/Kconfig.debug +4 -0

+         To set the level or flag value for type 'level' or 'flag': 
+
+               $echo "set level=<#> <module_name>" > dynamic_printk/modules
+

I think that set level=<#> should also work for "all"

Perhaps a simpler interface would be to use
enable <module> <level>
where <level> not specified is 0.

lib/dynamic_printk.c line 138

Quoted 13 lines

lib/dynamic_printk.c new file +13 -0

+int unregister_debug_module(char *mod_name)
+{
+	struct debug_name *element;
+	struct debug_name *parent = NULL;
+	int ret = 0;
+	int i;
+
+	down(&debug_list_mutex);
+	element = find_debug_module(mod_name);
+	if (!element) {
+		ret = -EINVAL;
+		goto out;
+	}

[]

lib/dynamic_printk.c line 170

Quoted 4 lines

lib/dynamic_printk.c new file +4 -0

+out:
+	up(&debug_list_mutex);
+	return 0;
+}

Because the return values aren't used,
the functions might as well be declared void

You should probably add a sprinkling of "const"
to the argument lists.

include/linux/kernel.h +3 -0

+extern void dynamic_printk(char *, char *, ...);
 
+	dynamic_printk(KBUILD_MODNAME,                     \
+			KERN_DEBUG KBUILD_MODNAME ": " fmt,\

Instead of prefixing every fmt with KBUILD_MODNAME ": ", why not change this to something like:

extern void dynamic_printk(const char *level, const char *module,

			   const char *fmt, ...);

and just do the printk in 2 parts?

	if (module_enabled) {
		printk("%s%s: ", level, module);
		vprintk(fmt, args);
	}

If not that, why should dynamic_printk prefix a KBUILD_MODNAME at all? Why not just check if the module is enabled, then output what the code specifies?

trivial: The dynamic versions of the dev_dbg and pr_debug macros don't return the number of chars output, but always return 0.

include/linux/device.h +0 -0

@@ -595,6 +595,22 @@ extern const char *dev_driver_string(struct device *dev);
 #ifdef DEBUG
 #define dev_dbg(dev, format, arg...)		\

include/linux/kernel.h +1 -0

@@ -14,6 +14,7 @@
 #include <linux/compiler.h>
 #include <linux/bitops.h>
 #include <linux/log2.h>
+#include <linux/dynamic_printk.h>
 #include <asm/byteorder.h>
 #include <asm/bug.h>
 

Quoted 10 lines · Jason Baron

include/linux/device.h +4 -0

@@ -595,6 +595,22 @@ extern const char *dev_driver_string(struct device *dev);
 #ifdef DEBUG
 #define dev_dbg(dev, format, arg...)		\
 	dev_printk(KERN_DEBUG , dev , format , ## arg)
+#elif defined(CONFIG_DYNAMIC_PRINTK_DEBUG)
+#define dev_dbg(dev, format, ...) do {				    	     \
+	static char mod_name[]						     \
+	__attribute__((section("__verbose_strings")))			     \

include/linux/device.h extern const char *dev_driver_string(struct device *dev); · line 606

Quoted 5 lines

include/linux/device.h +5 -0

+	 = KBUILD_MODNAME;						     \
+	static struct mod_debug foobar					     \
+	__used								     \
+	__attribute__((section("__verbose"), aligned(8))) =		     \
+	{ mod_name, mod_name, "0", "0", NULL };				     \

Does the compiler merge all of these variables together into one within the same file?

If not, should we have a new macro, one per file, for this information?

Quoted 11 lines · Greg KH

Quoted 10 lines · Jason Baron

include/linux/device.h +4 -0

@@ -595,6 +595,22 @@ extern const char *dev_driver_string(struct device *dev);
 #ifdef DEBUG
 #define dev_dbg(dev, format, arg...)		\
 	dev_printk(KERN_DEBUG , dev , format , ## arg)
+#elif defined(CONFIG_DYNAMIC_PRINTK_DEBUG)
+#define dev_dbg(dev, format, ...) do {				    	     \
+	static char mod_name[]						     \
+	__attribute__((section("__verbose_strings")))			     \

Quoted 9 lines

include/linux/device.h extern const char *dev_driver_string(struct device *dev); · line 606

Quoted 5 lines

include/linux/device.h +5 -0

+	 = KBUILD_MODNAME;						     \
+	static struct mod_debug foobar					     \
+	__used								     \
+	__attribute__((section("__verbose"), aligned(8))) =		     \
+	{ mod_name, mod_name, "0", "0", NULL };				     \

Does the compiler merge all of these variables together into one within the same file?

no.

Quoted 2 lines

If not, should we have a new macro, one per file, for this information?

With this feature enabled, the above 'meta-data' added ~32K to the .init.data section. This memory is freed when the system boots because it is placed in the .init.data section. The same is true for modules, the 'meta-data' is freed when the module loads.

We could reduce the vmlinux by having 'register()' type calls for this infrastructure, or a new marco per file as you suggest, and i had something like that in an earlier iteration, but I think the memory savings is very small when compared to the increased complexity. The simplicity to just put a 'pr_debug()" anywhere and just have it do the right thing is nice.

Also, it should be noted that the total increase in the size of the 'vmlinux' was 3%, or 2M, this is due to the above 'meta-data', the new code, and probably most significantly, the strings, for the additinal printks. Thus, compressing the above meta-data, or eliminating it by some other means would only decrease the size of this infrastructure by 2% or so.

This is the core patch that implements a new dynamic debug infrastructure.

Each kernel sub-system seems to have its own way of dealing with debugging statements. Some of these methods include 'dprintk', 'pr_debug', 'dev_debug', 'DEBUGP'. There are also a myriad of ways of enabling these statements. Some require CONFIG_ parameters to be set, some provide /proc interfaces, while others require 'DEBUG' to be set in header files. Most of these methods also require kernel re-compiles in order to set the appropriate knobs.

I've attempted to standardize how how the kernel deals with debugging statements, both from the user as well as the kernel perspective. Why aren't these debug statements made into printk(KERN_DEBUG), and be done with it? The problem here is that 'dprintk', 'pr_debug', etc. were introduced b/c they are often provide too verbose a level of output, could potentially adversly affect system performance if they were always enabled, and they clutter up the system logs.