Introduction
Previously, we discussed
Linux Kernel Debugging: The Powerful printk (Part 2)
Linux Kernel Debugging: The Powerful printk (Part 3)
In those articles, we introduced pr_debug and dev_dbg. Below is the definition of dev_dbg:
#if defined(CONFIG_DYNAMIC_DEBUG) || \
(defined(CONFIG_DYNAMIC_DEBUG_CORE) && defined(DYNAMIC_DEBUG_MODULE))
#define dev_dbg(dev, fmt, ...) \
dynamic_dev_dbg(dev, dev_fmt(fmt), ##__VA_ARGS__)
#elif defined(DEBUG)
#define dev_dbg(dev, fmt, ...) \
dev_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__)
#else
#define dev_dbg(dev, fmt, ...) \
dev_no_printk(KERN_DEBUG, dev, dev_fmt(fmt), ##__VA_ARGS__)
#endif
As we can see, when CONFIG_DYNAMIC_DEBUG is defined or when CONFIG_DYNAMIC_DEBUG_CORE and DYNAMIC_DEBUG_MODULE are defined, it corresponds to dynamic printing. In this article, we will explore dynamic printing in the Linux Kernel.
Dynamic Debug in the Linux Kernel
Features
The dynamic debugging feature of the Linux kernel is a very powerful built-in tool with the following characteristics:
-
It allows enabling and disabling debug messages at runtime without recompiling the kernel or rebooting the system, which is crucial for diagnosing issues in production environments.
-
It can enable debug messages for specific parts of the kernel or even individual modules, allowing focus on relevant information.
-
It monitors and optimizes kernel performance by selectively enabling or disabling debug messages based on current analysis needs.
Enabling Dynamic Debugging
-
From the definition in the kernel code, we can see that to enable dynamic debugging, the
<span><span>CONFIG_DYNAMIC_DEBUG</span></span>configuration option must be enabled during kernel compilation, so that the kernel supports dynamic debugging. However, this will increase the size of the compiled kernel file, which may not be feasible on resource-constrained embedded platforms. In that case, enable the<span><span>CONFIG_DYNAMIC_DEBUG_CORE</span></span>configuration option and define<span><span>DYNAMIC_DEBUG_MODULE</span></span>during driver compilation to still allow dynamic debugging of the driver. -
Additionally, after the system starts, the debugfs filesystem needs to be manually mounted with the following command:
sudo mount -t debugfs none /sys/kernel/debug
To mount debugfs, the <span><span>CONFIG_DEBUG_FS</span></span> option must be enabled, along with <span><span>CONFIG_DEBUG_FS_ALLOW_ALL=y</span></span>
<span><span>CONFIG_DEBUG_FS_DISALLOW_MOUNT=n</span></span>. If
<span><span>CONFIG_DEBUG_FS_DISALLOW_MOUNT=y</span></span> or <span><span>CONFIG_DEBUG_FS_ALLOW_NONE=y</span></span>, then the control file is located at <span><span>/proc/dynamic_debug/control</span></span>
In our previous section on compiling the debug kernel, we configured <span><span>CONFIG_DEBUG_FS=y</span></span> and <span><span>CONFIG_DEBUG_FS_ALLOW_ALL=y</span></span>
<span><span>CONFIG_DEBUG_FS_DISALLOW_MOUNT=n</span></span>, so the control file is located at <span><span>/sys/kernel/debug/dynamic_debug/control</span></span>
<span>Subsequent introductions will also be based on </span><code><span><span>/sys/kernel/debug/dynamic_debug/control</span> for configuration.</span>
Once mounted, you can configure dynamic debugging through this file.
Viewing Dynamic Debugging Behavior
You can check the current dynamic debugging configuration by viewing the <span><span>/sys/kernel/debug/dynamic_debug/control</span></span> file. Note that root privileges are required to view it:
sudo vim /sys/kernel/debug/dynamic_debug/control
This file contains entries for all instances of the <span>pr_debug()</span> or <span>dev_dbg()</span> debug macros in the kernel, formatted as follows:
filename:lineno [module]function flags format
Where filename is the file name, lineno is the line number, [module] is the module name, function is the function name, flags indicate the dynamic debug flags that control the output behavior of log messages, and format is the formatted output.
The flags can be a combination of the following:
-
<span>_</span>: Disable debug information. -
<span>p</span>: Enable debug information (print). -
<span>f</span>: Show function name in output. -
<span>l</span>: Show line number in output. -
<span>m</span>: Show module name in output. -
<span>t</span>: Include thread ID in output. This flag will include the thread ID in debug information but is not applicable in interrupt context.
Additionally, the following flags can be used:
-
+: Add specified flags, for example:
echo 'file example.c +plf' > /sys/kernel/debug/dynamic_debug/controlThis will enable printing in example.c, along with line numbers and function names.
-
-: Remove specified flags.
-
=: Set to specified flags.
Dynamic Control of Debug Information
Now that we know the format of the <span><span>/sys/kernel/debug/dynamic_debug/control</span></span> file, how do we operate this file to dynamically enable or disable debug information output? It’s simple; we just need to use the echo command to write a specific string to this file, and the kernel will process this specific string. However, it should be noted that to write content to this file using echo, root privileges are required. The command syntax is roughly as follows:
echo <match-spec* flags=""> > /sys/kernel/debug/dynamic_debug/control
</match-spec*>Or
echo <match-spec* flags=""> > /proc/dynamic_debug/control
</match-spec*>Where
match-spec ::= 'func' string | 'file' string | 'module' string | 'format' string | 'class' string | 'line' line-range line-range ::= lineno | '-'lineno | lineno'-' | lineno'-'lineno lineno ::= unsigned-int
Where func, file, module, format, class, and the following string correspond to their respective names, and line can be followed by a range of line numbers.
Thus, for
func run_init_process +p
file init/main.c +pl
module usbhid +pl
fmtfile init/main.c line 1150-1389 +pf
For instance, let’s check the first few lines of the <span>/sys/kernel/debug/dynamic_debug/control</span> file:
$ sudo passwd // Set root password
New password: Retype new password: passwd: password updated successfully
$ suPassword: // Enter the password just set
# head -n 10 /sys/kernel/debug/dynamic_debug/control
# filename:lineno [module]function flags format
init/main.c:1150 [main]initcall_blacklist =p "blacklisting initcall %s\n"
init/main.c:1189 [main]initcall_blacklisted =p "initcall %s blacklisted\n"
init/main.c:1384 [main]run_init_process =p " with arguments:\n"
init/main.c:1386 [main]run_init_process =p " %s\n"
init/main.c:1387 [main]run_init_process =p " with environment:\n"
init/main.c:1389 [main]run_init_process =p " %s\n"
init/initramfs.c:534 [initramfs]unpack_to_rootfs =_ "Detected %s compressed data\n"
arch/x86/events/amd/ibs.c:1370 [ibs]setup_ibs_ctl =_ "Failed to setup IBS LVT offset, IBSCTL = 0x%08x\n"
arch/x86/events/amd/ibs.c:1377 [ibs]setup_ibs_ctl =_ "No CPU node configured for IBS\n"
Now, let’s execute the echo command:
# echo "file init/main.c -p" > /sys/kernel/debug/dynamic_debug/control
Then check the first few lines of the <span>/sys/kernel/debug/dynamic_debug/control</span> file again:
# head -n 10 /sys/kernel/debug/dynamic_debug/control
# filename:lineno [module]function flags format
init/main.c:1150 [main]initcall_blacklist =_ "blacklisting initcall %s\n"
init/main.c:1189 [main]initcall_blacklisted =_ "initcall %s blacklisted\n"
init/main.c:1384 [main]run_init_process =_ " with arguments:\n"
init/main.c:1386 [main]run_init_process =_ " %s\n"
init/main.c:1387 [main]run_init_process =_ " with environment:\n"
init/main.c:1389 [main]run_init_process =_ " %s\n"
init/initramfs.c:534 [initramfs]unpack_to_rootfs =_ "Detected %s compressed data\n"
arch/x86/events/amd/ibs.c:1370 [ibs]setup_ibs_ctl =_ "Failed to setup IBS LVT offset, IBSCTL = 0x%08x\n"
arch/x86/events/amd/ibs.c:1377 [ibs]setup_ibs_ctl =_ "No CPU node configured for IBS\n"
As we can see, the flags for the lines in init/main.c have changed from =p to =_, meaning the printing in init/main.c has been turned off.
Through this small experiment, we have learned how to operate the <span>/sys/kernel/debug/dynamic_debug/control</span> file to dynamically enable or adjust output information. Later, we will write a kernel module for practical application.
Implementation Principle
In simple terms, when dynamic configuration is enabled, the kernel records all dynamic debugging usage information during the compilation phase, including file path, module name, function, output line number, and the print statements to be output. This information can be queried through the <span><span>/sys/kernel/debug/dynamic_debug/control</span></span> file node, and specific fields can be configured to select the information to be printed.
Taking the <span>dev_dbg</span> interface as an example, its implementation is as follows:
When dynamic debugging is configured, <span>dev_dbg</span> will call the <span>dynamic_dev_dbg</span> interface to control the output of prints. The <span>dynamic_dev_dbg</span> interface will ultimately determine whether to output based on the settings of the <span>descriptor</span>‘s flag <span>_DPRINTK_FLAGS_PRINT</span>.
For specific implementation details, please refer to the source code!
Dynamic Debugging in Practice
Now, let’s modify the virtual device driver from Linux Kernel Debugging: The Powerful printk (Part 3) to demonstrate the use of dynamic debugging when debugging device drivers. To limit the length, only the modified code snippets are provided. For the complete code, please download it here: https://gitee.com/coolloser/linux-kerenl-debug/tree/master/005_dynamic_debug. The modifications are as follows:
[...]
static int vdev_open(struct inode *inode, struct file *file){ [...] dev_dbg(data->dev, "Device opened\n"); return 0;}
static int vdev_release(struct inode *inode, struct file *file){ [...] dev_dbg(vdev_device, "Device closed\n"); return 0;}
static ssize_t vdev_read(struct file *file, char __user *buf, size_t count, loff_t *pos){ [...] dev_dbg(data->dev, "Read %zu bytes\n", data->size); return data->size;}
static ssize_t vdev_read(struct file *file, char __user *buf, size_t count, loff_t *pos){ [...] dev_dbg(data->dev, "Read %zu bytes\n", data->size); return data->size;}
// Writing to device
static ssize_t vdev_write(struct file *file, const char __user *buf, size_t count, loff_t *pos){ [...] dev_dbg(data->dev, "Received %zu bytes\n", count); return count;}
[...]Correspondingly, the Makefile also needs to be modified as follows:
[...]
ccflags-y += -UDEBUG -DDYNAMIC_DEBUG_MODULE
[...]After completing the modifications, execute make to compile. Before loading the driver, we first use the following command to check if our driver content is present in the <span>/sys/kernel/debug/dynamic_debug/control</span> file:
# grep dyn_debug /sys/kernel/debug/dynamic_debug/control
#As we can see, there is currently no content for our driver.
After loading the driver, execute it again:
# insmod dyn_debug.ko
# grep dyn_debug /sys/kernel/debug/dynamic_debug/control
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:45 [dyn_debug]vdev_open =_ "Device opened\n"
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:59 [dyn_debug]vdev_release =_ "Device closed\n"
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:76 [dyn_debug]vdev_read =_ "Read %zu bytes\n"
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:96 [dyn_debug]vdev_write =_ "Received %zu bytes\n"
Now we can see that the information for our driver is present, and all these prints are currently disabled.
Execute the following command to check if there are any prints:
mknod /dev/vdev c 240 0
chmod 666 /dev/vdev
echo "test" > /dev/vdev
dmesg
As we can see, in addition to the dev_info information being printed, dev_dbg has not printed anything.
Now, let’s modify the <span>/sys/kernel/debug/dynamic_debug/control</span> to enable printing:
# echo "module dyn_debug +pmflt" > /sys/kernel/debug/dynamic_debug/control
# grep dyn_debug /sys/kernel/debug/dynamic_debug/control
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:45 [dyn_debug]vdev_open =pmflt "Device opened\n"
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:59 [dyn_debug]vdev_release =pmflt "Device closed\n"
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:76 [dyn_debug]vdev_read =pmflt "Read %zu bytes\n"
/home/leo/linux-kerenl-debug/005_dynamic_debug/dyn_debug.c:96 [dyn_debug]vdev_write =pmflt "Received %zu bytes\n"
Now we can see that the flags for the dyn_debug module have changed to =pmflt.
Next, execute the following command:
echo "test" > /dev/vdev
dmesg
At this point, the dev_dbg information has been printed, and the output is prefixed with:
[process ID] module name:function name:line number
If you need to turn off printing, execute the following command again:
# echo "module dyn_debug -pmflt" > /sys/kernel/debug/dynamic_debug/control
Now we can dynamically turn on or off debug information at runtime without recompiling.
Conclusion
Dynamic debugging is powerful and convenient. When not enabled, it has minimal impact on performance, but enabling printing does have an impact, so the granularity of printing needs to be carefully managed. Additionally, enabling <span><span>CONFIG_DYNAMIC_DEBUG</span></span> will increase the kernel code size by about 2% because each debug statement will attach metadata to record debugging information.
It is worth mentioning that no matter how much we introduce here, it is impossible to cover everything. There are many usages of log output in the kernel that require continuous exploration and discovery in practical applications. Also, hands-on practice is essential; seeing it a thousand times is not as good as debugging it once!
References
Kernel Documentation: Documentation/admin-guide/dynamic-debug-howto.rst