1

Sometimes I receive the flollowing logs from kernel when trying to unload a module using delete_module system call:

static inline int delete_module(const char *name, int flags)
{
    return syscall(__NR_delete_module, name, flags);
}

From the backtrace, the kernel is trying to find a kernfs_node by name and remove it. But the name is NULL in this case. What could be the root cause of such random problem ?

[[ 135.142426] st_asm330lhh_spi spi2.0: Removing device 0
[[ 135.143021] st_asm330lhh_spi spi2.0: Removing device 1
[[ 135.145053] Unable to handle kernel paging request at virtual address 11ffe6ff
[[ 135.145072] pgd = d75a4000
[[ 135.145082] [11ffe6ff] *pgd=00000000
[[ 135.145097] Internal error: Oops: 5 [#1] PREEMPT ARM
[[ 135.145114] Modules linked in: st_asm330lhh(-) gpio50 [last unloaded: st_asm330lhh]
[[ 135.145139] CPU: 0 PID: 2361 Comm: lifecyclemgr Not tainted 3.18.48 #4
[[ 135.145152] task: cc93b900 ti: cc96c000 task.ti: cc96c000
[[ 135.145170] PC is at strlen+0x4/0x24
[[ 135.145187] LR is at kernfs_name_hash+0x10/0x6c
[[ 135.145201] pc : [<c01f4698>] lr : [<c012e5f0>] psr: 60010013
[[ 135.145201] sp : cc96def8 ip : 00000000 fp : b1bfe48c
[[ 135.145215] r10: 00000000 r9 : cc96c000 r8 : 00000800
[[ 135.145227] r7 : bf0060d0 r6 : 11ffe6ff r5 : 00000000 r4 : 11ffe6ff
[[ 135.145239] r3 : 11ffe6ff r2 : 00000000 r1 : 00000000 r0 : 11ffe6ff
[[ 135.145252] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment none
[[ 135.145265] Control: 10c53c7d Table: 975a4059 DAC: 00000051
[[ 135.145277] Process lifecyclemgr (pid: 2361, stack limit = 0xcc96c208)
[[ 135.145289] Stack: (0xcc96def8 to 0xcc96e000)
[[ 135.145303] dee0: cc952b50 00000000
[[ 135.145321] df00: 11ffe6ff c012efc8 cc952870 11ffe6ff 00000000 11ffe6ff cc952870 00000000
[[ 135.145339] df20: bf0060d0 c012fd84 bf006088 00000000 cc887c00 c006d678 00000000 bf006088
[[ 135.145357] df40: c0d21008 60010013 00000800 c006d7fc 615f7473 33336d73 68686c30 00000000
[[ 135.145375] df60: 00000000 00000000 cc93b900 00000000 cc93b900 00000000 c0dcd3b8 cc96dfb0
[[ 135.145393] df80: b1bfe494 c0033d14 0096c000 29427fd7 4fe52e18 b1bfe4ac 4fe48a54 00000081
[[ 135.145411] dfa0: c000e624 c000e460 4fe52e18 b1bfe4ac 4fe52e18 00000800 00000000 00000800
[[ 135.145430] dfc0: 4fe52e18 b1bfe4ac 4fe48a54 00000081 002179bc 001c9790 0bebc200 b1bfe48c
[[ 135.145448] dfe0: b1bfe480 b1bfe470 4fe48914 4fafce30 60010010 4fe52e18 e594102c e2840024
[[ 135.145476] [<c01f4698>] (strlen) from [<c012e5f0>] (kernfs_name_hash+0x10/0x6c)
[[ 135.145500] [<c012e5f0>] (kernfs_name_hash) from [<c012efc8>] (kernfs_find_ns+0x70/0xd8)
[[ 135.145524] [<c012efc8>] (kernfs_find_ns) from [<c012fd84>] (kernfs_remove_by_name_ns+0x48/0x78)
[[ 135.145548] [<c012fd84>] (kernfs_remove_by_name_ns) from [<c006d678>] (free_module+0x184/0x1c4)
[[ 135.145569] [<c006d678>] (free_module) from [<c006d7fc>] (SyS_delete_module+0x144/0x1dc)
[[ 135.145591] [<c006d7fc>] (SyS_delete_module) from [<c000e460>] (ret_fast_syscall+0x0/0x44)
[[ 135.145609] Code: 1afffff9 e12fff1e c077e998 e1a03000 (e5d32000)
[[ 135.145622] ---[ end trace 7e807feb82cc2ca5 ]--- 
0

Welcome to Unix & Linux SE!

When a module is unloaded, it needs to free any system resources it has allocated for its operations.

Perhaps the module you're unloading has a bug in it, causing the module unloading process to call kernfs_remove_by_name_ns() with a NULL instead of a valid parameter when the module is being unloaded?

A quick glance through the functions referred to in the backtrace indicates the problem is probably the second parameter of kernfs_remove_by_name_ns() being NULL.

Looking at the source code of free_module(), the first things referring to the module's resources by name would be based on the name member in the module's struct module - if that's already NULL for some reason when the module is being removed, that Oops would be expected.

  • Thank you for your feedback. But I don't think the issue is related to the module itself, because the same behavior was seen with other modules from different providers/types .. – TLILI Nassim Jan 28 at 9:57
  • There is an Unable to handle kernel paging request at virtual address 11ffe6ff before the oops, so the system state may have been corrupted at some earlier point. Or if you are making several delete_module() syscalls quickly one after another, you may have discovered a race condition in the module unloading sequence. You mention "modules from different providers/types" - what exactly are these modules? Any common factors? – telcoM Jan 28 at 10:43
  • Test done by adding a delay of 1 sec between the occurences of delete_module(). But the issue is seen. Example of modules used: st_asm330lhh_spi, gpio50. – TLILI Nassim Jan 29 at 9:32
  • Now, we are trying to add a check of busy state as implemented in "rmmod" source code: github.com/vadmium/module-init-tools/blob/master/rmmod.c – TLILI Nassim Jan 29 at 9:39

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.