Why is pr_debug of the Linux kernel not giving any output?

Question

I have a loadable kernel module and its init is as given below

static int __init id_init(void)
{
    struct identity *temp;

    /* some code which is not relevant to the question */

    temp = identity_find(3);
    pr_debug("id 3 = %s\n", temp->name);

    temp = identity_find(42);
    if (temp == NULL)
        pr_debug("id 42 not found\n");

    /* some code which is not relevant to the question */

    return 0;
}

Also I have enabled dynamic debugging enabled on the kernel version I am using - i.e CONFIG_DYNAMIC_DEBUG=y.

And in the Makefile of the module I have added a line CFLAGS_[id].o := -DDEBUG where id.c is the file name.

Now I checked in the /sys/kernel/debug/dynamic_debug/control after doing insmod of this module, in which I found the below lines

/home/pauldc/Programming/Kernel/id/id.c:69 [id]id_init =_ "id 42 not found\012"
/home/pauldc/Programming/Kernel/id/id.c:65 [id]id_init =_ "id 3 = %s\012"

Even after doing all this, to my disappointment I could not find the above two pr_debug statements in the output of dmesg. So what am I missing or doing wrong?

Answer 1

Add following to Makefile, assuming filename.c is the module source file.

CFLAGS_filename.o := -DDEBUG

not

CFLAGS_[filename].o := -DDEBUG

Refer https://www.kernel.org/doc/local/pr_debug.txt

Answer 2

CONFIG_DYNAMIC_DEBUG=y

https://www.kernel.org/doc/html/v4.11/admin-guide/dynamic-debug-howto.html

If you compile the kernel with this option, then you can do amazing things like:

echo 8 > /proc/sys/kernel/printk
echo 'file kernel/module.c +p' > /sys/kernel/debug/dynamic_debug/control

and this will selectively enable the pr_debug() you want.

We can then test this out with:

insmod mymodule.ko

which prints a lot of extra debug info as in:

[   84.875592] init_module: umod=0000000073518b66, len=185416, uargs=000000009c6e375a                    
[   84.876099] Core section allocation order:       
[   84.876257]  .text                               
[   84.876332]  .note.gnu.build-id                  
[   84.876418]  .rodata.str1.1                      
[   84.876492]  .orc_unwind_ip                      
[   84.876568]  .orc_unwind                         
[   84.876636]  __mcount_loc                        
[   84.876705]  .data                               
[   84.876760]  .gnu.linkonce.this_module           
[   84.876856]  .bss                                
[   84.876919] Init section allocation order:       
[   84.877041]  .symtab                             
[   84.877121]  .strtab                             
[   84.877235] final section addresses:             
[   84.877352]  0xffffffffc0006000 .note.gnu.build-id                                                    
[   84.877482]  0xffffffffc0005000 .text            
[   84.877580]  0xffffffffc0006024 .rodata.str1.1   
[   84.877695]  0xffffffffc0006040 .orc_unwind_ip   
[   84.877805]  0xffffffffc0006050 .orc_unwind      
[   84.877905]  0xffffffffc0006068 __mcount_loc     
[   84.878012]  0xffffffffc0007000 .data            
[   84.878107]  0xffffffffc0007000 .gnu.linkonce.this_module                                             
[   84.878238]  0xffffffffc0007340 .bss             
[   84.878331]  0xffffffffc000a000 .symtab          
[   84.878430]  0xffffffffc000a348 .strtab          
[   84.878657] Absolute symbol: 0x00000000          
[   84.878951] Absolute symbol: 0x00000000          
[   84.879713] hello init 

And in particular, it contains the module load address:

[   84.877482]  0xffffffffc0005000 .text            

which is useful to convert addresses to lines.

For modules, we can do:

echo 8 > /proc/sys/kernel/printk
echo 'module myprintk +p' > /sys/kernel/debug/dynamic_debug/control
insmod /myprintk.ko

which allows us to easily test pr_debug by adding that to our own module.

Tested on kernel 4.16 with this setup.

printk(KERN_DEBUG != pr_debug when CONFIG_DYNAMIC_DEBUG=y

This is very inconsistent, but printk(KERN_DEBUG does show up when loglevel=8 even if we don't enable /sys/kernel/debug/dynamic_debug/control, this can be seen from: https://stackoverflow.com/a/37283021/895245