[Bug Report] SOUND: Kernel panic occurs when playback

[Bug Report] SOUND: Kernel panic occurs when playback

[Cao Minh Hiep]

Re: [Bug Report] PM: Warning messages -> [Bug Report] SOUND: Kernel 
panic occurs when playback

On 2015年05月13日 17:27, Cao Minh Hiep wrote:
> Hi Morimoto-san
>
> We are testing Linux upstream version-4.1-rc2 on Koelsch and Lager.
> We found a bug(kernel panic) on SOUND driver when Playback a sound file.
>
> The kernel panic logs is showed as below:
> "root@linaro-nano:~# aplay audio/Track\ 10.wav
> Playing WAVE 'audio/Track 10.wav' : Signed 16 bit Little Endian, Rate 
> 44100 Hz, Stereo
> Unable to handle kernel NULL pointer dereference at virtual address 
> 00000048
> pgd = edfac000
> [00000048] *pgdn0f0831, *pte\0000000, *ppte\0000000
> Internal error: Oops: 17 [#1] SMP ARM
> CPU: 0 PID: 2009 Comm: aplay Not tainted 4.1.0-rc2-dirty #4
> Hardware name: Generic R8A7790 (Flattened Device Tree)
> ..."
>
> Testing method:
> # amixer set "LINEOUT Mixer DACL" on
> # amixer set "DVC Out" 80%
> # amixer set "DVC In" 80%
> # aplay ./audio.wav
>
> We'd like to report this problem first.
> There are not this problem at version v4.0 stable.
> so we are looking for the error patch that added between v4.0 and 
> v4.1-rc2.
>
> Best Regards,
> Jinso/Cao Minh Hiep.
>
> ===========================> HERE IS LOG OF SOUND TEST:
>
> root@linaro-nano:~#
> root@linaro-nano:~#
> root@linaro-nano:~# amixer set "LINEOUT Mixer DACL" on
> Simple mixer control 'LINEOUT Mixer DACL',0
>   Capabilities: pswitch pswitch-joined
>   Playback channels: Mono
>   Mono: Playback [on]
> root@linaro-nano:~# amixer set "DVC Out" 80%
> Simple mixer control 'DVC Out',0
>   Capabilities: pvolume
>   Playback channels: Front Left - Front Right
>   Limits: Playback 0 - 8388607
>   Mono:
>   Front Left: Playback 6710886 [80%]
>   Front Right: Playback 6710886 [80%]
> root@linaro-nano:~# amixer set "DVC In" 80%
> Simple mixer control 'DVC In',0
>   Capabilities: cvolume
>   Capture channels: Front Left - Front Right
>   Limits: Capture 0 - 8388607
>   Front Left: Capture 6710886 [80%]
>   Front Right: Capture 6710886 [80%]
> root@linaro-nano:~#
> root@linaro-nano:~#
> root@linaro-nano:~#
> root@linaro-nano:~#
> root@linaro-nano:~# aplay
> aplay      aplaymidi
> root@linaro-nano:~# aplay audio/Track\ 10.wav
> Playing WAVE 'audio/Track 10.wav' : Signed 16 bit Little Endian, Rate 
> 44100 Hz, Stereo
> root@linaro-nano:~#
> root@linaro-nano:~# aplay audio/Track\ 10.wav
> Playing WAVE 'audio/Track 10.wav' : Signed 16 bit Little Endian, Rate 
> 44100 Hz, Stereo
> Unable to handle kernel NULL pointer dereference at virtual address 
> 00000048
> pgd = edfac000
> [00000048] *pgdn0f0831, *pte\0000000, *ppte\0000000
> Internal error: Oops: 17 [#1] SMP ARM
> CPU: 0 PID: 2009 Comm: aplay Not tainted 4.1.0-rc2-dirty #4
> Hardware name: Generic R8A7790 (Flattened Device Tree)
> task: eeac9040 ti: eebe8000 task.ti: eebe8000
> PC is at rsnd_get_adinr+0x28/0x60
> LR is at rsnd_src_ssiu_start+0xdc/0x19c
> pc : [<c0409790>]    lr : [<c040c068>]    psr: a0000193
> sp : eebe9e58  ip : eebe9e68  fp : eebe9e64
> r10: c06ed9d0  r9 : ee919d10  r8 : 00000001
> r7 : 00000001  r6 : ee1cb090  r5 : 00000000  r4 : edcaa418
> r3 : 00000000  r2 : eea8ce00  r1 : 80000193  r0 : edcaa418
> Flags: NzCv  IRQs off  FIQs on  Mode SVC_32  ISA ARM  Segment user
> Control: 10c5307d  Table: 6dfac06a  DAC: 00000015
> Process aplay (pid: 2009, stack limit = 0xeebe8210)
> Stack: (0xeebe9e58 to 0xeebea000)
> 9e40: eebe9e94 eebe9e68
> 9e60: c040c068 c0409774 00000000 eebe9e78 edcaa418 ee919d20 edcaa418 
> ee1cb090
> 9e80: 15014330 c06e5d34 eebe9eac eebe9e98 c040d510 c040bf98 eea8ce00 
> edcaa410
> 9ea0: eebe9edc eebe9eb0 c040d654 c040d4f8 c040d55c eeb27580 00000156 
> 00000000
> 9ec0: 00000000 ee91c880 00000008 c06ed9d0 eebe9f14 eebe9ee0 c005e9f0 
> c040d568
> 9ee0: ee427d48 ee427d98 00000000 ee91c880 ee91c8e0 c06b2be4 ee806000 
> 00000001
> 9f00: 00000008 00000000 eebe9f34 eebe9f18 c005eb34 c005e9c4 ee91c880 
> c06cfdc0
> 9f20: c06b2be4 ee806000 eebe9f4c eebe9f38 c0061a08 c005eaf4 00000156 
> 00000000
> 9f40: eebe9f64 eebe9f50 c005e318 c0061968 00000000 00000000 eebe9f8c 
> eebe9f68
> 9f60: c005e3b8 c005e2fc f0002000 c06b8784 eebe9fb0 10c5307d 10c5307d 
> 00000008
> 9f80: eebe9fac eebe9f90 c000a3b0 c005e334 b6f55520 60000030 ffffffff 
> 10c5307d
> 9fa0: 00000000 eebe9fb0 c0013f48 c000a378 00009235 b6f62eb2 00000069 
> 00000069
> 9fc0: b6f62ea4 00009233 00000000 a49b9752 b6f5bed0 00000008 00000000 
> b6f63d90
> 9fe0: 00000002 be9ac470 b6f4fc25 b6f55520 60000030 ffffffff ee3fc700 
> 00000000
> Backtrace:
> [<c0409768>] (rsnd_get_adinr) from [<c040c068>] 
> (rsnd_src_ssiu_start+0xdc/0x19c)
> [<c040bf8c>] (rsnd_src_ssiu_start) from [<c040d510>] 
> (rsnd_ssi_start+0x24/0x40)
>  r9:c06e5d34 r8:15014330 r7:ee1cb090 r6:edcaa418 r5:ee919d20 r4:edcaa418
> [<c040d4ec>] (rsnd_ssi_start) from [<c040d654>] 
> (rsnd_ssi_interrupt+0xf8/0x12c)
>  r5:edcaa410 r4:eea8ce00
> [<c040d55c>] (rsnd_ssi_interrupt) from [<c005e9f0>] 
> (handle_irq_event_percpu+0x38/0x130)
>  r10:c06ed9d0 r9:00000008 r8:ee91c880 r7:00000000 r6:00000000 r5:00000156
>  r4:eeb27580 r3:c040d55c
> [<c005e9b8>] (handle_irq_event_percpu) from [<c005eb34>] 
> (handle_irq_event+0x4c/0x6c)
>  r10:00000000 r9:00000008 r8:00000001 r7:ee806000 r6:c06b2be4 r5:ee91c8e0
>  r4:ee91c880
> [<c005eae8>] (handle_irq_event) from [<c0061a08>] 
> (handle_fasteoi_irq+0xac/0x134)
>  r7:ee806000 r6:c06b2be4 r5:c06cfdc0 r4:ee91c880
> [<c006195c>] (handle_fasteoi_irq) from [<c005e318>] 
> (generic_handle_irq+0x28/0x38)
>  r5:00000000 r4:00000156
> [<c005e2f0>] (generic_handle_irq) from [<c005e3b8>] 
> (__handle_domain_irq+0x90/0xb8)
>  r5:00000000 r4:00000000
> [<c005e328>] (__handle_domain_irq) from [<c000a3b0>] 
> (gic_handle_irq+0x44/0x64)
>  r9:00000008 r8:10c5307d r7:10c5307d r6:eebe9fb0 r5:c06b8784 r4:f0002000
> [<c000a36c>] (gic_handle_irq) from [<c0013f48>] (__irq_usr+0x48/0x60)
> Exception stack(0xeebe9fb0 to 0xeebe9ff8)
> 9fa0:                                     00009235 b6f62eb2 00000069 
> 00000069
> 9fc0: b6f62ea4 00009233 00000000 a49b9752 b6f5bed0 00000008 00000000 
> b6f63d90
> 9fe0: 00000002 be9ac470 b6f4fc25 b6f55520 60000030 ffffffff
>  r7:10c5307d r6:ffffffff r5:60000030 r4:b6f55520
> Code: e5922080 e3530000 159330a4 e5922000 (e5930048)
> ---[ end trace 267c4161094ae10b ]---
> Kernel panic - not syncing: Fatal exception in interrupt
> CPU2: stopping
> CPU: 2 PID: 0 Comm: swapper/2 Tainted: G      D 4.1.0-rc2-dirty #4
> Hardware name: Generic R8A7790 (Flattened Device Tree)
> Backtrace:
> [<c0012f50>] (dump_backtrace) from [<c00130f8>] (show_stack+0x18/0x1c)
>  r7:ee86dfac r6:00000000 r5:00000002 r4:00000000
> [<c00130e0>] (show_stack) from [<c04ff59c>] (dump_stack+0x78/0x94)
> [<c04ff524>] (dump_stack) from [<c00158f0>] (handle_IPI+0xd0/0x168)
>  r5:00000002 r4:c06f03ec
> [<c0015820>] (handle_IPI) from [<c000a3c8>] (gic_handle_irq+0x5c/0x64)
>  r7:ee86dfac r6:ee86df78 r5:c06b8784 r4:f0002000
> [<c000a36c>] (gic_handle_irq) from [<c0013c80>] (__irq_svc+0x40/0x54)
> Exception stack(0xee86df78 to 0xee86dfc0)
> df60: 00000000 00000000
> df80: 00006dae c001f880 c06b1304 c06b84fc ee86c000 c06f0418 4000406a 
> 413fc0f2
> dfa0: 00000000 ee86dfcc ee86dfd0 ee86dfc0 c001068c c0010690 60000013 
> ffffffff
>  r7:ee86dfac r6:ffffffff r5:60000013 r4:c0010690
> [<c001065c>] (arch_cpu_idle) from [<c00552c8>] 
> (cpu_startup_entry+0x188/0x1bc)
> [<c0055140>] (cpu_startup_entry) from [<c00155f4>] 
> (secondary_start_kernel+0x108/0x124)
> [<c00154ec>] (secondary_start_kernel) from [<4000a46c>] (0x4000a46c)
>  r5:00000015 r4:6e85406a
> CPU1: stopping
> CPU: 1 PID: 0 Comm: swapper/1 Tainted: G      D 4.1.0-rc2-dirty #4
> Hardware name: Generic R8A7790 (Flattened Device Tree)
> Backtrace:
> [<c0012f50>] (dump_backtrace) from [<c00130f8>] (show_stack+0x18/0x1c)
>  r7:ee86bfac r6:00000000 r5:00000001 r4:00000000
> [<c00130e0>] (show_stack) from [<c04ff59c>] (dump_stack+0x78/0x94)
> [<c04ff524>] (dump_stack) from [<c00158f0>] (handle_IPI+0xd0/0x168)
>  r5:00000001 r4:c06f03ec
> [<c0015820>] (handle_IPI) from [<c000a3c8>] (gic_handle_irq+0x5c/0x64)
>  r7:ee86bfac r6:ee86bf78 r5:c06b8784 r4:f0002000
> [<c000a36c>] (gic_handle_irq) from [<c0013c80>] (__irq_svc+0x40/0x54)
> Exception stack(0xee86bf78 to 0xee86bfc0)
> bf60: 00000000 00000000
> bf80: 000087f4 c001f880 c06b1304 c06b84fc ee86a000 c06f0418 4000406a 
> 413fc0f2
> bfa0: 00000000 ee86bfcc ee86bfd0 ee86bfc0 c001068c c0010690 60000013 
> ffffffff
>  r7:ee86bfac r6:ffffffff r5:60000013 r4:c0010690
> [<c001065c>] (arch_cpu_idle) from [<c00552c8>] 
> (cpu_startup_entry+0x188/0x1bc)
> [<c0055140>] (cpu_startup_entry) from [<c00155f4>] 
> (secondary_start_kernel+0x108/0x124)
> [<c00154ec>] (secondary_start_kernel) from [<4000a46c>] (0x4000a46c)
>  r5:00000015 r4:6e85406a
> CPU3: stopping
> CPU: 3 PID: 0 Comm: swapper/3 Tainted: G      D 4.1.0-rc2-dirty #4
> Hardware name: Generic R8A7790 (Flattened Device Tree)
> Backtrace:
> [<c0012f50>] (dump_backtrace) from [<c00130f8>] (show_stack+0x18/0x1c)
>  r7:ee86ffac r6:00000000 r5:00000003 r4:00000000
> [<c00130e0>] (show_stack) from [<c04ff59c>] (dump_stack+0x78/0x94)
> [<c04ff524>] (dump_stack) from [<c00158f0>] (handle_IPI+0xd0/0x168)
>  r5:00000003 r4:c06f03ec
> [<c0015820>] (handle_IPI) from [<c000a3c8>] (gic_handle_irq+0x5c/0x64)
>  r7:ee86ffac r6:ee86ff78 r5:c06b8784 r4:f0002000
> [<c000a36c>] (gic_handle_irq) from [<c0013c80>] (__irq_svc+0x40/0x54)
> Exception stack(0xee86ff78 to 0xee86ffc0)
> ff60: 00000000 00000000
> ff80: 0000509c c001f880 c06b1304 c06b84fc ee86e000 c06f0418 4000406a 
> 413fc0f2
> ffa0: 00000000 ee86ffcc ee86ffd0 ee86ffc0 c001068c c0010690 600c0013 
> ffffffff
>  r7:ee86ffac r6:ffffffff r5:600c0013 r4:c0010690
> [<c001065c>] (arch_cpu_idle) from [<c00552c8>] 
> (cpu_startup_entry+0x188/0x1bc)
> [<c0055140>] (cpu_startup_entry) from [<c00155f4>] 
> (secondary_start_kernel+0x108/0x124)
> [<c00154ec>] (secondary_start_kernel) from [<4000a46c>] (0x4000a46c)
>  r5:00000015 r4:6e85406a
> drm_kms_helper: panic occurred, switching back to text console
> ---[ end Kernel panic - not syncing: Fatal exception in interrupt
>
> -- 
> To unsubscribe from this list: send the line "unsubscribe linux-sh" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>
>

Re: [Bug Report] SOUND: Kernel panic occurs when playback

[Kuninori Morimoto]

Hi Hiep-san

> > We are testing Linux upstream version-4.1-rc2 on Koelsch and Lager.
> > We found a bug(kernel panic) on SOUND driver when Playback a sound file.
> >
> > The kernel panic logs is showed as below:
> > "root@linaro-nano:~# aplay audio/Track\ 10.wav
> > Playing WAVE 'audio/Track 10.wav' : Signed 16 bit Little Endian,
> > Rate 44100 Hz, Stereo
> > Unable to handle kernel NULL pointer dereference at virtual address
> > 00000048
> > pgd = edfac000
> > [00000048] *pgdn0f0831, *pte\0000000, *ppte\0000000
> > Internal error: Oops: 17 [#1] SMP ARM
> > CPU: 0 PID: 2009 Comm: aplay Not tainted 4.1.0-rc2-dirty #4
> > Hardware name: Generic R8A7790 (Flattened Device Tree)
> > ..."

Thank you for your report.
I will check it.

Re: [Bug Report] SOUND: Kernel panic occurs when playback

[Kuninori Morimoto]

Hi Laurent

Can I ask you about DMAEngine and spin_lock ?

> > > We are testing Linux upstream version-4.1-rc2 on Koelsch and Lager.
> > > We found a bug(kernel panic) on SOUND driver when Playback a sound file.
> > >
> > > The kernel panic logs is showed as below:
> > > "root@linaro-nano:~# aplay audio/Track\ 10.wav
> > > Playing WAVE 'audio/Track 10.wav' : Signed 16 bit Little Endian,
> > > Rate 44100 Hz, Stereo
> > > Unable to handle kernel NULL pointer dereference at virtual address
> > > 00000048
> > > pgd = edfac000
> > > [00000048] *pgdn0f0831, *pte\0000000, *ppte\0000000
> > > Internal error: Oops: 17 [#1] SMP ARM
> > > CPU: 0 PID: 2009 Comm: aplay Not tainted 4.1.0-rc2-dirty #4
> > > Hardware name: Generic R8A7790 (Flattened Device Tree)
> > > ..."

In my debug, this issue happens under DMAEngine,
and it depends on spin_lock (I think we talked this topic before...)
but I don't know which one is wrong, DMAEngine or Sound ?

Now, sound driver is calling DMAEngine API under spin_lock_irqsave

	spin_lock_irqsave(xxxx);
	...
	dmaengine_prep_dma_cyclic();
	...
	spin_unlock_irqrestore();

dmaengine_prep_dma_cyclic() does many things,
and it is using spin_unlock_irq().
It re-enabled sound interrupt before calling spin_unlock_irqrestore()

My question is which one is correct solution ??
 - sound driver shouldn't call DMAEngine API under spin_lock_irqsave() ?
 - DMAEngine driver should use spin_lock_irqsave() instead of spin_lock_irq() ?

Best regards
---
Kuninori Morimoto

Re: [Bug Report] SOUND: Kernel panic occurs when playback

[Laurent Pinchart]

Hi Morimoto-san,

On Friday 15 May 2015 08:32:39 Kuninori Morimoto wrote:
> Hi Laurent
> 
> Can I ask you about DMAEngine and spin_lock ?
> 
> > > > We are testing Linux upstream version-4.1-rc2 on Koelsch and Lager.
> > > > We found a bug(kernel panic) on SOUND driver when Playback a sound
> > > > file.
> > > > 
> > > > The kernel panic logs is showed as below:
> > > > "root@linaro-nano:~# aplay audio/Track\ 10.wav
> > > > Playing WAVE 'audio/Track 10.wav' : Signed 16 bit Little Endian,
> > > > Rate 44100 Hz, Stereo
> > > > Unable to handle kernel NULL pointer dereference at virtual address
> > > > 00000048
> > > > pgd = edfac000
> > > > [00000048] *pgdn0f0831, *pte\0000000, *ppte\0000000
> > > > Internal error: Oops: 17 [#1] SMP ARM
> > > > CPU: 0 PID: 2009 Comm: aplay Not tainted 4.1.0-rc2-dirty #4
> > > > Hardware name: Generic R8A7790 (Flattened Device Tree)
> > > > ..."
> 
> In my debug, this issue happens under DMAEngine,
> and it depends on spin_lock (I think we talked this topic before...)
> but I don't know which one is wrong, DMAEngine or Sound ?
> 
> Now, sound driver is calling DMAEngine API under spin_lock_irqsave
> 
> 	spin_lock_irqsave(xxxx);
> 	...
> 	dmaengine_prep_dma_cyclic();
> 	...
> 	spin_unlock_irqrestore();
> 
> dmaengine_prep_dma_cyclic() does many things,
> and it is using spin_unlock_irq().
> It re-enabled sound interrupt before calling spin_unlock_irqrestore()
> 
> My question is which one is correct solution ??
>  - sound driver shouldn't call DMAEngine API under spin_lock_irqsave() ?
>  - DMAEngine driver should use spin_lock_irqsave() instead of
> spin_lock_irq() ?

I'm sorry to have missed this e-mail. I've now replied to your patch series 
fixing the problem.

I believe the best solution would be to refactor the DMA engine API to make 
reuse of descriptors possible. That way drivers could allocate descriptors at 
initialization time in non-atomic context, and then use them in atomic 
contexts (including interrupt handlers) without requiring reallocation.

That's a longer term problem, and we need a fix now for the sound bug, so 
switching to spin_lock_irqsave() seems fine to me.

-- 
Regards,

Laurent Pinchart