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