Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Call trace when loading a module in Linux

I'm writing my first Linux kernel module, which actually is a RAM disk driver plus some additional features. When I tried to insmod the module, "Segmentation fault" happened.

And here is the corresponding kernel log, actually two pieces of kernel oops messages. After reading a lot of related tutorials, I still have some questions regarding this log:

  1. In the call trace list, there are functions preceeded with and without question marks, what is the special meaning of the question mark "?" for that function?

  2. My understanding of the call trace is: every function, except the bottom one, should be called by the one below it. But for this:

     [  397.855035]  [<c05a603b>] ? exact_lock+0x0/0x16
     [  397.855035]  [<f787c252>] ? diag_init+0x252/0x4bd [b2bntb_diag]
     [  397.855035]  [<c0451e35>] ? __blocking_notifier_call_chain+0x42/0x4d
     [  397.855035]  [<f787c000>] ? diag_init+0x0/0x4bd [b2bntb_diag]
    

diag_init the module init function written by me. It does not call any function named either exact_lock or __blocking_notifier_call_chain, how come these two functions appear such in the call trace here?

  1. What is the error and how to resolve it?

BTW, the Linux kernel I'm running has version 2.6.35.6.

[  397.850955] ------------[ cut here ]------------
[  397.851544] WARNING: at lib/kobject.c:168 kobject_add_internal+0x3a/0x1e2()
[  397.851601] Hardware name: VirtualBox
[  397.851639] kobject: (f4580258): attempted to be registered with empty name!
[  397.851678] Modules linked in: b2bntb_diag(+) fuse vboxvideo drm sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6 vboxsf uinput snd_intel8x0 snd_ac97_codec vboxguest ac97_bus snd_seq snd_seq_device ppdev snd_pcm parport_pc parport microcode snd_timer joydev snd e1000 i2c_piix4 soundcore i2c_core snd_page_alloc [last unloaded: mperf]
[  397.852707] Pid: 1958, comm: insmod Tainted: G        W   2.6.35.6-45.fc14.i686 #1
[  397.852749] Call Trace:
[  397.852828]  [<c043938d>] warn_slowpath_common+0x6a/0x7f
[  397.852970]  [<c05b054d>] ? kobject_add_internal+0x3a/0x1e2
[  397.853130]  [<c0439415>] warn_slowpath_fmt+0x2b/0x2f
[  397.853182]  [<c05b054d>] kobject_add_internal+0x3a/0x1e2
[  397.853235]  [<c05b098b>] kobject_add+0x5b/0x66
[  397.853292]  [<c064e8e3>] device_add+0xda/0x4b6
[  397.853346]  [<c05b7bc7>] ? kvasprintf+0x38/0x43
[  397.853394]  [<c05b08e0>] ? kobject_set_name_vargs+0x46/0x4c
[  397.853467]  [<c051b9bc>] register_disk+0x31/0x109
[  397.853528]  [<c05a6234>] ? blk_register_region+0x20/0x25
[  397.853579]  [<c05a6b08>] add_disk+0x9f/0xf0
[  397.853627]  [<c05a5bff>] ? exact_match+0x0/0xd
[  397.853678]  [<c05a603b>] ? exact_lock+0x0/0x16
[  397.853731]  [<f787c252>] diag_init+0x252/0x4bd [b2bntb_diag]
[  397.853785]  [<c0451e35>] ? __blocking_notifier_call_chain+0x42/0x4d
[  397.853836]  [<f787c000>] ? diag_init+0x0/0x4bd [b2bntb_diag]
[  397.853889]  [<c0401246>] do_one_initcall+0x4f/0x139
[  397.853967]  [<c0451e51>] ? blocking_notifier_call_chain+0x11/0x13
[  397.854086]  [<c04621a4>] sys_init_module+0x7f/0x19b
[  397.854142]  [<c07a7374>] syscall_call+0x7/0xb
[  397.854177] ---[ end trace 6dc509801197bdc3 ]---
[  397.855035] ------------[ cut here ]------------
[  397.855035] kernel BUG at fs/sysfs/group.c:65!
[  397.855035] invalid opcode: 0000 [#1] SMP
[  397.855035] last sysfs file: /sys/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A03:00/PNP0C0A:00/power_supply/BAT0/energy_full
[  397.855035] Modules linked in: b2bntb_diag(+) fuse vboxvideo drm sunrpc ip6t_REJECT nf_conntrack_ipv6 ip6table_filter ip6_tables ipv6 vboxsf uinput snd_intel8x0 snd_ac97_codec vboxguest ac97_bus snd_seq snd_seq_device ppdev snd_pcm parport_pc parport microcode snd_timer joydev snd e1000 i2c_piix4 soundcore i2c_core snd_page_alloc [last unloaded: mperf]
[  397.855035]
[  397.855035] Pid: 1958, comm: insmod Tainted: G        W   2.6.35.6-45.fc14.i686 #1 /VirtualBox
[  397.855035] EIP: 0060:[<c0520d15>] EFLAGS: 00010246 CPU: 0
[  397.855035] EIP is at internal_create_group+0x23/0x103
[  397.855035] EAX: f4580258 EBX: f4580258 ECX: c09d4344 EDX: 00000000
[  397.855035] ESI: f60521f0 EDI: c09d4344 EBP: f45b7ef0 ESP: f45b7ed0
[  397.855035]  DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
[  397.855035] Process insmod (pid: 1958, ti=f45b6000 task=f3a68ca0 task.ti=f45b6000)
[  397.855035] Stack:
[  397.855035]  00000000 f45b7ee4 c05b08e0 8eecb04c f4580200 f4580200 f60521f0 f4580200
[  397.855035] <0> f45b7ef8 c0520e1c f45b7f00 c0498de9 f45b7f18 c05a261a f4580250 f4580200
[  397.855035] <0> 00000001 00000000 f45b7f38 c05a6b0f c05a5bff c05a603b f4580200 0fc00000
[  397.855035] Call Trace:
[  397.855035]  [<c05b08e0>] ? kobject_set_name_vargs+0x46/0x4c
[  397.855035]  [<c0520e1c>] ? sysfs_create_group+0x11/0x15
[  397.855035]  [<c0498de9>] ? blk_trace_init_sysfs+0x10/0x12
[  397.855035]  [<c05a261a>] ? blk_register_queue+0x3b/0xac
[  397.855035]  [<c05a6b0f>] ? add_disk+0xa6/0xf0
[  397.855035]  [<c05a5bff>] ? exact_match+0x0/0xd
[  397.855035]  [<c05a603b>] ? exact_lock+0x0/0x16
[  397.855035]  [<f787c252>] ? diag_init+0x252/0x4bd [b2bntb_diag]
[  397.855035]  [<c0451e35>] ? __blocking_notifier_call_chain+0x42/0x4d
[  397.855035]  [<f787c000>] ? diag_init+0x0/0x4bd [b2bntb_diag]
[  397.855035]  [<c0401246>] ? do_one_initcall+0x4f/0x139
[  397.855035]  [<c0451e51>] ? blocking_notifier_call_chain+0x11/0x13
[  397.855035]  [<c04621a4>] ? sys_init_module+0x7f/0x19b
[  397.855035]  [<c07a7374>] ? syscall_call+0x7/0xb
[  397.855035] Code: 8d 65 f4 5b 5e 5f 5d c3 55 89 e5 57 56 53 83 ec 14 0f 1f 44 00 00 85 c0 89 c3 89 55 e0 89 cf 74 0a 85 d2 75 08 83 78 18 00 75 11 <0f> 0b 83 78 18 00 be ea ff ff ff 0f 84 c5 00 00 00 8b 17 85 d2
[  397.855035] EIP: [<c0520d15>] internal_create_group+0x23/0x103 SS:ESP 0068:f45b7ed0
[  397.865682] ---[ end trace 6dc509801197bdc4 ]---
[root@localhost ntb]#
like image 761
OliveU Avatar asked Jun 02 '11 08:06

OliveU


People also ask

What is Call Trace in Linux?

A system call is a programmatic way a program requests a service from the kernel, and strace is a powerful tool that allows you to trace the thin layer between user processes and the Linux kernel.

What is dump_stack in Linux?

“dump_stack” is a function call which will dump the current stack on syslog file which can be seen in dmesg. This will help to understand at perticular point what stack is holding. Below are supporting logs for dump_stack() call. Here dump_stack() is called in module __init function.

What does trace do in Linux?

The Linux Trace Toolkit (LTT) is a set of tools that is designed to log program execution details from a patched Linux kernel and then perform various analyses on them, using console-based and graphical tools.

How to print stack trace in Linux kernel?

Linux kernel provides a function to print the stack trace: dump_stack(). The dump_stack function produces a stack trace much like panic and oops, but causes no problems and we return to the normal control flow. Calling dump_stack() function will print the stack trace at that point.


1 Answers

The first oopss message is actually a warning from the kernel. The important part of the warning is right here: "attempted to be registered with empty name!". It means a descriptive name string field in a kobject was not supplied. Specifically, since in the call trace of the warning we see register_disk, I assume you forgot to properly init the name field of a struct you passed during registration. This is the warning part.

The next oopss message is an actual crash - some code in the sysfs file system that tried to create the name of a group from the name you were supposed to give in your registration process hit a kernel runtime assertion, not doubt due to the missing name field.

So this is why it is crashing. About your questions - some of the functions you see in the trace are actually called from inlined functions (and/or macros) that are used in your code. So your code is calling them, although not by name.

About the question mark, the kernel stack tracking mechanism reports if the address to symbol name lookup it does is "reliable" or not. Not 100% sure what that means, but if it doesn't you get the question mark in the symbol name.

like image 92
gby Avatar answered Sep 29 '22 18:09

gby