Hi Christophe, On 31.01.2024 21:07, Christophe Leroy wrote: > Le 31/01/2024 à 16:17, Marek Szyprowski a écrit : >> [Vous ne recevez pas souvent de courriers de m.szyprowski@xxxxxxxxxxx. Découvrez pourquoi ceci est important à https://aka.ms/LearnAboutSenderIdentification ] >> >> On 31.01.2024 12:58, Christophe Leroy wrote: >>> Le 30/01/2024 à 18:48, Marek Szyprowski a écrit : >>>> [Vous ne recevez pas souvent de courriers de m.szyprowski@xxxxxxxxxxx. Découvrez pourquoi ceci est important à https://aka.ms/LearnAboutSenderIdentification ] >>>> >>>> On 30.01.2024 12:03, Christophe Leroy wrote: >>>>> Le 30/01/2024 à 10:16, Chen-Yu Tsai a écrit : >>>>>> [Vous ne recevez pas souvent de courriers de wenst@xxxxxxxxxxxx. D?couvrez pourquoi ceci est important ? https://aka.ms/LearnAboutSenderIdentification ] >>>>>> >>>>>> On Mon, Jan 29, 2024 at 12:09:50PM -0800, Luis Chamberlain wrote: >>>>>>> On Thu, Dec 21, 2023 at 10:02:46AM +0100, Christophe Leroy wrote: >>>>>>>> Declaring rodata_enabled and mark_rodata_ro() at all time >>>>>>>> helps removing related #ifdefery in C files. >>>>>>>> >>>>>>>> Signed-off-by: Christophe Leroy <christophe.leroy@xxxxxxxxxx> >>>>>>> Very nice cleanup, thanks!, applied and pushed >>>>>>> >>>>>>> Luis >>>>>> On next-20240130, which has your modules-next branch, and thus this >>>>>> series and the other "module: Use set_memory_rox()" series applied, >>>>>> my kernel crashes in some very weird way. Reverting your branch >>>>>> makes the crash go away. >>>>>> >>>>>> I thought I'd report it right away. Maybe you folks would know what's >>>>>> happening here? This is on arm64. >>>>> That's strange, it seems to bug in module_bug_finalize() which is >>>>> _before_ calls to module_enable_ro() and such. >>>>> >>>>> Can you try to revert the 6 patches one by one to see which one >>>>> introduces the problem ? >>>>> >>>>> In reality, only patch 677bfb9db8a3 really change things. Other ones are >>>>> more on less only cleanup. >>>> I've also run into this issue with today's (20240130) linux-next on my >>>> test farm. The issue is not fully reproducible, so it was a bit hard to >>>> bisect it automatically. I've spent some time on manual testing and it >>>> looks that reverting the following 2 commits on top of linux-next fixes >>>> the problem: >>>> >>>> 65929884f868 ("modules: Remove #ifdef CONFIG_STRICT_MODULE_RWX around >>>> rodata_enabled") >>>> 677bfb9db8a3 ("module: Don't ignore errors from set_memory_XX()") >>>> >>>> This in fact means that commit 677bfb9db8a3 is responsible for this >>>> regression, as 65929884f868 has to be reverted only because the latter >>>> depends on it. Let me know what I can do to help debugging this issue. >>>> >>> Thanks for the bisect. I suspect you hit one of the errors and something >>> goes wrong in the error path. >>> >>> To confirm this assumption, could you try with the following change on >>> top of everything ? >> >> Yes, this is the problem. I've added printing a mod->name to the log. >> Here is a log from kernel build from next-20240130 (sometimes it even >> boots to shell): >> >> # dmesg | grep module_set_memory >> [ 8.061525] module_set_memory(6, 0000000000000000, 0) name ipv6 >> returned -22 >> [ 8.067543] WARNING: CPU: 3 PID: 1 at kernel/module/strict_rwx.c:22 >> module_set_memory+0x9c/0xb8 > Would be good if you could show the backtrace too so that we know who is > the caller. I guess what you show here is what you get on the screen ? > The backtrace should be available throught 'dmesg'. Here are relevant parts of the boot log: [ 8.096850] ------------[ cut here ]------------ [ 8.096939] module_set_memory(6, 0000000000000000, 0) name ipv6 returned -22 [ 8.102947] WARNING: CPU: 4 PID: 1 at kernel/module/strict_rwx.c:22 module_set_memory+0x9c/0xb8 [ 8.111561] Modules linked in: [ 8.114596] CPU: 4 PID: 1 Comm: systemd Not tainted 6.8.0-rc2-next-20240130-dirty #14429 [ 8.122654] Hardware name: Khadas VIM3 (DT) [ 8.126815] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) [ 8.133747] pc : module_set_memory+0x9c/0xb8 [ 8.137994] lr : module_set_memory+0x9c/0xb8 [ 8.142240] sp : ffff800083fcba80 [ 8.145534] x29: ffff800083fcba80 x28: 0000000000000001 x27: ffff80007c024448 [ 8.152640] x26: ffff800083fcbc10 x25: ffff80007c007958 x24: ffff80007c024450 [ 8.159747] x23: ffff800083f2a090 x22: ffff80007c007940 x21: 0000000000000006 [ 8.166854] x20: 00000000ffffffea x19: ffff80007c007af0 x18: 0000000000000030 [ 8.173960] x17: 0000000000000000 x16: 0000000000005932 x15: ffffffffffffffff [ 8.181067] x14: ffff800082ea5658 x13: 00000000000003d5 x12: 0000000000000147 [ 8.188174] x11: 6920656d616e2029 x10: ffff800082efd658 x9 : 00000000fffff000 [ 8.195280] x8 : ffff800082ea5658 x7 : ffff800082efd658 x6 : 0000000000000000 [ 8.202387] x5 : 000000000000bff4 x4 : 0000000000000000 x3 : 0000000000000000 [ 8.209494] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff0000001f0000 [ 8.216601] Call trace: [ 8.219027] module_set_memory+0x9c/0xb8 [ 8.222927] module_enable_rodata_ro+0x64/0xa0 [ 8.227347] load_module+0x1838/0x1c88 [ 8.231074] init_module_from_file+0x84/0xc0 [ 8.235320] idempotent_init_module+0x180/0x250 [ 8.239827] __arm64_sys_finit_module+0x64/0xa0 [ 8.244334] invoke_syscall+0x48/0x114 [ 8.248060] el0_svc_common.constprop.0+0x40/0xe0 [ 8.252740] do_el0_svc+0x1c/0x28 [ 8.256034] el0_svc+0x4c/0xe4 [ 8.259067] el0t_64_sync_handler+0xc0/0xc4 [ 8.263227] el0t_64_sync+0x190/0x194 [ 8.266868] irq event stamp: 1304234 [ 8.270421] hardirqs last enabled at (1304233): [<ffff80008012c95c>] console_unlock+0x120/0x12c [ 8.279174] hardirqs last disabled at (1304234): [<ffff800081239bc0>] el1_dbg+0x24/0x8c [ 8.287147] softirqs last enabled at (1301556): [<ffff800080010a60>] __do_softirq+0x4a0/0x4e8 [ 8.295727] softirqs last disabled at (1301545): [<ffff8000800169b0>] ____do_softirq+0x10/0x1c [ 8.304307] ---[ end trace 0000000000000000 ]--- [ 8.508381] ------------[ cut here ]------------ [ 8.508432] module_set_memory(6, 0000000000000000, 0) name x_tables returned -22 [ 8.514785] WARNING: CPU: 2 PID: 1 at kernel/module/strict_rwx.c:22 module_set_memory+0x9c/0xb8 [ 8.523410] Modules linked in: [ 8.526444] CPU: 2 PID: 1 Comm: systemd Tainted: G W 6.8.0-rc2-next-20240130-dirty #14429 [ 8.535976] Hardware name: Khadas VIM3 (DT) [ 8.540137] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) [ 8.547069] pc : module_set_memory+0x9c/0xb8 [ 8.551316] lr : module_set_memory+0x9c/0xb8 [ 8.555562] sp : ffff800083fcba80 [ 8.558856] x29: ffff800083fcba80 x28: 0000000000000001 x27: ffff80007bfab1f0 [ 8.565963] x26: ffff800083fcbc10 x25: ffff80007bfa5458 x24: ffff80007bfab1f8 [ 8.573069] x23: ffff800083f2a090 x22: ffff80007bfa5440 x21: 0000000000000006 [ 8.580176] x20: 00000000ffffffea x19: ffff80007bfa55f0 x18: 0000000000000030 [ 8.587282] x17: 64656e7275746572 x16: 2073656c6261745f x15: 7820656d616e2029 [ 8.594389] x14: ffff800082ea5658 x13: 000000000000044a x12: 000000000000016e [ 8.601496] x11: 6261745f7820656d x10: ffff800082efd658 x9 : 00000000fffff000 [ 8.608602] x8 : ffff800082ea5658 x7 : ffff800082efd658 x6 : 0000000000000000 [ 8.615709] x5 : 000000000000bff4 x4 : 0000000000000000 x3 : 0000000000000000 [ 8.622816] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff0000001f0000 [ 8.629923] Call trace: [ 8.632349] module_set_memory+0x9c/0xb8 [ 8.636249] module_enable_rodata_ro+0x64/0xa0 [ 8.640669] load_module+0x1838/0x1c88 [ 8.644396] init_module_from_file+0x84/0xc0 [ 8.648642] idempotent_init_module+0x180/0x250 [ 8.653149] __arm64_sys_finit_module+0x64/0xa0 [ 8.657656] invoke_syscall+0x48/0x114 [ 8.661383] el0_svc_common.constprop.0+0x40/0xe0 [ 8.666062] do_el0_svc+0x1c/0x28 [ 8.669356] el0_svc+0x4c/0xe4 [ 8.672389] el0t_64_sync_handler+0xc0/0xc4 [ 8.676549] el0t_64_sync+0x190/0x194 [ 8.680190] irq event stamp: 1304890 [ 8.683742] hardirqs last enabled at (1304889): [<ffff80008012c95c>] console_unlock+0x120/0x12c [ 8.692496] hardirqs last disabled at (1304890): [<ffff800081239bc0>] el1_dbg+0x24/0x8c [ 8.700469] softirqs last enabled at (1304870): [<ffff800080010a60>] __do_softirq+0x4a0/0x4e8 [ 8.709049] softirqs last disabled at (1304865): [<ffff8000800169b0>] ____do_softirq+0x10/0x1c [ 8.717629] ---[ end trace 0000000000000000 ]--- [ 10.560872] ------------[ cut here ]------------ [ 10.560924] module_set_memory(6, 0000000000000000, 0) name dm_mod returned -22 [ 10.567128] WARNING: CPU: 4 PID: 127 at kernel/module/strict_rwx.c:22 module_set_memory+0x9c/0xb8 [ 10.575902] Modules linked in: [ 10.578937] CPU: 4 PID: 127 Comm: modprobe Tainted: G W 6.8.0-rc2-next-20240130-dirty #14429 [ 10.588728] Hardware name: Khadas VIM3 (DT) [ 10.592889] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) [ 10.599821] pc : module_set_memory+0x9c/0xb8 [ 10.604068] lr : module_set_memory+0x9c/0xb8 [ 10.608314] sp : ffff800084da3a80 [ 10.611608] x29: ffff800084da3a80 x28: 0000000000000001 x27: ffff80007bfbf22c [ 10.618714] x26: ffff800084da3c10 x25: ffff80007bfb4c58 x24: ffff80007bfbf234 [ 10.623602] systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore... [ 10.625820] x23: ffff800083f2a090 x22: ffff80007bfb4c40 x21: 0000000000000006 [ 10.625848] x20: 00000000ffffffea x19: ffff80007bfb4df0 x18: 0000000000000030 [ 10.648751] x17: 2d2064656e727574 x16: 657220646f6d5f6d x15: 6420656d616e2029 [ 10.648768] x14: ffff800082ea5658 x13: 000000000000051f x12: 00000000000001b5 [ 10.648782] x11: 5f6d6420656d616e x10: ffff800082efd658 x9 : 00000000fffff000 [ 10.648795] x8 : ffff800082ea5658 x7 : ffff800082efd658 x6 : 0000000000000000 [ 10.677128] x5 : 000000000000bff4 x4 : 0000000000000000 x3 : 0000000000000000 [ 10.684235] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff00003d341b80 [ 10.691342] Call trace: [ 10.693768] module_set_memory+0x9c/0xb8 [ 10.697668] module_enable_rodata_ro+0x64/0xa0 [ 10.702088] load_module+0x1838/0x1c88 [ 10.705815] init_module_from_file+0x84/0xc0 [ 10.710061] idempotent_init_module+0x180/0x250 [ 10.714568] __arm64_sys_finit_module+0x64/0xa0 [ 10.719075] invoke_syscall+0x48/0x114 [ 10.722801] el0_svc_common.constprop.0+0x40/0xe0 [ 10.727481] do_el0_svc+0x1c/0x28 [ 10.730774] el0_svc+0x4c/0xe4 [ 10.733808] el0t_64_sync_handler+0xc0/0xc4 [ 10.737968] el0t_64_sync+0x190/0x194 [ 10.741609] irq event stamp: 13696 [ 10.744988] hardirqs last enabled at (13695): [<ffff80008012c95c>] console_unlock+0x120/0x12c [ 10.753568] hardirqs last disabled at (13696): [<ffff800081239bc0>] el1_dbg+0x24/0x8c [ 10.761368] softirqs last enabled at (13692): [<ffff800080010a60>] __do_softirq+0x4a0/0x4e8 [ 10.769774] softirqs last disabled at (13683): [<ffff8000800169b0>] ____do_softirq+0x10/0x1c [ 10.778181] ---[ end trace 0000000000000000 ]--- [ 10.860938] ------------[ cut here ]------------ [ 10.860989] module_set_memory(6, 0000000000000000, 0) name fuse returned -22 [ 10.867007] WARNING: CPU: 3 PID: 130 at kernel/module/strict_rwx.c:22 module_set_memory+0x9c/0xb8 [ 10.875796] Modules linked in: [ 10.878829] CPU: 3 PID: 130 Comm: modprobe Tainted: G W 6.8.0-rc2-next-20240130-dirty #14429 [ 10.888621] Hardware name: Khadas VIM3 (DT) [ 10.892781] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--) [ 10.899714] pc : module_set_memory+0x9c/0xb8 [ 10.903960] lr : module_set_memory+0x9c/0xb8 [ 10.908207] sp : ffff800084d8ba80 [ 10.911500] x29: ffff800084d8ba80 x28: 0000000000000001 x27: ffff80007bff7148 [ 10.918607] x26: ffff800084d8bc10 x25: ffff80007bfee758 x24: ffff80007bff7150 [ 10.925714] x23: ffff800083f2a090 x22: ffff80007bfee740 x21: 0000000000000006 [ 10.932820] x20: 00000000ffffffea x19: ffff80007bfee8f0 x18: 0000000000000030 [ 10.939927] x17: 0000000000000000 x16: 0000000000000000 x15: ffffffffffffffff [ 10.947034] x14: ffff800082ea5658 x13: 000000000000059d x12: 00000000000001df [ 10.954140] x11: 6620656d616e2029 x10: ffff800082efd658 x9 : 00000000fffff000 [ 10.961247] x8 : ffff800082ea5658 x7 : ffff800082efd658 x6 : 0000000000000000 [ 10.968354] x5 : 000000000000bff4 x4 : 0000000000000000 x3 : 0000000000000000 [ 10.975460] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff00000268d280 [ 10.982568] Call trace: [ 10.984994] module_set_memory+0x9c/0xb8 [ 10.988894] module_enable_rodata_ro+0x64/0xa0 [ 10.993314] load_module+0x1838/0x1c88 [ 10.997041] init_module_from_file+0x84/0xc0 [ 11.001287] idempotent_init_module+0x180/0x250 [ 11.005794] __arm64_sys_finit_module+0x64/0xa0 [ 11.010301] invoke_syscall+0x48/0x114 [ 11.014027] el0_svc_common.constprop.0+0x40/0xe0 [ 11.018707] do_el0_svc+0x1c/0x28 [ 11.022000] el0_svc+0x4c/0xe4 [ 11.025034] el0t_64_sync_handler+0xc0/0xc4 [ 11.029194] el0t_64_sync+0x190/0x194 [ 11.032835] irq event stamp: 13612 [ 11.036214] hardirqs last enabled at (13611): [<ffff80008012c95c>] console_unlock+0x120/0x12c [ 11.044794] hardirqs last disabled at (13612): [<ffff800081239bc0>] el1_dbg+0x24/0x8c [ 11.052594] softirqs last enabled at (13584): [<ffff800080010a60>] __do_softirq+0x4a0/0x4e8 [ 11.061000] softirqs last disabled at (13333): [<ffff8000800169b0>] ____do_softirq+0x10/0x1c [ 11.069407] ---[ end trace 0000000000000000 ]--- > I guess we will now seek help from ARM64 people to understand why > module_set_memory_something() fails with -EINVAL when loading modules. > > ... Best regards -- Marek Szyprowski, PhD Samsung R&D Institute Poland
