Posted at

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型にキャストして出力


各変換の出力結果

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


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まではひたすら関数を下っていきます。


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);



kernel/printk/printk_safe.c

__printf(1, 0) int vprintk_func(const char *fmt, va_list args)

{

...

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



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);



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)

  2. ログをバッファに格納(log_output)


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);
}



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で定義されていますので興味がある方は参照ください。


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