bug-hunting.rst 15 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369
  1. Bug hunting
  2. ===========
  3. Kernel bug reports often come with a stack dump like the one below::
  4. ------------[ cut here ]------------
  5. WARNING: CPU: 1 PID: 28102 at kernel/module.c:1108 module_put+0x57/0x70
  6. Modules linked in: dvb_usb_gp8psk(-) dvb_usb dvb_core nvidia_drm(PO) nvidia_modeset(PO) snd_hda_codec_hdmi snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_timer snd soundcore nvidia(PO) [last unloaded: rc_core]
  7. CPU: 1 PID: 28102 Comm: rmmod Tainted: P WC O 4.8.4-build.1 #1
  8. Hardware name: MSI MS-7309/MS-7309, BIOS V1.12 02/23/2009
  9. 00000000 c12ba080 00000000 00000000 c103ed6a c1616014 00000001 00006dc6
  10. c1615862 00000454 c109e8a7 c109e8a7 00000009 ffffffff 00000000 f13f6a10
  11. f5f5a600 c103ee33 00000009 00000000 00000000 c109e8a7 f80ca4d0 c109f617
  12. Call Trace:
  13. [<c12ba080>] ? dump_stack+0x44/0x64
  14. [<c103ed6a>] ? __warn+0xfa/0x120
  15. [<c109e8a7>] ? module_put+0x57/0x70
  16. [<c109e8a7>] ? module_put+0x57/0x70
  17. [<c103ee33>] ? warn_slowpath_null+0x23/0x30
  18. [<c109e8a7>] ? module_put+0x57/0x70
  19. [<f80ca4d0>] ? gp8psk_fe_set_frontend+0x460/0x460 [dvb_usb_gp8psk]
  20. [<c109f617>] ? symbol_put_addr+0x27/0x50
  21. [<f80bc9ca>] ? dvb_usb_adapter_frontend_exit+0x3a/0x70 [dvb_usb]
  22. [<f80bb3bf>] ? dvb_usb_exit+0x2f/0xd0 [dvb_usb]
  23. [<c13d03bc>] ? usb_disable_endpoint+0x7c/0xb0
  24. [<f80bb48a>] ? dvb_usb_device_exit+0x2a/0x50 [dvb_usb]
  25. [<c13d2882>] ? usb_unbind_interface+0x62/0x250
  26. [<c136b514>] ? __pm_runtime_idle+0x44/0x70
  27. [<c13620d8>] ? __device_release_driver+0x78/0x120
  28. [<c1362907>] ? driver_detach+0x87/0x90
  29. [<c1361c48>] ? bus_remove_driver+0x38/0x90
  30. [<c13d1c18>] ? usb_deregister+0x58/0xb0
  31. [<c109fbb0>] ? SyS_delete_module+0x130/0x1f0
  32. [<c1055654>] ? task_work_run+0x64/0x80
  33. [<c1000fa5>] ? exit_to_usermode_loop+0x85/0x90
  34. [<c10013f0>] ? do_fast_syscall_32+0x80/0x130
  35. [<c1549f43>] ? sysenter_past_esp+0x40/0x6a
  36. ---[ end trace 6ebc60ef3981792f ]---
  37. Such stack traces provide enough information to identify the line inside the
  38. Kernel's source code where the bug happened. Depending on the severity of
  39. the issue, it may also contain the word **Oops**, as on this one::
  40. BUG: unable to handle kernel NULL pointer dereference at (null)
  41. IP: [<c06969d4>] iret_exc+0x7d0/0xa59
  42. *pdpt = 000000002258a001 *pde = 0000000000000000
  43. Oops: 0002 [#1] PREEMPT SMP
  44. ...
  45. Despite being an **Oops** or some other sort of stack trace, the offended
  46. line is usually required to identify and handle the bug. Along this chapter,
  47. we'll refer to "Oops" for all kinds of stack traces that need to be analized.
  48. .. note::
  49. ``ksymoops`` is useless on 2.6 or upper. Please use the Oops in its original
  50. format (from ``dmesg``, etc). Ignore any references in this or other docs to
  51. "decoding the Oops" or "running it through ksymoops".
  52. If you post an Oops from 2.6+ that has been run through ``ksymoops``,
  53. people will just tell you to repost it.
  54. Where is the Oops message is located?
  55. -------------------------------------
  56. Normally the Oops text is read from the kernel buffers by klogd and
  57. handed to ``syslogd`` which writes it to a syslog file, typically
  58. ``/var/log/messages`` (depends on ``/etc/syslog.conf``). On systems with
  59. systemd, it may also be stored by the ``journald`` daemon, and accessed
  60. by running ``journalctl`` command.
  61. Sometimes ``klogd`` dies, in which case you can run ``dmesg > file`` to
  62. read the data from the kernel buffers and save it. Or you can
  63. ``cat /proc/kmsg > file``, however you have to break in to stop the transfer,
  64. ``kmsg`` is a "never ending file".
  65. If the machine has crashed so badly that you cannot enter commands or
  66. the disk is not available then you have three options:
  67. (1) Hand copy the text from the screen and type it in after the machine
  68. has restarted. Messy but it is the only option if you have not
  69. planned for a crash. Alternatively, you can take a picture of
  70. the screen with a digital camera - not nice, but better than
  71. nothing. If the messages scroll off the top of the console, you
  72. may find that booting with a higher resolution (eg, ``vga=791``)
  73. will allow you to read more of the text. (Caveat: This needs ``vesafb``,
  74. so won't help for 'early' oopses)
  75. (2) Boot with a serial console (see
  76. :ref:`Documentation/admin-guide/serial-console.rst <serial_console>`),
  77. run a null modem to a second machine and capture the output there
  78. using your favourite communication program. Minicom works well.
  79. (3) Use Kdump (see Documentation/kdump/kdump.txt),
  80. extract the kernel ring buffer from old memory with using dmesg
  81. gdbmacro in Documentation/kdump/gdbmacros.txt.
  82. Finding the bug's location
  83. --------------------------
  84. Reporting a bug works best if you point the location of the bug at the
  85. Kernel source file. There are two methods for doing that. Usually, using
  86. ``gdb`` is easier, but the Kernel should be pre-compiled with debug info.
  87. gdb
  88. ^^^
  89. The GNU debug (``gdb``) is the best way to figure out the exact file and line
  90. number of the OOPS from the ``vmlinux`` file.
  91. The usage of gdb works best on a kernel compiled with ``CONFIG_DEBUG_INFO``.
  92. This can be set by running::
  93. $ ./scripts/config -d COMPILE_TEST -e DEBUG_KERNEL -e DEBUG_INFO
  94. On a kernel compiled with ``CONFIG_DEBUG_INFO``, you can simply copy the
  95. EIP value from the OOPS::
  96. EIP: 0060:[<c021e50e>] Not tainted VLI
  97. And use GDB to translate that to human-readable form::
  98. $ gdb vmlinux
  99. (gdb) l *0xc021e50e
  100. If you don't have ``CONFIG_DEBUG_INFO`` enabled, you use the function
  101. offset from the OOPS::
  102. EIP is at vt_ioctl+0xda8/0x1482
  103. And recompile the kernel with ``CONFIG_DEBUG_INFO`` enabled::
  104. $ ./scripts/config -d COMPILE_TEST -e DEBUG_KERNEL -e DEBUG_INFO
  105. $ make vmlinux
  106. $ gdb vmlinux
  107. (gdb) l *vt_ioctl+0xda8
  108. 0x1888 is in vt_ioctl (drivers/tty/vt/vt_ioctl.c:293).
  109. 288 {
  110. 289 struct vc_data *vc = NULL;
  111. 290 int ret = 0;
  112. 291
  113. 292 console_lock();
  114. 293 if (VT_BUSY(vc_num))
  115. 294 ret = -EBUSY;
  116. 295 else if (vc_num)
  117. 296 vc = vc_deallocate(vc_num);
  118. 297 console_unlock();
  119. or, if you want to be more verbose::
  120. (gdb) p vt_ioctl
  121. $1 = {int (struct tty_struct *, unsigned int, unsigned long)} 0xae0 <vt_ioctl>
  122. (gdb) l *0xae0+0xda8
  123. You could, instead, use the object file::
  124. $ make drivers/tty/
  125. $ gdb drivers/tty/vt/vt_ioctl.o
  126. (gdb) l *vt_ioctl+0xda8
  127. If you have a call trace, such as::
  128. Call Trace:
  129. [<ffffffff8802c8e9>] :jbd:log_wait_commit+0xa3/0xf5
  130. [<ffffffff810482d9>] autoremove_wake_function+0x0/0x2e
  131. [<ffffffff8802770b>] :jbd:journal_stop+0x1be/0x1ee
  132. ...
  133. this shows the problem likely in the :jbd: module. You can load that module
  134. in gdb and list the relevant code::
  135. $ gdb fs/jbd/jbd.ko
  136. (gdb) l *log_wait_commit+0xa3
  137. .. note::
  138. You can also do the same for any function call at the stack trace,
  139. like this one::
  140. [<f80bc9ca>] ? dvb_usb_adapter_frontend_exit+0x3a/0x70 [dvb_usb]
  141. The position where the above call happened can be seen with::
  142. $ gdb drivers/media/usb/dvb-usb/dvb-usb.o
  143. (gdb) l *dvb_usb_adapter_frontend_exit+0x3a
  144. objdump
  145. ^^^^^^^
  146. To debug a kernel, use objdump and look for the hex offset from the crash
  147. output to find the valid line of code/assembler. Without debug symbols, you
  148. will see the assembler code for the routine shown, but if your kernel has
  149. debug symbols the C code will also be available. (Debug symbols can be enabled
  150. in the kernel hacking menu of the menu configuration.) For example::
  151. $ objdump -r -S -l --disassemble net/dccp/ipv4.o
  152. .. note::
  153. You need to be at the top level of the kernel tree for this to pick up
  154. your C files.
  155. If you don't have access to the code you can also debug on some crash dumps
  156. e.g. crash dump output as shown by Dave Miller::
  157. EIP is at +0x14/0x4c0
  158. ...
  159. Code: 44 24 04 e8 6f 05 00 00 e9 e8 fe ff ff 8d 76 00 8d bc 27 00 00
  160. 00 00 55 57 56 53 81 ec bc 00 00 00 8b ac 24 d0 00 00 00 8b 5d 08
  161. <8b> 83 3c 01 00 00 89 44 24 14 8b 45 28 85 c0 89 44 24 18 0f 85
  162. Put the bytes into a "foo.s" file like this:
  163. .text
  164. .globl foo
  165. foo:
  166. .byte .... /* bytes from Code: part of OOPS dump */
  167. Compile it with "gcc -c -o foo.o foo.s" then look at the output of
  168. "objdump --disassemble foo.o".
  169. Output:
  170. ip_queue_xmit:
  171. push %ebp
  172. push %edi
  173. push %esi
  174. push %ebx
  175. sub $0xbc, %esp
  176. mov 0xd0(%esp), %ebp ! %ebp = arg0 (skb)
  177. mov 0x8(%ebp), %ebx ! %ebx = skb->sk
  178. mov 0x13c(%ebx), %eax ! %eax = inet_sk(sk)->opt
  179. Reporting the bug
  180. -----------------
  181. Once you find where the bug happened, by inspecting its location,
  182. you could either try to fix it yourself or report it upstream.
  183. In order to report it upstream, you should identify the mailing list
  184. used for the development of the affected code. This can be done by using
  185. the ``get_maintainer.pl`` script.
  186. For example, if you find a bug at the gspca's sonixj.c file, you can get
  187. their maintainers with::
  188. $ ./scripts/get_maintainer.pl -f drivers/media/usb/gspca/sonixj.c
  189. Hans Verkuil <hverkuil@xs4all.nl> (odd fixer:GSPCA USB WEBCAM DRIVER,commit_signer:1/1=100%)
  190. Mauro Carvalho Chehab <mchehab@kernel.org> (maintainer:MEDIA INPUT INFRASTRUCTURE (V4L/DVB),commit_signer:1/1=100%)
  191. Tejun Heo <tj@kernel.org> (commit_signer:1/1=100%)
  192. Bhaktipriya Shridhar <bhaktipriya96@gmail.com> (commit_signer:1/1=100%,authored:1/1=100%,added_lines:4/4=100%,removed_lines:9/9=100%)
  193. linux-media@vger.kernel.org (open list:GSPCA USB WEBCAM DRIVER)
  194. linux-kernel@vger.kernel.org (open list)
  195. Please notice that it will point to:
  196. - The last developers that touched on the source code. On the above example,
  197. Tejun and Bhaktipriya (in this specific case, none really envolved on the
  198. development of this file);
  199. - The driver maintainer (Hans Verkuil);
  200. - The subsystem maintainer (Mauro Carvalho Chehab);
  201. - The driver and/or subsystem mailing list (linux-media@vger.kernel.org);
  202. - the Linux Kernel mailing list (linux-kernel@vger.kernel.org).
  203. Usually, the fastest way to have your bug fixed is to report it to mailing
  204. list used for the development of the code (linux-media ML) copying the driver maintainer (Hans).
  205. If you are totally stumped as to whom to send the report, and
  206. ``get_maintainer.pl`` didn't provide you anything useful, send it to
  207. linux-kernel@vger.kernel.org.
  208. Thanks for your help in making Linux as stable as humanly possible.
  209. Fixing the bug
  210. --------------
  211. If you know programming, you could help us by not only reporting the bug,
  212. but also providing us with a solution. After all, open source is about
  213. sharing what you do and don't you want to be recognised for your genius?
  214. If you decide to take this way, once you have worked out a fix please submit
  215. it upstream.
  216. Please do read
  217. :ref:`Documentation/process/submitting-patches.rst <submittingpatches>` though
  218. to help your code get accepted.
  219. ---------------------------------------------------------------------------
  220. Notes on Oops tracing with ``klogd``
  221. ------------------------------------
  222. In order to help Linus and the other kernel developers there has been
  223. substantial support incorporated into ``klogd`` for processing protection
  224. faults. In order to have full support for address resolution at least
  225. version 1.3-pl3 of the ``sysklogd`` package should be used.
  226. When a protection fault occurs the ``klogd`` daemon automatically
  227. translates important addresses in the kernel log messages to their
  228. symbolic equivalents. This translated kernel message is then
  229. forwarded through whatever reporting mechanism ``klogd`` is using. The
  230. protection fault message can be simply cut out of the message files
  231. and forwarded to the kernel developers.
  232. Two types of address resolution are performed by ``klogd``. The first is
  233. static translation and the second is dynamic translation. Static
  234. translation uses the System.map file in much the same manner that
  235. ksymoops does. In order to do static translation the ``klogd`` daemon
  236. must be able to find a system map file at daemon initialization time.
  237. See the klogd man page for information on how ``klogd`` searches for map
  238. files.
  239. Dynamic address translation is important when kernel loadable modules
  240. are being used. Since memory for kernel modules is allocated from the
  241. kernel's dynamic memory pools there are no fixed locations for either
  242. the start of the module or for functions and symbols in the module.
  243. The kernel supports system calls which allow a program to determine
  244. which modules are loaded and their location in memory. Using these
  245. system calls the klogd daemon builds a symbol table which can be used
  246. to debug a protection fault which occurs in a loadable kernel module.
  247. At the very minimum klogd will provide the name of the module which
  248. generated the protection fault. There may be additional symbolic
  249. information available if the developer of the loadable module chose to
  250. export symbol information from the module.
  251. Since the kernel module environment can be dynamic there must be a
  252. mechanism for notifying the ``klogd`` daemon when a change in module
  253. environment occurs. There are command line options available which
  254. allow klogd to signal the currently executing daemon that symbol
  255. information should be refreshed. See the ``klogd`` manual page for more
  256. information.
  257. A patch is included with the sysklogd distribution which modifies the
  258. ``modules-2.0.0`` package to automatically signal klogd whenever a module
  259. is loaded or unloaded. Applying this patch provides essentially
  260. seamless support for debugging protection faults which occur with
  261. kernel loadable modules.
  262. The following is an example of a protection fault in a loadable module
  263. processed by ``klogd``::
  264. Aug 29 09:51:01 blizard kernel: Unable to handle kernel paging request at virtual address f15e97cc
  265. Aug 29 09:51:01 blizard kernel: current->tss.cr3 = 0062d000, %cr3 = 0062d000
  266. Aug 29 09:51:01 blizard kernel: *pde = 00000000
  267. Aug 29 09:51:01 blizard kernel: Oops: 0002
  268. Aug 29 09:51:01 blizard kernel: CPU: 0
  269. Aug 29 09:51:01 blizard kernel: EIP: 0010:[oops:_oops+16/3868]
  270. Aug 29 09:51:01 blizard kernel: EFLAGS: 00010212
  271. Aug 29 09:51:01 blizard kernel: eax: 315e97cc ebx: 003a6f80 ecx: 001be77b edx: 00237c0c
  272. Aug 29 09:51:01 blizard kernel: esi: 00000000 edi: bffffdb3 ebp: 00589f90 esp: 00589f8c
  273. Aug 29 09:51:01 blizard kernel: ds: 0018 es: 0018 fs: 002b gs: 002b ss: 0018
  274. Aug 29 09:51:01 blizard kernel: Process oops_test (pid: 3374, process nr: 21, stackpage=00589000)
  275. Aug 29 09:51:01 blizard kernel: Stack: 315e97cc 00589f98 0100b0b4 bffffed4 0012e38e 00240c64 003a6f80 00000001
  276. Aug 29 09:51:01 blizard kernel: 00000000 00237810 bfffff00 0010a7fa 00000003 00000001 00000000 bfffff00
  277. Aug 29 09:51:01 blizard kernel: bffffdb3 bffffed4 ffffffda 0000002b 0007002b 0000002b 0000002b 00000036
  278. Aug 29 09:51:01 blizard kernel: Call Trace: [oops:_oops_ioctl+48/80] [_sys_ioctl+254/272] [_system_call+82/128]
  279. Aug 29 09:51:01 blizard kernel: Code: c7 00 05 00 00 00 eb 08 90 90 90 90 90 90 90 90 89 ec 5d c3
  280. ---------------------------------------------------------------------------
  281. ::
  282. Dr. G.W. Wettstein Oncology Research Div. Computing Facility
  283. Roger Maris Cancer Center INTERNET: greg@wind.rmcc.com
  284. 820 4th St. N.
  285. Fargo, ND 58122
  286. Phone: 701-234-7556