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:
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?
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?
- 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]#
Answer
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.