Kernel 내부 Memory-mapped I/O 추적

Mmiotrace 개요

MMIO tracing은 Intel이 2003년경 Fault Injection Test Harness용으로 처음 개발했다. 2006년 12월부터 2007년 1월 사이 Jeff Muizelaar가 Intel code를 이용해 Nouveau project를 위한 MMIO access tracing tool을 만들었고 이후 여러 사람이 기여했다.

Mmiotrace는 memory-mapped I/O device를 reverse engineering하기 위해 만들어졌으며 Nouveau가 첫 실제 사용자였다. 지원 architecture는 x86과 x86_64뿐이다.

Out-of-tree mmiotrace는 Pekka Paalanen이 mainline 포함과 ftrace framework에 맞게 수정했다. Home page와 선택적 user-space tool은 원문의 Nouveau MmioTrace URL을 참조한다.

===================================
In-kernel memory-mapped I/O tracing
===================================


Home page and links to optional user space tools:

	https://nouveau.freedesktop.org/wiki/MmioTrace

MMIO tracing was originally developed by Intel around 2003 for their Fault
Injection Test Harness. In Dec 2006 - Jan 2007, using the code from Intel,
Jeff Muizelaar created a tool for tracing MMIO accesses with the Nouveau
project in mind. Since then many people have contributed.

Mmiotrace was built for reverse engineering any memory-mapped IO device with
the Nouveau project as the first real user. Only x86 and x86_64 architectures
are supported.

Out-of-tree mmiotrace was originally modified for mainline inclusion and
ftrace framework by Pekka Paalanen <pq@iki.fi>.

준비와 CPU 제약

`CONFIG_MMIOTRACE`로 기능을 compile한다. Tracing은 기본적으로 disabled이므로 config를 켜 두어도 안전하다.

SMP system을 지원하지만 CPU가 둘 이상 online이면 race로 event를 놓칠 수 있어 신뢰성이 낮다. 따라서 runtime 활성화 때 한 CPU를 제외한 나머지를 offline으로 만든다. 수동으로 CPU를 다시 켤 수는 있지만 event loss를 자동 감지할 방법이 없다.

Preparation
-----------

Mmiotrace feature is compiled in by the CONFIG_MMIOTRACE option. Tracing is
disabled by default, so it is safe to have this set to yes. SMP systems are
supported, but tracing is unreliable and may miss events if more than one CPU
is on-line, therefore mmiotrace takes all but one CPU off-line during run-time
activation. You can re-enable CPUs by hand, but you have been warned, there
is no way to automatically detect if you are losing events due to CPUs racing.

빠른 사용 절차

::

	$ mount -t debugfs debugfs /sys/kernel/debug
	$ echo mmiotrace > /sys/kernel/tracing/current_tracer
	$ cat /sys/kernel/tracing/trace_pipe > mydump.txt &
	Start X or whatever.
	$ echo "X is up" > /sys/kernel/tracing/trace_marker
	$ echo nop > /sys/kernel/tracing/current_tracer
	Check for lost events.

Usage Quick Reference
---------------------
::

	$ mount -t debugfs debugfs /sys/kernel/debug
	$ echo mmiotrace > /sys/kernel/tracing/current_tracer
	$ cat /sys/kernel/tracing/trace_pipe > mydump.txt &
	Start X or whatever.
	$ echo "X is up" > /sys/kernel/tracing/trace_marker
	$ echo nop > /sys/kernel/tracing/current_tracer
	Check for lost events.

상세 사용법과 결과 제출

먼저 debugfs가 `/sys/kernel/debug`에 mount됐는지 확인하고, 추적할 driver가 load되지 않은 상태에서 `current_tracer`를 `mmiotrace`로 바꾼다.

Make sure debugfs is mounted to /sys/kernel/debug.
If not (requires root privileges)::

	$ mount -t debugfs debugfs /sys/kernel/debug

Check that the driver you are about to trace is not loaded.

Activate mmiotrace (requires root privileges)::

	$ echo mmiotrace > /sys/kernel/tracing/current_tracer

Start storing the trace::

	$ cat /sys/kernel/tracing/trace_pipe > mydump.txt &

Background의 `cat` process는 sleep 상태로 계속 실행돼야 한다. 이후 target driver를 load해 사용한다. Mmiotrace가 활성화된 동안 `ioremap`된 영역의 MMIO access만 포착한다.

Tracing 중 `trace_marker`에 설명 문자열을 쓰면 거대한 trace에서 각 action에 해당하는 구간을 찾기 쉬워진다. 수행한 작업을 설명하는 marker를 남기는 것이 권장된다.

During tracing you can place comments (markers) into the trace by
$ echo "X is up" > /sys/kernel/tracing/trace_marker
This makes it easier to see which part of the (huge) trace corresponds to
which action. It is recommended to place descriptive markers about what you
do.

Shut down mmiotrace (requires root privileges)::

	$ echo nop > /sys/kernel/tracing/current_tracer

`current_tracer`를 `nop`으로 바꾸면 mmiotrace를 종료하고 `cat` process도 끝난다. 끝나지 않으면 `fg` 뒤 Ctrl+C로 종료한다.

`grep -i lost mydump.txt` 또는 `dmesg`의 `mmiotrace has lost events` warning으로 buffer overflow event loss를 확인한다. Loss가 있으면 trace가 불완전하므로 buffer를 키우고 다시 시도해야 한다.

Check that mmiotrace did not lose events due to a buffer filling up. Either::

	$ grep -i lost mydump.txt

which tells you exactly how many events were lost, or use::

	$ dmesg

to view your kernel log and look for "mmiotrace has lost events" warning. If
events were lost, the trace is incomplete. You should enlarge the buffers and
try again. Buffers are enlarged by first seeing how large the current buffers
are::

	$ cat /sys/kernel/tracing/buffer_size_kb

gives you a number. Approximately double this number and write it back, for
instance::

	$ echo 128000 > /sys/kernel/tracing/buffer_size_kb

현재 `buffer_size_kb` 값을 읽고 대략 두 배를 다시 쓰면 buffer를 늘릴 수 있다.

Nouveau 같은 driver project에 trace를 제출할 때는 `lspci -vvv`와 `dmesg` 출력도 수집하고 trace와 함께 gzip tar archive로 묶는다. File 이름의 `pciid`와 `nick`은 조사 hardware의 PCI ID 또는 model name과 제출자 nickname으로 바꾼다.

If you are doing a trace for a driver project, e.g. Nouveau, you should also
do the following before sending your results::

	$ lspci -vvv > lspci.txt
	$ dmesg > dmesg.txt
	$ tar zcf pciid-nick-mmiotrace.tar.gz mydump.txt lspci.txt dmesg.txt

and then send the .tar.gz file. The trace compresses considerably. Replace
"pciid" and "nick" with the PCI ID or model name of your piece of hardware
under investigation and your nickname.

Usage
-----

Make sure debugfs is mounted to /sys/kernel/debug.
If not (requires root privileges)::

	$ mount -t debugfs debugfs /sys/kernel/debug

Check that the driver you are about to trace is not loaded.

Activate mmiotrace (requires root privileges)::

	$ echo mmiotrace > /sys/kernel/tracing/current_tracer

Start storing the trace::

	$ cat /sys/kernel/tracing/trace_pipe > mydump.txt &

The 'cat' process should stay running (sleeping) in the background.

Load the driver you want to trace and use it. Mmiotrace will only catch MMIO
accesses to areas that are ioremapped while mmiotrace is active.

During tracing you can place comments (markers) into the trace by
$ echo "X is up" > /sys/kernel/tracing/trace_marker
This makes it easier to see which part of the (huge) trace corresponds to
which action. It is recommended to place descriptive markers about what you
do.

Shut down mmiotrace (requires root privileges)::

	$ echo nop > /sys/kernel/tracing/current_tracer

The 'cat' process exits. If it does not, kill it by issuing 'fg' command and
pressing ctrl+c.

Check that mmiotrace did not lose events due to a buffer filling up. Either::

	$ grep -i lost mydump.txt

which tells you exactly how many events were lost, or use::

	$ dmesg

to view your kernel log and look for "mmiotrace has lost events" warning. If
events were lost, the trace is incomplete. You should enlarge the buffers and
try again. Buffers are enlarged by first seeing how large the current buffers
are::

	$ cat /sys/kernel/tracing/buffer_size_kb

gives you a number. Approximately double this number and write it back, for
instance::

	$ echo 128000 > /sys/kernel/tracing/buffer_size_kb

Then start again from the top.

If you are doing a trace for a driver project, e.g. Nouveau, you should also
do the following before sending your results::

	$ lspci -vvv > lspci.txt
	$ dmesg > dmesg.txt
	$ tar zcf pciid-nick-mmiotrace.tar.gz mydump.txt lspci.txt dmesg.txt

and then send the .tar.gz file. The trace compresses considerably. Replace
"pciid" and "nick" with the PCI ID or model name of your piece of hardware
under investigation and your nickname.

Mmiotrace 동작 원리

Hardware I/O memory는 `ioremap_*()` function으로 PCI bus address를 map해 접근한다. Mmiotrace는 `__ioremap()`에 hook돼 mapping이 생길 때마다 호출되고 이를 trace log event로 기록한다. 항상 존재해 직접 반환되는 ISA range mapping은 포착하지 못한다.

`__ioremap()` return 직전에 mapped page를 not-present로 표시한다. Access가 page fault를 일으키면 handler가 mmiotrace를 호출한다. Mmiotrace는 page를 present로 바꾸고 TF flag로 single-step을 설정한 뒤 fault handler를 빠져나온다.

Fault가 난 instruction이 실행된 뒤 debug trap으로 들어오면 mmiotrace가 page를 다시 not-present로 만든다. Instruction을 decode해 read/write 종류, data width, 읽거나 쓴 값을 얻어 trace log에 저장한다.

SMP에서 fault handler가 page를 present로 둔 single-step 사이 다른 CPU가 같은 page를 자유롭게 접근할 수 있어 알림 없이 event가 누락될 수 있다. Tracing 중 다른 CPU를 다시 online으로 만드는 것은 권장하지 않는다.

How Mmiotrace Works
-------------------

Access to hardware IO-memory is gained by mapping addresses from PCI bus by
calling one of the ioremap_*() functions. Mmiotrace is hooked into the
__ioremap() function and gets called whenever a mapping is created. Mapping is
an event that is recorded into the trace log. Note that ISA range mappings
are not caught, since the mapping always exists and is returned directly.

MMIO accesses are recorded via page faults. Just before __ioremap() returns,
the mapped pages are marked as not present. Any access to the pages causes a
fault. The page fault handler calls mmiotrace to handle the fault. Mmiotrace
marks the page present, sets TF flag to achieve single stepping and exits the
fault handler. The instruction that faulted is executed and debug trap is
entered. Here mmiotrace again marks the page as not present. The instruction
is decoded to get the type of operation (read/write), data width and the value
read or written. These are stored to the trace log.

Setting the page present in the page fault handler has a race condition on SMP
machines. During the single stepping other CPUs may run freely on that page
and events can be missed without a notice. Re-enabling other CPUs during
tracing is discouraged.

Trace log format

Raw log는 grep과 awk로 쉽게 filter할 수 있는 text다. Record 하나가 한 줄이며 keyword 뒤에 종류별 argument가 space로 구분돼 이어진다. 원문 format version은 `20070824`다.

Explanation	Keyword	Space-separated arguments
---------------------------------------------------------------------------

read event	R	width, timestamp, map id, physical, value, PC, PID
write event	W	width, timestamp, map id, physical, value, PC, PID
ioremap event	MAP	timestamp, map id, physical, virtual, length, PC, PID
iounmap event	UNMAP	timestamp, map id, PC, PID
marker		MARK	timestamp, text
version		VERSION	the string "20070824"
info for reader	LSPCI	one line from lspci -v
PCI address map	PCIDEV	space-separated /proc/bus/pci/devices data
unk. opcode	UNKNOWN	timestamp, map id, physical, data, PC, PID

Timestamp는 decimal seconds다. Physical은 PCI bus address, virtual은 kernel virtual address, width는 byte 단위 data 폭, value는 data 값이다. Map id는 operation에 사용한 mapping의 임의 식별자이며 PC는 program counter, PID는 process id다.

PC를 기록하지 않으면 0이다. User-space memory에서 발생한 MMIO access tracing은 아직 지원하지 않으므로 PID는 항상 0이다.

원문의 awk 예제는 physical address `[0xfb73ce40, 0xfb800000)` 범위에 쓰는 모든 32-bit write만 통과시킨다.

For instance, the following awk filter will pass all 32-bit writes that target
physical addresses in the range [0xfb73ce40, 0xfb800000]
::

	$ awk '/W 4 / { adr=strtonum($5); if (adr >= 0xfb73ce40 &&
	adr < 0xfb800000) print; }'

Trace Log Format
----------------

The raw log is text and easily filtered with e.g. grep and awk. One record is
one line in the log. A record starts with a keyword, followed by keyword-
dependent arguments. Arguments are separated by a space, or continue until the
end of line. The format for version 20070824 is as follows:

Explanation	Keyword	Space-separated arguments
---------------------------------------------------------------------------

read event	R	width, timestamp, map id, physical, value, PC, PID
write event	W	width, timestamp, map id, physical, value, PC, PID
ioremap event	MAP	timestamp, map id, physical, virtual, length, PC, PID
iounmap event	UNMAP	timestamp, map id, PC, PID
marker		MARK	timestamp, text
version		VERSION	the string "20070824"
info for reader	LSPCI	one line from lspci -v
PCI address map	PCIDEV	space-separated /proc/bus/pci/devices data
unk. opcode	UNKNOWN	timestamp, map id, physical, data, PC, PID

Timestamp is in seconds with decimals. Physical is a PCI bus address, virtual
is a kernel virtual address. Width is the data width in bytes and value is the
data value. Map id is an arbitrary id number identifying the mapping that was
used in an operation. PC is the program counter and PID is process id. PC is
zero if it is not recorded. PID is always zero as tracing MMIO accesses
originating in user space memory is not yet supported.

For instance, the following awk filter will pass all 32-bit writes that target
physical addresses in the range [0xfb73ce40, 0xfb800000]
::

	$ awk '/W 4 / { adr=strtonum($5); if (adr >= 0xfb73ce40 &&
	adr < 0xfb800000) print; }'

Developer용 도구

User-space tool에는 numeric address와 value를 hardware register name으로 치환하는 utility와, 기록된 write를 다시 실행해 MMIO log를 replay하는 utility가 포함된다.

Tools for Developers
--------------------

The user space tools include utilities for:
  - replacing numeric addresses and values with hardware register names
  - replaying MMIO logs, i.e., re-executing the recorded writes