modprobe of speakup modules on ARM RT kernel ends up in a lockup of module loading

[Colin Ian King]

ARM64, Ubuntu Noble, RT kernel 6.8.1.1002-realtime in VM (using virt-manager), hosted on a 24 proc ARM server with 24 processor ARM64 client server installation.

In theory, loading modules that the H/W does not support should not cause subsequent module loading issues. The speakup modules on a VM ARM64 server image don't seem to follow this rule.

Example

root@noble-arm64:/home/cking# modprobe speakup_dectlk
root@noble-arm64:/home/cking# modprobe speakup_apollo
[ 621.072682] INFO: task modprobe:1703 blocked for more than 122 seconds.
[ 621.072786] Not tainted 6.8.1-1002-realtime #2-Ubuntu
[ 621.072794] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.

The loading of the speakup_apolloc is locked up on a rt_mutex_slowlock, dmesg reports:

[ 388.982489] input: Speakup as /devices/virtual/input/input1
[ 388.985305] initialized device: /dev/synth, node (MAJOR 10, MINOR 122)
[ 388.986350] speakup 3.1.6: initialized
[ 388.986366] synth name on entry is: (null)
[ 388.996839] synth probe
[ 621.072682] INFO: task modprobe:1703 blocked for more than 122 seconds.
[ 621.072786] Not tainted 6.8.1-1002-realtime #2-Ubuntu
[ 621.072794] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 621.072799] task:modprobe state:D stack:0 pid:1703 tgid:1703 ppid:1687 flags:0x00000004
[ 621.072821] Call trace:
[ 621.072826] __switch_to+0xc8/0x100
[ 621.072849] __schedule+0x298/0x818
[ 621.072859] rt_mutex_schedule+0x30/0x68
[ 621.072874] rt_mutex_slowlock_block.constprop.0+0xb0/0x1a0
[ 621.072887] __rt_mutex_slowlock.constprop.0+0xb0/0x230
[ 621.072898] __rt_mutex_slowlock_locked.constprop.0+0x6c/0xc8
[ 621.072912] mutex_lock+0xa8/0xf0
[ 621.072922] synth_add+0x3c/0x110 [speakup]
[ 621.072995] synth_apollo_init+0x24/0xff8 [speakup_apollo]
[ 621.073019] do_one_initcall+0x64/0x3a8
[ 621.073031] do_init_module+0xa4/0x280
[ 621.073043] load_module+0x7f0/0x8b8
[ 621.073053] init_module_from_file+0x98/0x118
[ 621.073064] idempotent_init_module+0x1a4/0x2c8
[ 621.073074] __arm64_sys_finit_module+0x70/0xf8
[ 621.073085] invoke_syscall+0x7c/0x128
[ 621.073095] el0_svc_common.constprop.0+0x4c/0x140
[ 621.073105] do_el0_svc+0x28/0x58
[ 621.073113] el0_svc+0x44/0x1c0
[ 621.073125] el0t_64_sync_handler+0x148/0x158
[ 621.073137] el0t_64_sync+0x1b0/0x1b8

[Kevin Becker (kevinbecker)]

Hi Colin, I've consistently reproduced this issue in QEMU VMs on arm64 realtime (6.8.1.1002-realtime). However, it also occurs with the generic kernel (6.8.0-35-generic) on arm64. I couldn't get it to happen with amd64.

Here's the dmesg output on 6.8.0-35-generic after the modprobe gets stuck:

[ 303.168453] input: Speakup as /devices/virtual/input/input1
[ 303.174246] initialized device: /dev/synth, node (MAJOR 10, MINOR 122)
[ 303.176539] speakup 3.1.6: initialized
[ 303.176600] synth name on entry is: (null)
[ 303.187469] synth probe
[ 492.396049] INFO: task modprobe:1042 blocked for more than 122 seconds.
[ 492.397557] Not tainted 6.8.0-35-generic #35-Ubuntu
[ 492.398493] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 492.399616] task:modprobe state:D stack:0 pid:1042 tgid:1042 ppid:1041 flags:0x00000004
[ 492.401357] Call trace:
[ 492.401789] __switch_to+0xbc/0xf0
[ 492.403196] __schedule+0x2a8/0x7b0
[ 492.403312] schedule+0x40/0x168
[ 492.403363] schedule_preempt_disabled+0x30/0x68
[ 492.403408] __mutex_lock.constprop.0+0x31c/0x5d0
[ 492.403454] __mutex_lock_slowpath+0x20/0x48
[ 492.403502] mutex_lock+0x8c/0xc0
[ 492.403541] synth_add+0x3c/0x110 [speakup]
[ 492.404115] synth_apollo_init+0x24/0xff8 [speakup_apollo]
[ 492.404213] do_one_initcall+0x64/0x3b8
[ 492.404260] do_init_module+0xa4/0x280
[ 492.404316] load_module+0x7b8/0x8f0
[ 492.404364] init_module_from_file+0x98/0x118
[ 492.404412] idempotent_init_module+0x1a4/0x2c8
[ 492.404459] __arm64_sys_finit_module+0x70/0xf8
[ 492.404511] invoke_syscall+0x7c/0x128
[ 492.404563] el0_svc_common.constprop.0+0x4c/0x140
[ 492.404763] do_el0_svc+0x28/0x58
[ 492.404823] el0_svc+0x44/0x1a0
[ 492.404874] el0t_64_sync_handler+0x148/0x158
[ 492.404926] el0t_64_sync+0x1b0/0x1b8

We'll continue investigating this.

[Colin Ian King (colin-king)]

Thanks for investigating this. Much appreciated \o/