dynamic_debugのcontrolファイルを読むとこんな感じでファイル名、関数名、そしてpr_debugに渡している文字列などが見れます。これってどうやってんだろ？というのが今回調べたところです。

masami@kerntest:~/pr_debug_test$ sudo cat /sys/kernel/debug/dynamic_debug/control | head -n 10
# filename:lineno [module]function flags format
init/main.c:804 [main]initcall_blacklisted =p "initcall %s blacklisted\012"
init/main.c:771 [main]initcall_blacklist =p "blacklisting initcall %s\012"
init/initramfs.c:477 [initramfs]unpack_to_rootfs =_ "Detected %s compressed data\012"
arch/x86/events/amd/ibs.c:885 [ibs]force_ibs_eilvt_setup =_ "No EILVT entry available\012"
arch/x86/events/amd/ibs.c:856 [ibs]setup_ibs_ctl =_ "No CPU node configured for IBS\012"
arch/x86/events/amd/ibs.c:850 [ibs]setup_ibs_ctl =_ "Failed to setup IBS LVT offset, IBSCTL = 0x%08x\012"
arch/x86/events/intel/pt.c:736 [pt]pt_topa_dump =_ "# entry @%p (%lx sz %u %c%c%c) raw=%16llx\012"
arch/x86/events/intel/pt.c:727 [pt]pt_topa_dump =_ "# table @%p (%016Lx), off %llx size %zx\012"
arch/x86/kernel/tboot.c:98 [tboot]tboot_probe =_ "tboot_size: 0x%x\012"

自前のカーネルモジュールを作ってロードした後にはcontorolファイルに値が追加されます。

/home/masami/pr_debug_test/pr_debug_test.c:20 [pr_debug_test]pr_debug_test_read =_ "debug pr_debug test\012"

pr_debugの仕組み

さて、include/linux/printk.hでpr_debugがどのように定義されているか見てみます。dynamic_debugが有効な場合はCONFIG_DYNAMIC_DEBUGが定義されているのでdynamic_pr_debugが使われます。

/* If you are writing a driver, please use dev_dbg instead */
#if defined(CONFIG_DYNAMIC_DEBUG)
#include <linux/dynamic_debug.h>

/* dynamic_pr_debug() uses pr_fmt() internally so we don't need it here */
#define pr_debug(fmt, ...) \
   dynamic_pr_debug(fmt, ##__VA_ARGS__)
#elif defined(DEBUG)
#define pr_debug(fmt, ...) \
   printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#else
#define pr_debug(fmt, ...) \
   no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
#endif

dynamic_pr_debug()はこのようなマクロです。

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

ここの最初の処理がDEFINE_DYNAMIC_DEBUG_METADATAですのでこれを見てみるとこうなっています

#define DEFINE_DYNAMIC_DEBUG_METADATA(name, fmt) \
   DEFINE_DYNAMIC_DEBUG_METADATA_KEY(name, fmt, .key.dd_key_true, \
                     (STATIC_KEY_TRUE_INIT))

DEFINE_DYNAMIC_DEBUG_METADATA_KEYはこのように展開されます。

#define DEFINE_DYNAMIC_DEBUG_METADATA_KEY(name, fmt, key, init) \
   static struct _ddebug  __aligned(8)          \
   __attribute__((section("__verbose"))) name = {       \
       .modname = KBUILD_MODNAME,          \
       .function = __func__,              \
       .filename = __FILE__,              \
       .format = (fmt),                \
       .lineno = __LINE__,                \
       .flags = _DPRINTK_FLAGS_DEFAULT,        \
       dd_key_init(key, init)              \
   }

関数名、ファイル名、行数などがここで出てきてますね。この処理がdynamic_debugの肝っぽいです。nameという変数を定義して、その変数はverboseというセクションに置くようにしています（このマクロはdo {} while(0)の中で展開されるので変数はこのブロック中にあります）。この変数に値を設定してverboseセクションに変数を置くというのがdynamic_debugのポイントですね。ちなみにdd_key_initはjump_labelを使う場合の初期化用マクロです。

というわけで、dynamic_debugが有効なカーネルではpr_debugを使っているところはそのデータが__verboseセクションに置かれるということが分かりました。

__verboseセクションはinclude/asm-generic/vmlinux.lds.hで確認できます。カーネルのビルド後ならarch/x86/kernel/vmlinux.ldsがリンカのファイルです。

    /* implement dynamic printk debug */                \
    . = ALIGN(8);                          \
    __start___verbose = .;                      \
    KEEP(*(__verbose))                                              \
    __stop___verbose = .;                       \

__verboseセクションからデータを読んでいるところ

dynamic_debugの初期化時は以下のようにstartverboseからstopverboseまでのメモリ領域を読んでいってデータをddebug_add_module()でリストに登録しています。

 if (__start___verbose == __stop___verbose) {
        pr_warn("_ddebug table is empty in a CONFIG_DYNAMIC_DEBUG build\n");
        return 1;
    }
    iter = __start___verbose;
    modname = iter->modname;
    iter_start = iter;
    for (; iter < __stop___verbose; iter++) {
        entries++;
        verbose_bytes += strlen(iter->modname) + strlen(iter->function)
            + strlen(iter->filename) + strlen(iter->format);

        if (strcmp(modname, iter->modname)) {
            modct++;
            ret = ddebug_add_module(iter_start, n, modname);
            if (ret)
                goto out_err;
            n = 0;
            modname = iter->modname;
            iter_start = iter;
        }
        n++;
    }
    ret = ddebug_add_module(iter_start, n, modname);
    if (ret)

モジュールのロード時はload_module()からfind_module_sections()が呼ばれ、ここで__verboseセクションのデータを読み取っています。

 info->debug = section_objs(info, "__verbose",
                   sizeof(*info->debug), &info->num_debug);

そして、load_module()からdynamic_debug_setup()を呼び、ddebug_add_module()を読んでデータを登録する形となっています。

static void dynamic_debug_setup(struct module *mod, struct _ddebug *debug, unsigned int num)
{
    if (!debug)
        return;
#ifdef CONFIG_DYNAMIC_DEBUG
    if (ddebug_add_module(debug, num, mod->name))
        pr_err("dynamic debug error adding module: %s\n",
            debug->modname);
#endif
}

まとめ

dynamic_debugが有効なカーネルではソースコード中のpr_debug記述箇所でファイル行数、ファイル名などの情報を変数として登録し、その変数はverboseセクションに置かれる。dynamic_debugはverboseセクションからデータを読んでpr_debugの利用箇所などの情報を取得することができるという感じでした。