Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 1 | =================================== |
| 2 | In-kernel memory-mapped I/O tracing |
| 3 | =================================== |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 4 | |
| 5 | |
| 6 | Home page and links to optional user space tools: |
| 7 | |
| 8 | http://nouveau.freedesktop.org/wiki/MmioTrace |
| 9 | |
| 10 | MMIO tracing was originally developed by Intel around 2003 for their Fault |
| 11 | Injection Test Harness. In Dec 2006 - Jan 2007, using the code from Intel, |
| 12 | Jeff Muizelaar created a tool for tracing MMIO accesses with the Nouveau |
| 13 | project in mind. Since then many people have contributed. |
| 14 | |
| 15 | Mmiotrace was built for reverse engineering any memory-mapped IO device with |
| 16 | the Nouveau project as the first real user. Only x86 and x86_64 architectures |
| 17 | are supported. |
| 18 | |
| 19 | Out-of-tree mmiotrace was originally modified for mainline inclusion and |
| 20 | ftrace framework by Pekka Paalanen <pq@iki.fi>. |
| 21 | |
| 22 | |
| 23 | Preparation |
| 24 | ----------- |
| 25 | |
| 26 | Mmiotrace feature is compiled in by the CONFIG_MMIOTRACE option. Tracing is |
| 27 | disabled by default, so it is safe to have this set to yes. SMP systems are |
| 28 | supported, but tracing is unreliable and may miss events if more than one CPU |
| 29 | is on-line, therefore mmiotrace takes all but one CPU off-line during run-time |
Pekka Paalanen | 6f6f394 | 2008-05-12 21:21:03 +0200 | [diff] [blame] | 30 | activation. You can re-enable CPUs by hand, but you have been warned, there |
| 31 | is no way to automatically detect if you are losing events due to CPUs racing. |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 32 | |
| 33 | |
| 34 | Usage Quick Reference |
| 35 | --------------------- |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 36 | :: |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 37 | |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 38 | $ mount -t debugfs debugfs /sys/kernel/debug |
| 39 | $ echo mmiotrace > /sys/kernel/debug/tracing/current_tracer |
| 40 | $ cat /sys/kernel/debug/tracing/trace_pipe > mydump.txt & |
| 41 | Start X or whatever. |
| 42 | $ echo "X is up" > /sys/kernel/debug/tracing/trace_marker |
| 43 | $ echo nop > /sys/kernel/debug/tracing/current_tracer |
| 44 | Check for lost events. |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 45 | |
| 46 | |
| 47 | Usage |
| 48 | ----- |
| 49 | |
Randy Dunlap | 360b6e5 | 2009-12-18 15:16:56 -0800 | [diff] [blame] | 50 | Make sure debugfs is mounted to /sys/kernel/debug. |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 51 | If not (requires root privileges):: |
| 52 | |
| 53 | $ mount -t debugfs debugfs /sys/kernel/debug |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 54 | |
| 55 | Check that the driver you are about to trace is not loaded. |
| 56 | |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 57 | Activate mmiotrace (requires root privileges):: |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 58 | |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 59 | $ echo mmiotrace > /sys/kernel/debug/tracing/current_tracer |
| 60 | |
| 61 | Start storing the trace:: |
| 62 | |
| 63 | $ cat /sys/kernel/debug/tracing/trace_pipe > mydump.txt & |
| 64 | |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 65 | The 'cat' process should stay running (sleeping) in the background. |
| 66 | |
| 67 | Load the driver you want to trace and use it. Mmiotrace will only catch MMIO |
| 68 | accesses to areas that are ioremapped while mmiotrace is active. |
| 69 | |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 70 | During tracing you can place comments (markers) into the trace by |
GeunSik Lim | 156f5a7 | 2009-06-02 15:01:37 +0900 | [diff] [blame] | 71 | $ echo "X is up" > /sys/kernel/debug/tracing/trace_marker |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 72 | This makes it easier to see which part of the (huge) trace corresponds to |
| 73 | which action. It is recommended to place descriptive markers about what you |
| 74 | do. |
| 75 | |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 76 | Shut down mmiotrace (requires root privileges):: |
| 77 | |
| 78 | $ echo nop > /sys/kernel/debug/tracing/current_tracer |
| 79 | |
Pekka Paalanen | 6f6f394 | 2008-05-12 21:21:03 +0200 | [diff] [blame] | 80 | The 'cat' process exits. If it does not, kill it by issuing 'fg' command and |
| 81 | pressing ctrl+c. |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 82 | |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 83 | Check that mmiotrace did not lose events due to a buffer filling up. Either:: |
| 84 | |
| 85 | $ grep -i lost mydump.txt |
| 86 | |
| 87 | which tells you exactly how many events were lost, or use:: |
| 88 | |
| 89 | $ dmesg |
| 90 | |
Pekka Paalanen | 6f6f394 | 2008-05-12 21:21:03 +0200 | [diff] [blame] | 91 | to view your kernel log and look for "mmiotrace has lost events" warning. If |
| 92 | events were lost, the trace is incomplete. You should enlarge the buffers and |
| 93 | try again. Buffers are enlarged by first seeing how large the current buffers |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 94 | are:: |
| 95 | |
| 96 | $ cat /sys/kernel/debug/tracing/buffer_size_kb |
| 97 | |
Pekka Paalanen | 6f6f394 | 2008-05-12 21:21:03 +0200 | [diff] [blame] | 98 | gives you a number. Approximately double this number and write it back, for |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 99 | instance:: |
| 100 | |
| 101 | $ echo 128000 > /sys/kernel/debug/tracing/buffer_size_kb |
| 102 | |
Pekka Paalanen | 6f6f394 | 2008-05-12 21:21:03 +0200 | [diff] [blame] | 103 | Then start again from the top. |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 104 | |
| 105 | If you are doing a trace for a driver project, e.g. Nouveau, you should also |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 106 | do the following before sending your results:: |
| 107 | |
| 108 | $ lspci -vvv > lspci.txt |
| 109 | $ dmesg > dmesg.txt |
| 110 | $ tar zcf pciid-nick-mmiotrace.tar.gz mydump.txt lspci.txt dmesg.txt |
| 111 | |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 112 | and then send the .tar.gz file. The trace compresses considerably. Replace |
| 113 | "pciid" and "nick" with the PCI ID or model name of your piece of hardware |
Randy Dunlap | 360b6e5 | 2009-12-18 15:16:56 -0800 | [diff] [blame] | 114 | under investigation and your nickname. |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 115 | |
| 116 | |
| 117 | How Mmiotrace Works |
| 118 | ------------------- |
| 119 | |
| 120 | Access to hardware IO-memory is gained by mapping addresses from PCI bus by |
| 121 | calling one of the ioremap_*() functions. Mmiotrace is hooked into the |
| 122 | __ioremap() function and gets called whenever a mapping is created. Mapping is |
Randy Dunlap | 360b6e5 | 2009-12-18 15:16:56 -0800 | [diff] [blame] | 123 | an event that is recorded into the trace log. Note that ISA range mappings |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 124 | are not caught, since the mapping always exists and is returned directly. |
| 125 | |
| 126 | MMIO accesses are recorded via page faults. Just before __ioremap() returns, |
| 127 | the mapped pages are marked as not present. Any access to the pages causes a |
| 128 | fault. The page fault handler calls mmiotrace to handle the fault. Mmiotrace |
| 129 | marks the page present, sets TF flag to achieve single stepping and exits the |
| 130 | fault handler. The instruction that faulted is executed and debug trap is |
| 131 | entered. Here mmiotrace again marks the page as not present. The instruction |
| 132 | is decoded to get the type of operation (read/write), data width and the value |
| 133 | read or written. These are stored to the trace log. |
| 134 | |
| 135 | Setting the page present in the page fault handler has a race condition on SMP |
| 136 | machines. During the single stepping other CPUs may run freely on that page |
| 137 | and events can be missed without a notice. Re-enabling other CPUs during |
| 138 | tracing is discouraged. |
| 139 | |
| 140 | |
| 141 | Trace Log Format |
| 142 | ---------------- |
| 143 | |
| 144 | The raw log is text and easily filtered with e.g. grep and awk. One record is |
Randy Dunlap | 360b6e5 | 2009-12-18 15:16:56 -0800 | [diff] [blame] | 145 | one line in the log. A record starts with a keyword, followed by keyword- |
| 146 | dependent arguments. Arguments are separated by a space, or continue until the |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 147 | end of line. The format for version 20070824 is as follows: |
| 148 | |
Randy Dunlap | 360b6e5 | 2009-12-18 15:16:56 -0800 | [diff] [blame] | 149 | Explanation Keyword Space-separated arguments |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 150 | --------------------------------------------------------------------------- |
| 151 | |
| 152 | read event R width, timestamp, map id, physical, value, PC, PID |
| 153 | write event W width, timestamp, map id, physical, value, PC, PID |
| 154 | ioremap event MAP timestamp, map id, physical, virtual, length, PC, PID |
| 155 | iounmap event UNMAP timestamp, map id, PC, PID |
| 156 | marker MARK timestamp, text |
| 157 | version VERSION the string "20070824" |
| 158 | info for reader LSPCI one line from lspci -v |
Randy Dunlap | 360b6e5 | 2009-12-18 15:16:56 -0800 | [diff] [blame] | 159 | PCI address map PCIDEV space-separated /proc/bus/pci/devices data |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 160 | unk. opcode UNKNOWN timestamp, map id, physical, data, PC, PID |
| 161 | |
| 162 | Timestamp is in seconds with decimals. Physical is a PCI bus address, virtual |
| 163 | is a kernel virtual address. Width is the data width in bytes and value is the |
| 164 | data value. Map id is an arbitrary id number identifying the mapping that was |
| 165 | used in an operation. PC is the program counter and PID is process id. PC is |
| 166 | zero if it is not recorded. PID is always zero as tracing MMIO accesses |
| 167 | originating in user space memory is not yet supported. |
| 168 | |
| 169 | For instance, the following awk filter will pass all 32-bit writes that target |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 170 | physical addresses in the range [0xfb73ce40, 0xfb800000] |
| 171 | :: |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 172 | |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 173 | $ awk '/W 4 / { adr=strtonum($5); if (adr >= 0xfb73ce40 && |
| 174 | adr < 0xfb800000) print; }' |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 175 | |
| 176 | |
| 177 | Tools for Developers |
| 178 | -------------------- |
| 179 | |
| 180 | The user space tools include utilities for: |
Changbin Du | ed657c1 | 2018-02-17 13:39:47 +0800 | [diff] [blame] | 181 | - replacing numeric addresses and values with hardware register names |
| 182 | - replaying MMIO logs, i.e., re-executing the recorded writes |
Pekka Paalanen | c6c67c1 | 2008-05-12 21:20:59 +0200 | [diff] [blame] | 183 | |
| 184 | |