alsa-project/alsa-utils issue #168 was opened from ebrodlic:
We have a recurring issue on an embedded system where we use alsaloop to continually forward audio between: EC25E modem -> system speaker (output) system microphone (input) -> EC25E modem
The two alsaloop processes run constantly in the background, and are in charge of enabling the GSM call audio functionality on our devices.
What ends up happening is: - System boots up and starts the 2 processes - System usage is normal levels for 2-3 hours (very low CPU utilization) - After cca 3 hours of runtime, one alsaloop process will spike a single core of the CPU up to 100% continually - After a seemingly random amount of time of the single CPU core being fully utilized, the system may show reduced responsiveness, eventually showing recurring kernel warnings regarding CPU stalls
``` [Tue Aug 30 16:50:42 2022] rcu: INFO: rcu_preempt self-detected stall on CPU [Tue Aug 30 16:50:42 2022] rcu: 3-....: (5048 ticks this GP) idle=752/1/0x4000000000000002 softirq=1819133/1819133 fqs=2493 [Tue Aug 30 16:50:42 2022] (t=5250 jiffies g=3235733 q=26917) [Tue Aug 30 16:50:42 2022] Task dump for CPU 3: [Tue Aug 30 16:50:42 2022] alsaloop R running task 0 761 1 0x00000202 [Tue Aug 30 16:50:42 2022] Call trace: [Tue Aug 30 16:50:42 2022] dump_backtrace+0x0/0x140 [Tue Aug 30 16:50:42 2022] show_stack+0x14/0x20 [Tue Aug 30 16:50:42 2022] sched_show_task+0x110/0x138 [Tue Aug 30 16:50:42 2022] dump_cpu_task+0x40/0x4c [Tue Aug 30 16:50:42 2022] rcu_dump_cpu_stacks+0x94/0xd0 [Tue Aug 30 16:50:42 2022] rcu_sched_clock_irq+0x75c/0x9c8 [Tue Aug 30 16:50:42 2022] update_process_times+0x2c/0x68 [Tue Aug 30 16:50:42 2022] tick_sched_handle.isra.0+0x30/0x50 [Tue Aug 30 16:50:42 2022] tick_sched_timer+0x48/0x98 [Tue Aug 30 16:50:42 2022] __hrtimer_run_queues+0x110/0x1b0 [Tue Aug 30 16:50:42 2022] hrtimer_interrupt+0xe4/0x240 [Tue Aug 30 16:50:42 2022] arch_timer_handler_phys+0x30/0x40 [Tue Aug 30 16:50:42 2022] handle_percpu_devid_irq+0x80/0x140 [Tue Aug 30 16:50:42 2022] generic_handle_irq+0x24/0x38 [Tue Aug 30 16:50:42 2022] __handle_domain_irq+0x60/0xb8 [Tue Aug 30 16:50:42 2022] gic_handle_irq+0x5c/0x148 [Tue Aug 30 16:50:42 2022] el1_irq+0xb8/0x180 [Tue Aug 30 16:50:42 2022] snd_power_wait+0x0/0xe8 [Tue Aug 30 16:50:42 2022] snd_pcm_ioctl+0x2c/0x40 [Tue Aug 30 16:50:42 2022] do_vfs_ioctl+0x964/0xb48 [Tue Aug 30 16:50:42 2022] ksys_ioctl+0x78/0xa8 [Tue Aug 30 16:50:42 2022] __arm64_sys_ioctl+0x1c/0xb8 [Tue Aug 30 16:50:42 2022] el0_svc_common.constprop.0+0x68/0x160 [Tue Aug 30 16:50:42 2022] el0_svc_handler+0x20/0x80 [Tue Aug 30 16:50:42 2022] el0_svc+0x8/0x208 [Tue Aug 30 16:50:42 2022] retire_capture_urb: 307 callbacks suppressed ```
Commands used to start the two processes: `/usr/bin/alsaloop -P ec25 -C default -t 500000 -n -r 8000 -f S16_LE -c 1` `/usr/bin/alsaloop -C ec25 -P default -t 500000 -n -r 8000 -f S16_LE -c 1`
Our current alsa .asoundrc conf file: ``` pcm.dmixer { type dmix ipc_key 1024 ipc_key_add_uid false # let multiple users share ipc_perm 0666 # IPC permissions for multi-user sharing (octal, default 0600) slave { pcm "hw:tas5722,0" } bindings { 0 0 1 1 } }
pcm.dsnooped { type dsnoop ipc_key 1027 ipc_key_add_uid false # let multiple users share ipc_perm 0666 # IPC permissions for multi-user sharing (octal, default 0600) slave { pcm "hw:ics43432,0" channels 1 format S32_LE } }
pcm.asymed { type asym playback.pcm "dmixer" capture.pcm "softvol" }
pcm.!default { type plug slave.pcm "asymed" }
pcm_slave.ec25 { pcm "hw:EC25E,0" format S16_LE channels 1 rate 8000 }
pcm.ec25 { type plug slave ec25 }
pcm.softvol { type softvol slave.pcm dsnooped control { name "Boost Capture Volume" card ics43432 } min_dB -3.0 max_dB 50.0 } ```
This one is not very easy to debug so it would be great if I could get some pointers in are we dealing with: - potential bugs - alsaloop misuse in approach - problems in existing configuration
Any info would be appreciated!
Issue URL : https://github.com/alsa-project/alsa-utils/issues/168 Repository URL: https://github.com/alsa-project/alsa-utils