How to enable and tune Dynamic Debugging for xHCI

Dynamic debugging is a kernel debug mechanism that aims to allow linux users and developers to dynamically enable or suppress kernel debugging statements.

The debugging statements which can be managed via the dynamic debug interface are those that have been written using pr_debug() or dev_debug(). Dynamic debug does not operate over debugging messages written using other than those two functions.

To take advantage of the dynamic debug feature, the kernel has to be compiled with CONFIG_DYNAMIC_DEBUG on. So, before proceeding make sure that your configuration file includes the following line:

CONFIG_DYNAMIC_DEBUG=y

Another thing, that you should pay attention to, for the case of xhci, is that CONFIG_USB_DEBUG should not be set. If USB_DEBUG configuration option is turned on, the debugging statements of the usb host controller drivers would all be enabled by default blowing up your logs. That happens because when CONFIG_USB_DEBUG is set, the usb host controller drivers are compiled with the DEBUG flag.
Observing the code in linux/dynamic_debug.h (the relevant parts have been attached below) shows that when DEBUG is defined, then _DPRINTK_FLAGS_DEFAULT gets defined as _DPRINTK_FLAGS_PRINT. Therefore, the condition for the if statement in dynamic_pr_debug() succeeds and the message gets printed by default.

[snip]

#if defined DEBUG
    #define _DPRINTK_FLAGS_DEFAULT _DPRINTK_FLAGS_PRINT
#else
    #define _DPRINTK_FLAGS_DEFAULT 0
#endif

[snip]

#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt)                    \
            static struct _ddebug  __aligned(8)                     \
            __attribute__((section("__verbose"))) name = {          \
                    [snip]
                   .flags =  _DPRINTK_FLAGS_DEFAULT,                \
            }

#define dynamic_pr_debug(fmt, ...)                                  \
    do {                                                            \
            DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);         \
            if (unlikely(descriptor.flags & _DPRINTK_FLAGS_PRINT))  \
                    __dynamic_pr_debug(&descriptor, pr_fmt(fmt),    \
                                       ##__VA_ARGS__);              \
    } while (0)

The debugging statements can be dynamically enabled and disabled by writing to a debugfs file. So, make sure that debugfs is mounted (it is usually mounted at /sys/kernel/debug). Under debugfs, there is a subdirectory called ‘dynamic_debug’ that contains the file ‘control’.
In this file, you have to write queries with a specific format, in order to enable/disable the debugging statements contained in a module, a file, a function or even a line. In that way, you can enable only the messages that are really interested to you. That saves you from searching in the logs and from the need to recompile or even reboot your system (unless you are interested in early boot debugging statements).

How dynamic debugug interface can be manipulated is explained in great detail in Documentation/dynamic-debug-howto.txt, so let’s do the overall discussion more xhci specific.

======= How to enable dynamic debug for xhci at early boot =======

The reason I decided to write this post in first place is that in Debian I was using the boot option ddebug_query to enable dynamic debugging for xhci. However, when I moved to Arch linux, I realised that this option is deprecated and I had to use dyndbg option instead.
Therefore, if xhci is compiled as a built-in module, you need to add the following boot option:

dyndbg="<query>" (for instance, dyndbg='module xhci_hcd +p')

However, if xhci driver has been compiled as a loadable module, the boot option should be:

xhci_hcd.dyndbg="<query>" (no need to specify again the module
                                 e.g xhci_hcd.dyndbg=+p)

The boot option can be set at boot by pressing ‘e’ or if you want it to be set at every boot, you can add it to your linux ddefault command line by writing the /etc/default/grub file as follows:

GRUB_CMDLINE_LINUX_DEFAULT="xhci_hcd.dyndbg=+p"

Don’t forget to update the grub by doing ‘update-grub’ or ‘grub-mkconfig -o /boot/grub/grub.cfg’.

The query can target a specific file (i.e file <file name> +p) or a specific function (i.e func <function name> +p) or a specific line (i.e line <line num> +p).
Also, more than one queries can be issued using ‘;’ as delimiter to separate them.

======= How to enable dynamic debug for xhci at runtime =======

As it was already said above, dynamic debugging is tuned by echoing queries into the <debugfs>/dynamic_debug/control file.
For example, to enable xhci debug statements do:

echo 'module xhci_hcd +p' > <debugfs>/dynamic_debug/control

To disable them do:

echo 'module xhci_hcd -p' > <debugfs>/dynamic_debug/control

If you are interested in debug messages generated by a group of functions, for example, you can write all the associated queries in a batch file and then use that file to enable them all together.
I would like to stay a bit here, since I have implemented some xhci event traces that do exactly the above (isolate debug messages). For example, the functionality of the xhci_dbg_cancel_urb trace that aims to display the debug messages related to urb cancellation, can be implemented just by importing the following batch file to <debugfs>/dynamic_debug/control, lets call it urb_cancel.batch:

module xhci_hcd func xhci_urb_dequeue +p
module xhci_hcd func xhci_find_new_dequeue_state +p
module xhci_hcd func td_to_noop +p
module xhci_hcd func xhci_handle_cmd_stop_ep +p
module xhci_hcd func xhci_stop_endpoint_command_watchdog +p
module xhci_hcd func xhci_handle_cmd_set_deq +p

And, then, do:

cat urb_cancel.batch > <debugfs>/dynamic_debug/control

Note that using this method in the place of separate debug message traces does not have any overhead and does not require additional code, decreasing xhci size.
So, I will double the number of patches I have sent by revering my own patches :/

Apart from ‘p’, that indicates whether or not the statement will get printed, there are also some other flags like ‘f’, ‘l’, ‘m’ and ‘t’ that can be enabled/disabled if you want to include/exclude in the printed message the name of the function, the line number, the module name or the associated thread, respectively.

If you want to disable all the flags, use flag ‘_’, instead of disabling them individually.

Ok, I ‘m done! For more information, refer to Documentation/dynamic-debug-howto.txt that was currently updated and which was the main source for this post.

Advertisements
This entry was posted in Uncategorized. Bookmark the permalink.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s