On 2019-02-16 12:06:16 [+0100], Alain Chambron wrote: > Hello, Hi, > I have a running environment using SAMA5D3, kernel 4.14.41, using alsa with > SSC peripheral. > I am looking into the benefits of using the RT patches to lower audio > latency. > Applying the patches and compiling kernel + modules went very smoothly and > the system boots up well, the devices mount correctly and the audio > interface is up. > Anyhow, trying to actually play audio using aplay triggers a BUG(), I > believe on the first DMA interrupt. The backtrace is below this message. I > have some questions: > - has the scc dai being successfully tested on that architecture? maybe Ludovic can answer this. > - I know for a fact that DMA is being used successfully (for example with > SPI devices) on my system, and > atc_tx_status is probably being called from other places, what specifics of > the SSC driver would trigger this bug? > - any other hints from the traces, or other information I could gather from > the system that would help? Can you try addr2line -i on <c038a580> / (atc_tasklet+0x1ec/0x1f0)? It seems that atc_tasklet holds the lock and then atc_tx_status() later tries to acquire the same lock. It might have been fixed in a later kernel. Without -RT but with lockdebugging you should see a similar error. > After that, first bug trace, I get other traces from interrupt 30 being > misshandled and that note: > "irq 30: nobody cared (try booting with the "irqpoll" option)" and the > system is no longer responsive. > > regards, > Alain > > > [ 52.410000] kernel BUG at kernel/locking/rtmutex.c:1048! > [ 52.410000] Internal error: Oops - BUG: 0 [#1] PREEMPT ARM > [ 52.410000] Modules linked in: snd_atmel_soc_audiophil > snd_soc_atmel_ssc_dai snd_soc_atmel_pcm_dma atmel_ssc snd_soc_ak4115 > snd_soc_igloo snd_soc_pcm1792a_codec rotary_encoder snd_soc_si570 > snd_soc_core snd_pcm_dmaengine snd_pcm snd_timer snd soundcore ssd1322(O) > spi_atmel > [ 52.410000] CPU: 0 PID: 263 Comm: irq/30-at_hdmac Tainted: G O > 4.14.41-rt31+ #43 > [ 52.410000] Hardware name: Atmel SAMA5 > [ 52.410000] task: df631e00 task.stack: df6b2000 > [ 52.410000] PC is at rt_spin_lock_slowlock_locked+0x214/0x260 > [ 52.410000] LR is at 0xdf445d08 > [ 52.410000] pc : [<c063efd0>] lr : [<df445d08>] psr: 600f0093 > [ 52.410000] sp : df6b3db8 ip : df631e00 fp : 000000c0 > [ 52.410000] r10: c0a3c2c0 r9 : df75bc00 r8 : df6b3dd0 > [ 52.410000] r7 : a00f0013 r6 : df631e00 r5 : a00f0013 r4 : df445d00 > [ 52.410000] r3 : df631e00 r2 : 00000000 r1 : df631e00 r0 : 00000000 > [ 52.410000] Flags: nZCv IRQs off FIQs on Mode SVC_32 ISA ARM Segment > none > [ 52.410000] Control: 10c53c7d Table: 3ed48059 DAC: 00000051 > [ 52.410000] Process irq/30-at_hdmac (pid: 263, stack limit = 0xdf6b2208) > [ 52.410000] Stack: (0xdf6b3db8 to 0xdf6b4000) > [ 52.410000] 3da0: 00000001 a00f0013 > [ 52.410000] 3dc0: df445d00 df445d00 df445c74 c063f064 df6b3dd0 00000000 > 00000000 df6b3ddc > [ 52.410000] 3de0: 00000000 00000000 00000000 00000000 00000001 00000000 > 00000000 00000000 > [ 52.410000] 3e00: df6b3e2c 00000002 df445c74 c038848c de9a7600 deef3800 > de9a7600 00000000 > [ 52.410000] 3e20: bf070f5c bf058244 00000001 00000001 00000002 00000000 > dec65a00 bf06b2e4 > [ 52.410000] 3e40: df75bc00 df75bc00 00000024 00000000 de9a7600 00000001 > c0a3c2c0 bf045538 > [ 52.410000] 3e60: 00000000 df4f7e80 a00a0113 e09d2e74 df445c60 000f4240 > 000000c0 c013ecc0 > [ 52.410000] 3e80: 000000c0 c013f5c8 bf0006dc e09d2e58 df445bb8 c0388868 > 00000000 de9a7600 > [ 52.410000] 3ea0: df75bc00 600f0013 00000000 000f4240 00000018 c0a3c2c0 > 000000c0 bf04592c > [ 52.410000] 3ec0: df445cbc df445c74 df445d00 c038a580 00000000 00000000 > 00000000 00000000 > [ 52.410000] 3ee0: 00000000 00000000 df445cbc 00000000 df445cb8 00000000 > 000f4240 c011a380 > [ 52.410000] 3f00: 00000006 df6b2000 c0a0b13c 00208040 c0a3c300 c011a06c > c0a0b13c 00000006 > [ 52.410000] 3f20: df40801c 00000000 df445cb8 df7c3a00 df541b00 00000001 > c014a7fc c0a35bd6 > [ 52.410000] 3f40: df7c3ad8 df44bd6c 00000000 c011a194 00000104 c014a83c > df7c3a00 df6b2000 > [ 52.410000] 3f60: df541b00 c014aa40 00000000 c014a884 c014a948 df7c3ac0 > 00000000 df7c3a40 > [ 52.410000] 3f80: df7c3a00 c014a948 df7c3ad8 c0131674 df7c3a40 c0131554 > 00000000 00000000 > [ 52.410000] 3fa0: 00000000 00000000 00000000 c0107830 00000000 00000000 > 00000000 00000000 > [ 52.410000] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 > 00000000 00000000 > [ 52.410000] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000 > 00000000 00000000 > [ 52.410000] [<c063efd0>] (rt_spin_lock_slowlock_locked) from [<c063f064>] > (rt_spin_lock_slowlock+0x48/0x98) > [ 52.410000] [<c063f064>] (rt_spin_lock_slowlock) from [<c038848c>] > (atc_tx_status+0x84/0x234) > [ 52.410000] [<c038848c>] (atc_tx_status) from [<bf058244>] > (snd_dmaengine_pcm_pointer+0x28/0x8c [snd_pcm_dmaengine]) > [ 52.410000] [<bf058244>] (snd_dmaengine_pcm_pointer [snd_pcm_dmaengine]) > from [<bf06b2e4>] (soc_pcm_pointer+0x38/0xd0 [snd_soc_core]) > [ 52.410000] [<bf06b2e4>] (soc_pcm_pointer [snd_soc_core]) from > [<bf045538>] (snd_pcm_update_hw_ptr0+0x28/0x3a8 [snd_pcm]) > [ 52.410000] [<bf045538>] (snd_pcm_update_hw_ptr0 [snd_pcm]) from > [<bf04592c>] (snd_pcm_period_elapsed+0x74/0xac [snd_pcm]) > [ 52.410000] [<bf04592c>] (snd_pcm_period_elapsed [snd_pcm]) from > [<c038a580>] (atc_tasklet+0x1ec/0x1f0) > [ 52.410000] [<c038a580>] (atc_tasklet) from [<c011a380>] > (__tasklet_action+0x7c/0x164) > [ 52.410000] [<c011a380>] (__tasklet_action) from [<c011a06c>] > (do_current_softirqs+0x1ac/0x254) > [ 52.410000] [<c011a06c>] (do_current_softirqs) from [<c011a194>] > (__local_bh_enable+0x80/0x98) > [ 52.410000] [<c011a194>] (__local_bh_enable) from [<c014a83c>] > (irq_forced_thread_fn+0x40/0x54) > [ 52.410000] [<c014a83c>] (irq_forced_thread_fn) from [<c014aa40>] > (irq_thread+0xf8/0x1d4) > [ 52.410000] [<c014aa40>] (irq_thread) from [<c0131674>] > (kthread+0x120/0x150) > [ 52.410000] [<c0131674>] (kthread) from [<c0107830>] > (ret_from_fork+0x14/0x24) > [ 52.410000] Code: e5983000 e1580003 08bd81f0 e7f001f2 (e7f001f2) > [ 52.410000] ---[ end trace 0000000000000002 ]--- > Sebastian
