lkml.org 
[lkml]   [2008]   [Jul]   [1]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [PATCH 0/8] dynamic debug
On Fri, 13 Jun 2008 14:57:33 -0400 Jason Baron <jbaron@redhat.com> wrote:

>
> hi Andrew,
>
> thanks for reviewing the last set of patches. In this iteration, I've
> attempted to simplify the interfaces, and provide a better explanation
> for the patches.
>
> PROBLEM
>
> 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.
>
> SOLUTION
>
> 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.
>
> I've introduced CONFIG_DYNAMIC_PRINTK_DEBUG, which when enabled centralizes
> control of debugging statements on a per-module basis in one /proc file,
> currently, <debugfs>/dynamic_printk/modules. When, CONFIG_DYNAMIC_PRINTK_DEBUG,
> is not set, debugging statements can still be enabled as before, often by
> defining 'DEBUG' for the proper compilation unit. Thus, this patch set has not
> affect when CONFIG_DYNAMIC_PRINTK_DEBUG is not set. The rest of the discussion
> deals with the case where CONFIG_DYNAMIC_PRINTK_DEBUG is set.
>
> INTERFACE - userspace
>
> The file <debugfs>/dynamic_printk/modules is formatted as:
>
> <module_name><enabled/disabled><debug type><level setting><flags><module names>

Six fields

> $cat /sys/kernel/debug/dynamic_printk/modules
>
> uhci_hcd 0 boolean 0

But only four fields here.

I assume the remaining two are optional?

If so, what happens if "flags" is empty and "module names" is
non-empty? That's unparseable.

> dock 0 boolean 0
> mount 0 boolean 0
> main 0 boolean 0
> driver 0 boolean 0
> cpufreq_shared 0 flag 0
> CPUFREQ_DEBUG_CORE CPUFREQ_DEBUG_DRIVER CPUFREQ_DEBUG_GOVERNOR
> acpi_cpufreq freq_table cpufreq_userspace cpufreq
>
> <module_name> : Name of the module in which the debug call resides
> <enabled/disabled> : whether the the messages are enabled or not
> <debug type> : types are 'boolean', 'flag', or 'level'. 'boolean' is
> is simply on/off. 'Flag' allows different flags to be turned on or
> off. 'Level' means that all messages above a certain level are
> enabled.
> <level setting> : This the current value if 'flag' or 'level' is set
> <flags> : names of the flags that can be set if 'flag' type is set
> <module names> : name of modules in the grouping.

How about:

> Enable a module:
>
> $echo "enable <module_name>" > dynamic_printk/modules

echo 1 > dynamic_printk/modules/module_name/enable
> Disable a module:
>
> $echo "disable <module_name>" > dynamic_printk/modules

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

echo # > dynamic_printk/modules/module_name/level
> Enable all modules:
>
> $echo "add all" > dynamic_printk/modules

remove this

> Disable all modules:
>
> $echo "remove all" > dynamic_printk/modules

remove this

?

> INTERFACE - kernel
>
> I've tried to make the kernel interface as simple as possible. 'pr_debug()' and
> 'dev_dbg()' calls remain exactly the same, however the kernel now
> automatically recognizes these calls, and creates entries in
> /sys/kernel/debug/dynamic_printk/modules.
>
> For more sophisticated types of debugging i've introduced 1 new interface:
>
> int dynamic_dbg_enabled(type, level, current_level);
>
> 'dynamic_dbg_enabled' returns true (1) or false (0), depending on the settings
> in /sys/kernel/debug/dynamic_printk/modules. This allows printks or even
> blocks of code to be conditionally executed via:
>
> if (dynamic_dbg_enabled() {
> <code block>;
> }

By what means is the module_name identified in dynamic_dbg_enabled()?
Implicitly THIS_MODULE?

If so, what happens if the "module" is linked into vmlinux? Or if
we're using this for, say, the CPU scheduler?

> There are 3 possible values for 'type':
>
> 'TYPE_BOOLEAN' : this simply means the dynamic_dbg_enabled() is toggled on/off
> 'TYPE_FLAG' : this allows the dynamic_dbg_enabled() to be associated with
> a set of flags and a 'call flag'. The 'call flag' is associated
> with a particular dynamic_dbg_enabled() call, and if the 'call
> flag' is set in the flag set it return true o.t. false.
> 'TYPE_LEVEL' : Associates dynamic_dbg_enabled() with global level and a specific
> level for the call site. If the (specific level) < (global level)
> returns true o.t. false.
>
> Its probably best explained with an example (taken from cpufreq.c):
>
> -#define dprintk(msg...) cpufreq_debug_printk(CPUFREQ_DEBUG_DRIVER, "gx-suspmod", msg)
> +#define dprintk(msg...) do { \
> + if (dynamic_dbg_enabled(TYPE_FLAG, CPUFREQ_DEBUG_DRIVER, cpufreq_debug)) \
> + cpufreq_debug_printk(CPUFREQ_DEBUG_DRIVER, "gx-suspmod", msg); \
> + } while (0)
>
> So, now instead of calling cpufreq_debug_printk directly, we've made it
> contingent on 'dynamic_dbg_enabled()' call. The 'cpufreq' driver uses 'TYPE_FLAG',
> which allows invidual bits of flags to control the debugging level for cpufreq
> driver. The use of dynamic_dbg_enabled() automatically creates an entry in the
> /sys/kernel/debug/dynamic_printk/modules file, as was the case for 'pr_debug()'
> and 'dev_dbg()'. 'CPUFREQ_DEBUG_DRIVER' specifies the flag bit that needs to be
> set in order for cpufreq_debug_printk() to return true.
>
> By default, each dynamic_dbg_enabled() call implicity, sets its module, and its
> debug type. However, modules can override these implicit types by including
> a few special #define. For, example for cpufreq, the #defines are:
>
> #undef DYNAMIC_DEBUG_NUM_FLAGS
> #define DYNAMIC_DEBUG_NUM_FLAGS "3"
>
> #undef DYNAMIC_DEBUG_FLAG_NAMES
> #define DYNAMIC_DEBUG_FLAG_NAMES "CPUFREQ_DEBUG_CORE,CPUFREQ_DEBUG_DRIVER,CPUFREQ_DEBUG_GOVERNOR"
>
> #undef DYNAMIC_DEBUG_TYPE
> #define DYNAMIC_DEBUG_TYPE "2"
>
> #undef DYNAMIC_DEBUG_MODNAME
> #define DYNAMIC_DEBUG_MODNAME "cpufreq_shared"
>
>
> 'DYNAMIC_DEBUG_NUM_FLAGS' : number of flags the module has
> 'DYNAMIC_DEBUG_FLAG_NAMES' : the names of these flags
> 'DYNAMIC_DEBUG_TYPE' : can be one of 'TYPE_BOOLEAN or 0', 'TYPE_LEVEL or 1', or
> 'TYPE_FLAG or 2'
> 'DYNAMIC_DEBUG_MODNAME' : overrides the default module name, for example to allow
> different compilation units to share the same flags.
>
>
> IMPLEMENTATION
>
> The set of modules that can be dynamically controlled via
> /sys/kernel/debug/dynamic_printk/modules are created on the fly during bootup.
> Meta-data is implicity associated with each 'pr_debug()', dev_dbg()' and
> 'dynamic_debug_enabled()' call site. This meta-data includes the module name
> and the debug type, (one of boolean, flag, or level). The meta-data is
> contained in a special "verbose" section of the kernel binary. So this section
> is essentially scanned during bootup or module load/unload, and an internal
> kernel hash data structure is created. The "verbose" section is then freed.
> Thus, although the text size increases with this compile option (~2% in my
> testing), the runtime size remains the same.
>
> The internal hash table that is created is a hash on the module name. The
> hash table has 32 buckets. Each bucket has a per-cpu 'int' type associated with
> it. This 'int' has bit 'n' set, if any module which hashes into the bucket row
> 'n' is enabled. Thus, when debugging is disabled we are testing a bit in a per-cpu
> integer. Only, if the bit is enabled do we make a function call. This function
> call checks to see if the level or flags are appropriately set and that the module
> is enabled before outputing the printk (in the case of pr_debug() or dev_dbg()), or
> returning true or false, in the case of 'dynamic_debug_enabled()'.
>
> TODO
>
> -allow modules to be set by using flag names
> -fix up parsing in /proc file
> -possibly move control file out of debugfs
> -convert more modules to the infrastructure

Looks promising, thanks. I haven't looked at the implementation yet.
And I probably won't, this time around :( Still recovering from the
week off.



\
 
 \ /
  Last update: 2008-07-01 07:13    [from the cache]
©2003-2011 Jasper Spaans