Beginner Linux Kernel Logging: Mastering pr_ & dev_ Macros

Every programmer from beginner to pro knows how to output some debug prints (well at least I hope you do! otherwise debugging would be even more of an hell than it already is😉😂), but what if you’re developing (your first) drivers (kernel Modules)?

Yup, then a simple:

printf("Code reached!, sensor value here: %d", MySensorValue);

Would not suffice! You would need to be able to log somewhere else, so what do you do then? to a debug.log? Possible, messy, but possible😂. But what if you need to log normal events and such for your driver? Then it’s just not possible to expect the users of your driver to actually dig through all kinds of directories hoping to find the log-file of your particular driver.

And that is where Linux Kernel Logging comes to the rescue 😊. In this article I’m going to explain you how to log to the Linux kernel, which log levels there are, and how to use them (and when not to use them).

IMPORTANT NOTE: Using this ‘log system’ is NOT intended for normal user-space software like terminal applications, desktop applications, games or even ‘headless server applications’. For these applications you should just use a normal logging solution like logging to a .log file in the application directory.

Just to be clear:
This tutorial is aimed at Linux while programming in C, this is however not a complete tutorial on how to make your own device driver, but this just covers the use of pr_ and dev_ logging! I’m currently working on a device driver for Linux, which gave me the idea for this blog-post/tutorial, which I will link-to later when it’s done if you want a fully working example😊.

What is kernel logging?

I will keep this section as short as possible so we get to the ‘core of business’ (pun intended) as fast as possible. Kernel logging is the system the Linux kernel provides for drivers and other kernel code to output messages about their operation. This system has several different ‘log levels’ which we will get into shortly. To view the this log you can for example in your terminal type sudo dmesg :

In the example above you can see the 11 lines from my dmesg after I connected an Xbox Classic controller to my USB. And that? That is the same ‘logging system’ you should use when you’re developing your own driver.

Note: Kernel logs are also accessible via journald (systemd’s logging) or syslog, but dmesg is the simplest for direct kernel output.

pr_macros? dev_macros? logging? printk()?, what😳?

Yeah, it might sound a bit confusing at first, especially because I also just introduced printk in the header here… But even while I’m not going to dive too deeply into it, printk() is key here because pr_ and dev_ macros are essentially macros that use printk() under the hood.

But what is printk? Well I assume most of you by now (otherwise you would most likely not be reading this about driver development 😉) are far enough to know printf(). Well printk is basically it’s ‘bigger brother’, except that printk() prints it’s output to the kernel log buffer.

You don’t have to worry about properly learning how to use printk though, because that’s what the pr_* and dev_ macro families are for, those macro’s already use and ‘pre-setup’ printk() usage correctly for you😊.

You could then for example use when your module itself has loaded, and thus at module specific level NOT device level:

pr_info("My Controller Driver Loaded\n");

Or for a device level event (like a disconnect for example):

static void MyController_usb_disconnect(struct usb_interface *intf)
{
    dev_info(&intf->dev, "MyController device disconnected\n");
    // Rest of cleanup etc...
}

To use these two (pr_ and dev_) you would need to include the following two headers into your project:

#include <linux/kernel.h> // Used for the pr_ macros, this also brings in printk.h automatically in which the pr_ macros are defined
#include <linux/device.h> // Used for the dev_ macros

NOTE: I’m assuming you’ve already installed the Linux kernel headers so that you can actually compile driver modules. If not then I would recommend to Google how to install them for your kernel, most commonly used methods are:
Debian/Ubuntu based system:
sudo apt update
sudo apt install linux-headers-$(uname -r)

Fedora/RHEL: sudo dnf install kernel-devel
Arch: sudo pacman -S linux-headers

What do pr_ and dev_ stand for?

Well pr_ isn’t an official acronym and could be considered to just stand for print. dev_ is a bit more obvious though, and stands for device.

When to use pr_ or dev_?

Well there is a clear difference when you should use pr_ or dev_!
pr_ macros should be used for General kernel/module logging which is not tied to a specific (hardware) device. So these could still be messages from your driver like reporting the driver has loaded, but they should NOT be errors about a specific hardware device it’s trying to manage!

And that basically already gave away a bit when you should use dev_, and that is when a message, error etc needs to be reported about a specific (hardware) device which your driver is managing. I’m not going too deeply into this for now, but you will understand in the next sections why this is 😊

The Different pr_macros (and when to use them or not)

You might have already noticed that I used pr_info(…) in the example above, but that’s not the only one you can use, there are more ‘pr_ log macros’, and you should actually follow very specific rules to when to use which one. These are basically the ‘error levels’ which indicate the severity/seriousness for the events logged.

IMPORTANT: It is extremely important that you follow the correct guidelines when using pr_ or dev_ when logging! Otherwise you can basically make the log files and/or log filtering system of systems using your driver(s) a cluster-F*** with incorrectly logged ‘errors’!

It might sound a bit harsh how I phrased it above, but honestly it’s a serious matter! Incorrectly presenting critical log errors could for example trigger warning messages on users systems, servers etc. And if you are “caught using such error logging styles”, then chances are very realistic that people will call you out on it and possibly even avoid using your code/drivers like the plague.

I’ve created two tables of pr_ macros which I would recommend to use (when needed of course!) and which one I recommend not to use. The first table contains the ones which I recommend most (beginning) developers to use for regular driver development.

Macro	Log Level	Log Level NR	Purpose & Examples
pr_err	KERN_ERR	3	Errors where something failed (sysadmin’s attention likely required, module-level failures) pr_err(“Failed to register USB driver, error %d”, ret); pr_err(“Failed to allocate memory for module data”);
pr_warn	KERN_WARN	4	Warnings for potential problems or misconfiguration (module-level cautions) pr_warn(“Driver compiled for kernel newer kernel (6.15.x), some features may not work!”); pr_warn(“Module reached max controllers (%d), some devices may not work”, MAX_CONTROLLERS);
pr_notice	KERN_NOTICE	5	Normal but notable events pr_notice(“Starting enumeration of USB input devices”); pr_notice(“Driver configuration updated via module parameter”);
pr_info	KERN_INFO	6	Routine informational message (NOT device-specific) pr_info(“MyController Driver loaded, version 1.0”); pr_info(“Allocated memory for %d controllers”, MAX_CONTROLLERS);
pr_debug	KERN_DEBUG	7	Debugging output ‘to dmesg’ during Development (verbose trace of function calls, variable values, loop iteration states)

The following table however, contains pr_ log levels which I in general recommend not to use for generic device drivers.

Macro	Log Level	Log Level NR	Purpose & Examples
pr_emerg	KERN_EMERG	0	System Unusable (example: Kernel panic (‘bsod’) triggered, CPU Halt, critical memory corruption etc)
pr_alert	KERN_ALERT	1	Immediate Attention Required! (example: (file)system corruption, RAID failures etc)
pr_crit	KERN_CRIT	2	Critical Conditions (Example: Disk I/O Failures, hardware fails to initialize (repeatedly))

In my personal opinion (and I think most devs can agree with me here), most drivers/programmers should NOT touch level 0, 1 and 2 (pr_emerg, pr_alert and pr_crit) period. Those are in my book reserved for deep system errors from the kernel or system critical drivers like for example low-level GPU driver, storage controller drivers etc. But if you’re developing that kind of stuff, then you most likely won’t need this blog-post either😉, so for most/everyone reading this: Just don’t log to those three levels.

But WHEN to use pr_notice and when to use pr_info?

It can be a bit hard for beginners to determine where to put their ‘Driver loaded OK‘ messages and/or for example Controller Connected messages, and if they should be info or notice.

pr_info is to put it bluntly: basically information “no-one cares about when everything is working“, like the examples shown in the table above.

pr_notice are things which you or sysadmins might care about (important enough to have their own category because they could have an
effect to/on the system, but not important enough to be called away from your coffee break 😉).

pr_debug, when and how to use

In 95% of the cases when writing regular software I would recommend people to just use temporary printf debug outputs to the terminal, or to integrate something like this in your program:

#define DebugMode 1 // <- At the top of your code

void SomeMajorlyImportantFunction(){
   // Lots of super important stuff to do....

   if(DebugMode){ printf("Code Section Reached\n"); }

   // More world changing important stuff to do...
}

HOWEVER! If you’re developing driver (kernel modules), it is often not so simple to do this, you could then still resort to making a mini logger which logs/printf to a .log file while testing, but you could also use pr_debug to achieve the same.

It is however extremely important to disable (or even remove) the pr_debug events in the final release to prevent ‘massively spamming’ the log files of your users! An important side note here though: NEVER use pr_debug for ‘user-space‘ programs (terminal programs, games, desktop applications etc), that is just absolute overkill and unnecessary!

Using and enabling pr_debug

The cool part about pr_debug is that you can automatically disable it upon release (or to be more precise: you actually need to manually enable it). Because if DEBUG isn’t defined in your code, then for example pr_debug(“Code Section Reached\n”); won’t do anything because it isn’t even compiled into the code*. To use pr_debug you would do something like this:

#define DEBUG // <- At the top of your code

void SomeMajorlyImportantFunction(){
   // Lots of super important stuff to do....

   pr_debug("Code Section Reached\n");

   // More world changing important stuff to do...
}

* Nitpick: Unless CONFIG_DYNAMIC_DEBUG is enabled, then it IS still compiled into the code, but that’s a whole different story which doesn’t matter for now 😉.

Properly (automatically) prefixing your pr_macros

Of course it is very important that you make it clear in the log files from which driver an error came, nobody likes an error in a 10.000 lines log like: “Critical driver failure, driver failed to load!” without having ANY clue about what it could have been.

To prevent this you could for example use it like this (the manual method):

pr_err("MyControllerDriver: Critical driver failure, driver failed to load!");

or even a bit more automated:

#define DefInternalName     "MyControllerDriver" // <- At the top of your code 
pr_err("%s: Critical driver failure, driver failed to load!", DefInternalName); // <- The error elsewhere in your driver/code

Important nitpick here:
I’m using upper and lowercase in my (internal) drivername example here, but usually you should not do this! The internal naming convention of driver modules states that the names should be short, descriptive only use a-z in lowercase only, digits 0-9 and underscore (_). Don’t use special characters, spaces etc.

But there is a much better even more automated method of prefixing all the pr_macros for your driver:

#define DefInternalName     "MyControllerDriver" // <- At the top of your code 
#define pr_fmt(fmt) DefInternalName ": " fmt     // <- ABOVE the header includes, below your internal name definition/macro

// THEN the headers:
#include <linux/kernel.h>
#include <linux/device.h>

// Then somewhere in your code (where needed of course):
pr_info("Version 1.0.1 loaded");
pr_notice("Starting USB Enumeration");
pr_err("Critical driver failure, driver failed to load!");

This will automatically result in the following log outputs automatically:
MyControllerDriver: Version 1.0.1 loaded
MyControllerDriver: Starting USB Enumeration
MyControllerDriver: Critical driver failure, driver failed to load!

No matter which pr_macro you’ve used, it will now automatically prefix the prefix you’ve given it at the top.
Extra emphasis: It is very important that you place the pr_fmt macro (the #define pr_fmt part) ABOVE the header includes!

But what about device specific errors and messages?

Yes, that’s where many beginning driver developers ‘mess-up’, and while it is not a very big deal (since it’s still being logged), it does have a big significant impact if you use the wrong ‘logging system’ for device specific messages. Which means you have to pick when to use pr_ and dev_ appropiately. The main difference with dev_ is that it will include ‘automatic’ device context (which device it is exactly about).

I already briefly explained in the beginning that pr_ is for generic module/driver logging, and that dev_ is for device specific logging, but what does this exactly mean in laymen terms? I will explain this with a company-workers analogy where company messages are in bold, and worker messages are italicized:

Company: Turning on lights
Company: Letting in workers
Worker-1a: Entered building via front door
Worker-2b: Entered building via loading bay
Company: Turning on lights
Worker-2b: Hey! One of the lights isn't working!
Worker-1a: Everything A-Okay here, nice day at work
Company: Ready to receive customers

While that might look a bit like a childish example, it should immediately give you some clues on why we need devices to report their own errors & messages. If you would not have had the workers ‘automatically report’ which worker it was about, then you would have had one unknown worker report that everything is fine, and the other worker that there is something broken (a lamp in this example). But would you have even known where to start looking? Nope, but now you do know you have to look in the loading bay for a broken light😉.

And that is exactly why you would need to use dev_macros for messages and errors directly related (or caused by) a device.

A small additional example of pr_ vs dev_ for extra clarification:
pr_ for: pr_err(“Module init failed”);
dev_ for: dev_err(&intf->dev, “Device failed to initialize”);

How do you use dev_macros then?

For dev_macros you will need to include the device header (linux/device.h) and then you can use it in combination with pr_macros as shown in the example below:

#define DefInternalName     "MyControllerDriver" // <- At the top of your code 
#define pr_fmt(fmt) DefInternalName ": " fmt     // <- ABOVE the header includes, below your internal name definition/macro

// THEN the headers:
#include <linux/kernel.h>
#include <linux/device.h>

// Then somewhere in your code (where needed of course):
pr_info("Version 1.0.1 loaded");


// further on in your code when your USB device disconnects
static void MyControllerDriver_usb_disconnect(struct usb_interface *intf){
    dev_info(&intf->dev, "Device disconnected\n");
    // rest of cleanup on disconnect
}

Note that I didn’t added a prefix to the “Device disconnected” messages! And you might think: “No of course not! because you already included the pr_fmt macro!“. But no! thats not the case, because dev_macros don’t make use of the pr_fmt macro at all. The prefix of these macro’s is “partially” automatic. if you look at this line:

dev_info(&intf->dev, "Device disconnected\n");

Then you’ll notice that the bold &intf->dev points to an device (you adding this is the “partially” part of automatic, because you still have to point it to that device of course). But after doing that, the dev_macro will actually include the actual current device path of the device in the log like you might have seen in my screenshot above like this:
[36165.091121] usb 1-11.3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[36165.095735] hub 1-11.3:1.0: USB hub found
[36165.095899] hub 1-11.3:1.0: 3 ports detected
[36165.377293] usb 1-11.3.1: new full-speed USB device number 70 using xhci_hcd
[36165.462617] usb 1-11.3.1: New USB device found, idVendor=045e, idProduct=0202, bcdDevice= 1.00
[36165.462628] usb 1-11.3.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0

Those usb 1-1…. are the actual device paths reported by the dev_macro, and actually identify the device which is ‘causing’ the messages. This is not only important to know which device it is on your computer when you have multiple (of the same) devices connected, but also to find out where it is connected to your computer (which path).

I don’t want to make it all too technical, but I think this explains quite well why it is so important to use dev_ for device specific messages instead of just wildly tossing around pr_macros like you’re some upset PR Department 😉.

But those log lines don’t show it’s my driver!?
Yes you are correct they don’t (and should not), because they already contain the device path, and if it’s your driver running, then if the device itself is ‘spitting out messages’ then you basically already know it’s your driver doing it’s work 😉

But, but! I want to prefix it so I/everyone can see it’s my driver (because that’s cool!), so can i prefix all those lines myself?
I get your enthusiasm and that you think it’s cool if your driver is reporting in the Linux kernel logs, and yes that is totally epic if it’s your first driver you wrote😊👍🏽

However, what’s not cool, is creating a cluster-f*** in everyone their logfiles with spamming your driver name tons of times 😉. It is not recommended (and not even generally accepted) to prefix every device related log message with the name of the driver spitting them out.

The log files aren’t a place to ‘look cool’, flaunt or show the pride in your project, that’s what GitHub, YouTube, your blog and forums are for😉.

But which dev_macros are there?

Great question, and basically almost the same as for pr_macros actually😊:

Macro	Log Level	Log Level NR	Purpose & Examples
dev_err	KERN_ERR	3	Device-specific errors where an operation failed dev_err(&intf->dev, “USB connection failed”);
dev_warn	KERN_WARN	4	Potential device issues or unusual conditions dev_warn(&intf->dev, “Driver loaded, but received additional unrecognized data-bit (possible counterfeit controller?)”);
dev_notice	KERN_NOTICE	5	Normal but notable device events dev_notice(&intf->dev, “Device reset completed”); NOTE: Most drivers just use dev_info and ‘skip on using’ dev_notice entirely though!
dev_info	KERN_INFO	6	Routine informational message (device-specific) dev_info(&intf->dev, “Device connected successfully”); dev_info(&intf->dev, “Device disconnected”);
dev_dbg	KERN_DEBUG	7	Debugging output “to dmesg” during (USB) Development (Values output/read from the device)

And if you’ve read the rest of this tutorial, then I don’t really have to explain what each dev_macro does and what it’s for, because that’s basically the same as with the pr_macros but then with device specific paths included by the dev_macro system 😊

And also for dev_dbg the same applies as for pr_debug: it is ‘compiled out’ unless DEBUG is set (see example above about pr_debug).

Final word & Additional Resource(s)

I know this isn’t a full tutorial on how to write your own driver, how to interface with ‘driverless’ USB devices etc (FAR from it even😉😂), but that wasn’t the intention of this post/tutorial either. I just wanted to (as properly as possible) cover the use of pr_macros and dev_macros to give some additional context on their use😊.

I will (when it’s done) publish the driver I’m currently working on as open-source, so you can use that one as an (heavily) commented example if you are interested in that part, and then I will also update this post with a link to that driver (this is for a game controller which I can’t/won’t tell much about yet though😉).

Additional Resource
If you are interested more in detail how printk and the macros work, then I would recommend to checkout the kernel.org documentation here, this is very useful information for developers.

And I also hope that my blog-post/tutorial was useful for (beginning) driver developers😊

Have fun, and happy coding,