printkで%pを使うといろいろと出力できる

#はじめに
printkの使い方を調べていたところ、ポインタ出力(%p)を使っていろいろと出力できることがわかりましたので、少し紹介してみたいと思います。
元ネタはDocumentation/core-api/printk-formats.rstです。
調査対象のLinuxカーネルは4.15、動作確認環境はx86_64上のubuntu16.04(カーネルは4.15)です。

#printkの%pでできること
printkの%pで出力できることを以下表にまとめました。
以下表では[Xy]はXまたはyのいずれかを意味します。また、?は直前の1文字はの省略可能を意味します。
一部用途が不明な部分についてはTODOとしています。

|No | 変換文字 | 概要 |
|:-----------------|:------------|:------------|
|1 | %p                  |ポインタの値を出力.ユーザの権限によって出力内容も制限される模様. 制限かけたくなければpxを使う方がよい **TODO** 制限のかかり方|
|2 | %p[SF]              |ポインタの指すシンボル名、シンボル先頭からのオフセットを出力 |
|3 | %p[sf]              |ポインタの指すシンボル名を出力 |
|4 | %p[SF]B             |%p[SF]と同等 |
|5 | %p[sf]B             |%p[sf]と同等 |
|6 | %pB                 |ポインタの指すシンボル名、シンボル先頭からのオフセットを出力.バックトレース出力時はこの変換を使用するのがよいらしい **TODO** tail-callsとの関係|
|7 | %pK                 |ポインタの値を出力.sysctlのkernel.kptr_restrictの値によって出力が変化する模様 **TODO** kernel.kptr_restrictによる出力変化|
|8 | %px                 |ポインタの値を出力|
|9 | %p[Rr]              |ポインタの指すデータをstruct resourcesの構造で出力|
|10| %pa                 |ポインタの指すデータをphys_addr_t型にキャストして出力|
|11| %pad                |ポインタの指すデータをdma_addr_t型にキャストして出力|
|12| %*pE[achnops]?      |ポインタの指すデータをエスケープして出力.エスケープ方法はEに続く文字で指定|
|13| %ph[CDN]?           |ポインタの指すデータを1バイトずつ16進数表記で出力.各出力の区切りはhに続く文字で指定|
|14| %p[mM][RF]?         |ポインタの指すデータを6バイトのMAC/FDDI形式で出力|
|15| %p[iI]4[hnbl]?      |ポインタの指すデータをIPv4形式で出力|
|16| %p[iI]6c?           |ポインタの指すデータをIPv6形式で出力|
|17| %p[iI]S[pfschnbl]   |ポインタの指すデータをIPv4/IPv6形式で出力.各形式でのフォーマットはNo.15, 16と同じ|
|18| %pU[bBlL]           |ポインタの指すデータをUUID/GUIDアドレス形式で出力|
|19| %p[dD][234]?        |ポインタの指すstruct d_entryデータに対応するパスを出力|
|20| %pg                 |ポインタの指すstruct block_deviceデータに対応するデバイス名を出力|
|21| %pV                 |ポインタの指すstruct va_formatデータを出力|
|22| %pOF[fnpPcCF]       |ポインタの指すstruct kobjectを出力.出力内容はpOFに続く文字で指定可能.CONFIG_OFオプションが有効時のみ使用可能|
|23| %pCn?               |ポインタの指すstruct clkの名前を出力|
|24| %*pbl?              |ポインタの指すデータのビットがセットされている位置を出力|
|25| %*pG[pgv]           |ポインタの指すデータにセットされているフラグを出力.フラグの種類はGに続く文字で指定.p:page flag, g:gfp flag, v:vma flag|
|26| %pNF                |ポインタの指すデータをnetdev_features_t型にキャストして出力|

#各変換の出力結果
上記表だけではイメージが湧きづらいと思いましたので、各変換を出力するカーネルモジュールを作成してみました。ソースコードは以下になります。

```C:printk_test.c
#include <linux/clk.h>
#include <linux/fs.h>
#include <linux/init.h>
#include <linux/ioport.h>
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/moduleparam.h>
#include <linux/sched.h>
#include <linux/types.h>
#include <uapi/linux/in6.h>
#include <uapi/linux/in.h>

static int data;
struct resource resource = {
    .start = 0x1234,
    .end = 0x5678, 
    .name = "test_resource", 
    .flags = 0xABCDEF,
};

static void test_va(const char *fmt, ...)
{
	va_list args;
	struct va_format f;

	va_start(args, fmt);
	f.va = &args;
	f.fmt = fmt;
	printk("%pV\n", &f);
	va_end(args);
}

static int __init init_printk_test(void)
{
    phys_addr_t pa;
    dma_addr_t da;
    uint64_t u_64, u_64_2[2];
    int n;
    char buf[256];
    struct sockaddr_in	v4;
    struct sockaddr_in6	v6;
    struct module *mod;
    unsigned long pflag;
    gfp_t gfp;

    printk("=========start=========\n");

    printk("=====No.1:%%p=====\n");
    printk("%%p: %p, %p\n", init_printk_test, &data);

    printk("=====No.2, 3:%%p[sfSF]=====\n");
    printk("%%pS: %pS, %pS\n", init_printk_test+0x10, &data+0x10);
    printk("%%pF: %pF, %pF\n", init_printk_test, &data+0x10);
    printk("%%ps: %ps, %ps\n", init_printk_test+0x10, &data);
    printk("%%pf: %pf, %pf\n", init_printk_test, &data);

    printk("=====No.4, 5:%%p[sfSF]B=====\n");
    printk("%%pSB: %pSB, %pSB\n", init_printk_test+0x10, &data);
    printk("%%pFB: %pFB, %pFB\n", init_printk_test, &data);
    printk("%%psB: %psB, %psB\n", init_printk_test+0x10, &data);
    printk("%%pfB: %pfB, %pfB\n", init_printk_test, &data);

    printk("=====No.6:%%pB=====\n");
    printk("%%pB: %pB, %pB\n", init_printk_test+0x10, &data);


    printk("=====No.7:%%pK=====\n");
    printk("%%pK: %pK, %pK\n", init_printk_test, &data);
    printk("=====No.8:%%px=====\n");
    printk("%%px: %px, %px\n", init_printk_test, &data);

    printk("=====No.9:%%p[rR]=====\n");
    printk("%%pR: %pR\n", &resource);
    printk("%%pr: %pr\n", &resource);

    printk("=====No.10, 11:%%pa[pd]=====\n");
    pa = 0x0012345678abcdef;
    da = 0x1122334455667788;
    n = 0xaabbccdd;
    printk("%%pa: %pa, %pa\n", &pa, &n);
    printk("%%pap: %pap, %pap\n", &pa, &n);
    printk("%%pad: %pad, %pad\n", &da, &n);

    printk("=====No.12:%%*pE, %%*pE[achnops]=====\n");
    buf[0] = '\0'; buf[1] = '\n'; buf[2] = ' '; buf[3] = 'a'; buf[4] = '\a';
    n = 5;
    printk("%%*pE: %*pE\n", n, buf);
    printk("%%*pEa: %*pEa\n", n, buf);
    printk("%%*pEc: %*pEc\n", n, buf);
    printk("%%*pEh: %*pEh\n", n, buf);
    printk("%%*pEn: %*pEn\n", n, buf);
    printk("%%*pEo: %*pEo\n", n, buf);
    printk("%%*pEp: %*pEp\n", n, buf);
    printk("%%*pEs: %*pEs\n", n, buf);

    printk("=====No.13:%%ph, %%ph[CDN]=====\n");
    printk("%%*ph: %*ph\n", n, buf);
    printk("%%*phC: %*phC\n", n, buf);
    printk("%%*phD: %*phD\n", n, buf);
    printk("%%*phN: %*phN\n", n, buf);

    printk("=====No.14:%%p[mM], %%p[mM][RF]=====\n");
    u_64 = 0x12345678abcdef00;
    printk("%%pm: %pm\n", &u_64);
    printk("%%pmR: %pmR\n", &u_64);
    printk("%%pmF: %pmF\n", &u_64);
    printk("%%pM: %pM\n", &u_64);
    printk("%%pMR: %pMR\n", &u_64);
    printk("%%pMF: %pMF\n", &u_64);

    printk("=====No.15:%%p[iI]4, %%p[iI]4[hnbl]=====\n");
    u_64 = 0x10203040;
    printk("%%pi4: %pi4\n", &u_64);
    printk("%%pI4: %pI4\n", &u_64);
    printk("%%pi4h: %pi4h\n", &u_64);
    printk("%%pi4n: %pi4n\n", &u_64);
    printk("%%pI4b: %pI4b\n", &u_64);
    printk("%%pI4l: %pI4l\n", &u_64);

    printk("=====No.16:%%p[iI]6, %%p[iI]6c=====\n");
    u_64_2[0] = 0x1020304050607080;
    u_64_2[1] = 0x90a0b0c0d0e0f000;
    printk("%%pi6: %pi6\n", &u_64_2);
    printk("%%pI6: %pI6\n", &u_64_2);
    printk("%%pi6c: %pi6c\n", &u_64_2);

    printk("=====No.17:%%p[iI]Spc=====\n");
    v4.sin_family = AF_INET;
    v4.sin_port = htons(1234);
    v4.sin_addr.s_addr = 0x50607080;

    v6.sin6_family = AF_INET6;
    memcpy(&v6.sin6_addr.in6_u, u_64_2, sizeof(v6.sin6_addr.in6_u));
    v6.sin6_port = htons(5678);

    printk("%%piSp: %piSp\n", &v4);
    printk("%%pISp: %pISp\n", &v6);
    printk("%%pISpc: %pISpc\n", &v6);

    printk("=====No.18:%%pU[bBlL]=====\n");
    u_64_2[0] = 0x1020304050607080;
    u_64_2[1] = 0x90a0b0c0d0e0f000;
    printk("%%pUb: %pUb\n", &u_64_2);
    printk("%%pUB: %pUB\n", &u_64_2);
    printk("%%pUl: %pUl\n", &u_64_2);
    printk("%%pUL: %pUL\n", &u_64_2);

    printk("=====No.19:%%p[dD]=====\n");
    printk("%%pd: %pd\n", file_dentry(current->mm->mmap->vm_file));
    printk("%%pd2: %pd2\n", file_dentry(current->mm->mmap->vm_file));
    printk("%%pD4: %pD4\n", file_dentry(current->mm->mmap->vm_file));

    printk("=====No.20:%%pg=====\n");
    printk("%%pg: %pg\n", current->mm->mmap->vm_file->f_inode->i_sb->s_bdev);

    printk("=====No.21:%%pV=====\n");
    test_va("%s", "abcd");

    printk("=====No.22:%%pOF[fnpPcCF]=====\n");
    mod = find_module("printk_test");
    printk("%%pOF: %pOF\n", &mod->mkobj.kobj);
    printk("%%pOFf: %pOFf\n", &mod->mkobj.kobj);
    printk("%%pOFn: %pOFn\n", &mod->mkobj.kobj);
    printk("%%pOFp: %pOFp\n", &mod->mkobj.kobj);
    printk("%%pOFP: %pOFP\n", &mod->mkobj.kobj);
    printk("%%pOFc: %pOFc\n", &mod->mkobj.kobj);
    printk("%%pOFC: %pOFC\n", &mod->mkobj.kobj);
    printk("%%pOFF: %pOFF\n", &mod->mkobj.kobj);

    printk("=====No.24:%%*pbl=====\n");
    u_64 = 0x0102040810204080;
    printk("%%*pb: %*pb\n", sizeof(u_64)*8, &u_64);
    printk("%%*pbl: %*pbl\n", sizeof(u_64)*8, &u_64);

    printk("=====No.25:%%pG[pvg]=====\n");
    gfp = GFP_KERNEL;
    printk("%%pGg: %pGg\n", &gfp);

    pflag = 0x5678;
    printk("%%pGp: %pGp\n", &pflag);
    printk("%%pGv: %pGv\n", &pflag);

    printk("=========end=========\n");
    return 0;
}

static void __exit exit_printk_test(void)
{
}

module_init(init_printk_test)
module_exit(exit_printk_test)
MODULE_LICENSE("GPL");

```

以下は上記モジュールをinsmodした際のdmesgの出力結果です(先頭の時間情報は削除しています)。

```
 =========start=========
 =====No.1:%p=====
 %p: 000000000ce8e3c6, 000000003b5198cf
 =====No.2, 3:%p[sfSF]=====
 %pS: init_printk_test+0x10/0x1000 [printk_test], data+0x40/0xffffffffffffec80 [printk_test]
 %pF: init_printk_test+0x0/0x1000 [printk_test], data+0x40/0xffffffffffffec80 [printk_test]
 %ps: init_printk_test [printk_test], data [printk_test]
 %pf: init_printk_test [printk_test], data [printk_test]
 =====No.4, 5:%p[sfSF]B=====
 %pSB: init_printk_test+0x10/0x1000 [printk_test], data+0x0/0xffffffffffffec80 [printk_test]
 %pFB: init_printk_test+0x0/0x1000 [printk_test], data+0x0/0xffffffffffffec80 [printk_test]
 %psB: init_printk_test [printk_test], data [printk_test]
 %pfB: init_printk_test [printk_test], data [printk_test]
 =====No.6:%pB=====
 %pB: init_printk_test+0x10/0x1000 [printk_test], __this_module+0x340/0xffffffffffffefc0 [printk_test]
 =====No.7:%pK=====
 %pK: ffffffffc051b000, ffffffffc0a6d380
 =====No.8:%px=====
 %px: ffffffffc051b000, ffffffffc0a6d380
 =====No.9:%p[rR]=====
 %pR: [io  0x1234-0x5678 window]
 %pr: [io  0x1234-0x5678 flags 0xabcdef]
 =====No.10, 11:%pa[pd]=====
 %pa: 0x0012345678abcdef, 0x00000000aabbccdd
 %pap: 0x0012345678abcdef, 0x00000000aabbccdd
 %pad: 0x1122334455667788, 0x00000000aabbccdd
 =====No.12:%*pE, %*pE[achnops]=====
 %*pE: \0\n a\a
 %*pEa: \0\n\040\141\a
 %*pEc: 
 %*pEh: \x00\x0a\x20\x61\x07
 %*pEn: \0
  a
 %*pEo: \000\012\040\141\007
 %*pEp: 
 %*pEs: 
 =====No.13:%ph, %ph[CDN]=====
 %*ph: 00 0a 20 61 07
 %*phC: 00:0a:20:61:07
 %*phD: 00-0a-20-61-07
 %*phN: 000a206107
 =====No.14:%p[mM], %p[mM][RF]=====
 %pm: 00efcdab7856
 %pmR: 5678abcdef00
 %pmF: 00efcdab7856
 %pM: 00:ef:cd:ab:78:56
 %pMR: 56:78:ab:cd:ef:00
 %pMF: 00-ef-cd-ab-78-56
 =====No.15:%p[iI]4, %p[iI]4[hnbl]=====
 %pi4: 064.048.032.016
 %pI4: 64.48.32.16
 %pi4h: 016.032.048.064
 %pi4n: 064.048.032.016
 %pI4b: 64.48.32.16
 %pI4l: 16.32.48.64
 =====No.16:%p[iI]6, %p[iI]6c=====
 %pi6: 807060504030201000f0e0d0c0b0a090
 %pI6: 8070:6050:4030:2010:00f0:e0d0:c0b0:a090
 %pi6c: 807060504030201000f0e0d0c0b0a090
 =====No.17:%p[iI]Spc=====
 %piSp: 128.112.096.080:1234
 %pISp: [8070:6050:4030:2010:00f0:e0d0:c0b0:a090]:5678
 %pISpc: [8070:6050:4030:2010:f0:e0d0:c0b0:a090]:5678
 =====No.18:%pU[bBlL]=====
 %pUb: 80706050-4030-2010-00f0-e0d0c0b0a090
 %pUB: 80706050-4030-2010-00F0-E0D0C0B0A090
 %pUl: 50607080-3040-1020-00f0-e0d0c0b0a090
 %pUL: 50607080-3040-1020-00F0-E0D0C0B0A090
 =====No.19:%p[dD]=====
 %pd: kmod
 %pd2: bin/kmod
 %pD4: /bin
 =====No.20:%pg=====
 %pg: sda1
 =====No.21:%pV=====
 abcd
 =====No.22:%pOF[fnpPcCF]=====
#試験環境ではCONFIG_OFが無効のため、有効な情報が出力されていない
 %pOF: (!OF)
 %pOFf: (!OF)
 %pOFn: (!OF)
 %pOFp: (!OF)
 %pOFP: (!OF)
 %pOFc: (!OF)
 %pOFC: (!OF)
 %pOFF: (!OF)
 =====No.24:%*pbl=====
 %*pb: 01020408,10204080
 %*pbl: 7,14,21,28,35,42,49,56
 =====No.25:%pG[pvg]=====
 %pGg: GFP_KERNEL
 %pGp: uptodate|dirty|lru|active|owner_priv_1|arch_1|private|writeback
 %pGv: shared|mayread|maywrite|mayexec|uffd_missing|pfnmap|uffd_wp|io
 =========end=========
```


#printkのソースコード
補足としてprintkのソースコードを簡単に眺めてみます。
フォーマット処理に注目しているため、その他の部分はかなり端折っています。省略箇所は...で記載しています。
まずはvprintk_storeまではひたすら関数を下っていきます。

```C:kernel/printk/printk.c
asmlinkage __visible int printk(const char *fmt, ...)
{
	va_list args;
	int r;

	va_start(args, fmt);
	r = vprintk_func(fmt, args);
	va_end(args);

	return r;
}
EXPORT_SYMBOL(printk);
```


```C:kernel/printk/printk_safe.c
__printf(1, 0) int vprintk_func(const char *fmt, va_list args)
{

	...

	/* No obstacles. */
	return vprintk_default(fmt, args);
}
```

```C:kernel/printk/printk.c
int vprintk_default(const char *fmt, va_list args)
{
	int r;

	...

	r = vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);

	return r;
}
EXPORT_SYMBOL_GPL(vprintk_default);
```

```C:kernel/printk/printk.c
asmlinkage int vprintk_emit(int facility, int level,
			    const char *dict, size_t dictlen,
			    const char *fmt, va_list args)
{

	...

	printed_len = vprintk_store(facility, level, dict, dictlen, fmt, args);

	...

```

vprintk_storeでは以下を行います。以降では1.に注目して見ていきます。

1. 書式文字列のデコード(vscnprintf)
1. ログをバッファに格納(log_output)


```C:kernel/printk/printk.c
int vprintk_store(int facility, int level,
		  const char *dict, size_t dictlen,
		  const char *fmt, va_list args)
{
	static char textbuf[LOG_LINE_MAX];
	char *text = textbuf;
	size_t text_len;
	enum log_flags lflags = 0;

	/*
	 * The printf needs to come first; we need the syslog
	 * prefix which might be passed-in as a parameter.
	 */
	/* 1. 書式文字列をデコード */
	text_len = vscnprintf(text, sizeof(textbuf), fmt, args);

	...

	/* 2. ログをバッファに格納 */
	return log_output(facility, level, lflags,
			  dict, dictlen, text, text_len);
}
```

```C:lib/vsprintf.c
int vscnprintf(char *buf, size_t size, const char *fmt, va_list args)
{
	int i;

	i = vsnprintf(buf, size, fmt, args);

	if (likely(i < size))
		return i;
	if (size != 0)
		return size - 1;
	return 0;
}
EXPORT_SYMBOL(vscnprintf);
```

vsnprintfはformat_decodeで書式文字列をデコードし、その結果に応じてargsを処理していきます。
関数のコメントにあるように、pointerの扱いが拡張されており、pointer関数で%p*の処理を行います。
format_decodeとpointerの実装についてはここでは割愛しますが、それぞれlib/vsprintf.cで定義されていますので興味がある方は参照ください。

```C:lib/vsprintf.c
    ...

 * This function generally follows C99 vsnprintf, but has some
 * extensions and a few limitations:
 *
 *  - ``%n`` is unsupported
 *  - ``%p*`` is handled by pointer()
 *
 * See pointer() or Documentation/core-api/printk-formats.rst for more
 * extensive description.
    ...

 * This function generally follows C99 vsnprintf, but has some
int vsnprintf(char *buf, size_t size, const char *fmt, va_list args)
{
	unsigned long long num;
	char *str, *end;
	struct printf_spec spec = {0};

	/* Reject out-of-range values early.  Large positive sizes are
	   used for unknown buffer sizes. */
	if (WARN_ON_ONCE(size > INT_MAX))
		return 0;

	str = buf;
	end = buf + size;

	/* Make sure end is always >= buf */
	if (end < buf) {
		end = ((void *)-1);
		size = end - buf;
	}

	while (*fmt) {
		const char *old_fmt = fmt;
		int read = format_decode(fmt, &spec);

	...

		case FORMAT_TYPE_PTR:
			str = pointer(fmt, str, end, va_arg(args, void *),
				      spec);
			while (isalnum(*fmt))
				fmt++;
			break;

	...

```

#終わりに
printkはprintfを拡張した部分もあり、いろいろな情報をフォーマットして出力してくれます。
なかなか使うケースが無いような出力もありますが、参考になれば幸いです。

#参考文献
Documentation/core-api/printk-formats.rst