2013-03-25 11:01:51

by Hector Palacios

[permalink] [raw]
Subject: BUG: soft lockup when recording audio on MX28EVK with ASoC sgtl5000

Hello,

I just tried recording audio on Freescale's MX28EVK that uses ASoC sgtl5000 (kernel
v3.8) with:

arecord -M -f cd sound.wav --duration 10

and got a scheduler message:

[ 789.041847] [sched_delayed] sched: RT throttling activated

The system then becomes nearly unresponsive and after some seconds the kernel
complains of a soft lockup.

[ 904.211821] BUG: soft lockup - CPU#0 stuck for 22s! [mdev:279]
[ 904.217693] Modules linked in:
[ 904.220776] irq event stamp: 1576636
[ 904.224363] hardirqs last enabled at (1576635): [<c000ee28>] __irq_svc+0x48/0x54
[ 904.231903] hardirqs last disabled at (1576636): [<c000ee14>] __irq_svc+0x34/0x54
[ 904.239422] softirqs last enabled at (1575782): [<c0026138>] __do_softirq+0x13c/0x220
[ 904.247388] softirqs last disabled at (1575771): [<c002630c>] irq_exit+0x8c/0x94
[ 904.254821]
[ 904.256328] Pid: 279, comm: mdev
[ 904.260967] CPU: 0 Not tainted (3.8.0-00041-gbdf34c0-dirty #49)
[ 904.267272] PC is at cpu_arm926_switch_mm+0x8/0x20
[ 904.272089] LR is at flush_old_exec+0x340/0x5c0
[ 904.276644] pc : [<c001a5c8>] lr : [<c00da6a0>] psr: 00000013
[ 904.276644] sp : c6f73e60 ip : 00000000 fp : c0634c10
[ 904.288138] r10: c779dd20 r9 : c77ac654 r8 : c779d5a0
[ 904.293378] r7 : c6f0ac00 r6 : c77ac400 r5 : c6f72000 r4 : c779dd20
[ 904.299918] r3 : 60000013 r2 : 00000000 r1 : c779d5a0 r0 : 46f7c000
[ 904.306461] Flags: nzcv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user
[ 904.313613] Control: 0005317f Table: 46f78000 DAC: 00000015
[ 904.319427] [<c001510c>] (unwind_backtrace+0x0/0xf4) from [<c006c4a8>]
(watchdog_timer_fn+0x124/0x160)
[ 904.328795] [<c006c4a8>] (watchdog_timer_fn+0x124/0x160) from [<c0042784>]
(__run_hrtimer+0x7c/0x1e8)
[ 904.338061] [<c0042784>] (__run_hrtimer+0x7c/0x1e8) from [<c0042c9c>]
(hrtimer_interrupt+0x110/0x310)
[ 904.347329] [<c0042c9c>] (hrtimer_interrupt+0x110/0x310) from [<c001ab80>]
(mxs_timer_interrupt+0x1c/0x2
8)
[ 904.357033] [<c001ab80>] (mxs_timer_interrupt+0x1c/0x28) from [<c006cb38>]
(handle_irq_event_percpu+0x5c
/0x26c)
[ 904.367169] [<c006cb38>] (handle_irq_event_percpu+0x5c/0x26c) from [<c006cd84>]
(handle_irq_event+0x3c/0
x5c)
[ 904.377039] [<c006cd84>] (handle_irq_event+0x3c/0x5c) from [<c006f3b0>]
(handle_level_irq+0x8c/0x118)
[ 904.386300] [<c006f3b0>] (handle_level_irq+0x8c/0x118) from [<c006cacc>]
(generic_handle_irq+0x28/0x30)
[ 904.395741] [<c006cacc>] (generic_handle_irq+0x28/0x30) from [<c001009c>]
(handle_IRQ+0x30/0x84)
[ 904.404568] [<c001009c>] (handle_IRQ+0x30/0x84) from [<c00086ec>]
(icoll_handle_irq+0x30/0x44)
[ 904.413220] [<c00086ec>] (icoll_handle_irq+0x30/0x44) from [<c000ee24>]
(__irq_svc+0x44/0x54)
[ 904.421761] Exception stack(0xc6f73e18 to 0xc6f73e60)
[ 904.426834] 3e00: 46f7c000
c779d5a0
[ 904.435043] 3e20: 00000000 60000013 c779dd20 c6f72000 c77ac400 c6f0ac00 c779d5a0
c77ac654
[ 904.443250] 3e40: c779dd20 c0634c10 00000000 c6f73e60 c00da6a0 c001a5c8 00000013
ffffffff
[ 904.451472] [<c000ee24>] (__irq_svc+0x44/0x54) from [<c001a5c8>]
(cpu_arm926_switch_mm+0x8/0x20)
[ 904.460298] [<c001a5c8>] (cpu_arm926_switch_mm+0x8/0x20) from [<c6e740c0>] (0xc6e740c0)
[ 936.211821] BUG: soft lockup - CPU#0 stuck for 21s! [arecord:264]
[ 936.217952] Modules linked in:
[ 936.221038] irq event stamp: 6749868
[ 936.224624] hardirqs last enabled at (6749867): [<c000ee28>] __irq_svc+0x48/0x54
[ 936.232163] hardirqs last disabled at (6749868): [<c000ee14>] __irq_svc+0x34/0x54
[ 936.239681] softirqs last enabled at (6749012): [<c0026138>] __do_softirq+0x13c/0x220
[ 936.247644] softirqs last disabled at (6748999): [<c002630c>] irq_exit+0x8c/0x94
[ 936.255077]
[ 936.256586] Pid: 264, comm: arecord
[ 936.261223] CPU: 0 Not tainted (3.8.0-00041-gbdf34c0-dirty #49)
[ 936.267528] PC is at cpu_arm926_switch_mm+0x8/0x20
[ 936.272352] LR is at T.1273+0xf4/0x150
[ 936.276125] pc : [<c001a5c8>] lr : [<c004c9d4>] psr: 00000013
[ 936.276125] sp : c6ed1d98 ip : 00000000 fp : c6ed1dc4
[ 936.287618] r10: c0455e0c r9 : c6ec91e0 r8 : 00000001
[ 936.292857] r7 : c7430000 r6 : 00000000 r5 : c062e870 r4 : c6ed0000
[ 936.299398] r3 : c6ec91e0 r2 : 20000013 r1 : c6ec91e0 r0 : 46ec4000
[ 936.305942] Flags: nzcv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user
[ 936.313092] Control: 0005317f Table: 4776c000 DAC: 00000015
[ 936.318906] [<c001510c>] (unwind_backtrace+0x0/0xf4) from [<c006c4a8>]
(watchdog_timer_fn+0x124/0x160)
[ 936.328273] [<c006c4a8>] (watchdog_timer_fn+0x124/0x160) from [<c0042784>]
(__run_hrtimer+0x7c/0x1e8)
[ 936.337539] [<c0042784>] (__run_hrtimer+0x7c/0x1e8) from [<c0042c9c>]
(hrtimer_interrupt+0x110/0x310)
[ 936.346806] [<c0042c9c>] (hrtimer_interrupt+0x110/0x310) from [<c001ab80>]
(mxs_timer_interrupt+0x1c/0x2
8)
[ 936.356509] [<c001ab80>] (mxs_timer_interrupt+0x1c/0x28) from [<c006cb38>]
(handle_irq_event_percpu+0x5c
/0x26c)
[ 936.366647] [<c006cb38>] (handle_irq_event_percpu+0x5c/0x26c) from [<c006cd84>]
(handle_irq_event+0x3c/0
x5c)
[ 936.376519] [<c006cd84>] (handle_irq_event+0x3c/0x5c) from [<c006f3b0>]
(handle_level_irq+0x8c/0x118)
[ 936.385781] [<c006f3b0>] (handle_level_irq+0x8c/0x118) from [<c006cacc>]
(generic_handle_irq+0x28/0x30)
[ 936.395222] [<c006cacc>] (generic_handle_irq+0x28/0x30) from [<c001009c>]
(handle_IRQ+0x30/0x84)
[ 936.404050] [<c001009c>] (handle_IRQ+0x30/0x84) from [<c00086ec>]
(icoll_handle_irq+0x30/0x44)
[ 936.412701] [<c00086ec>] (icoll_handle_irq+0x30/0x44) from [<c000ee24>]
(__irq_svc+0x44/0x54)
[ 936.421243] Exception stack(0xc6ed1d50 to 0xc6ed1d98)
[ 936.426320] 1d40: 46ec4000 c6ec91e0 20000013
c6ec91e0
[ 936.434527] 1d60: c6ed0000 c062e870 00000000 c7430000 00000001 c6ec91e0 c0455e0c
c6ed1dc4
[ 936.442727] 1d80: 00000000 c6ed1d98 c004c9d4 c001a5c8 00000013 ffffffff
[ 936.449389] [<c000ee24>] (__irq_svc+0x44/0x54) from [<c001a5c8>]
(cpu_arm926_switch_mm+0x8/0x20)
[ 936.458217] [<c001a5c8>] (cpu_arm926_switch_mm+0x8/0x20) from [<c6e303c0>] (0xc6e303c0)

The system does not completely die but it is extremely slow and almost unusable,
I checked that the mxs-saif interrupt (184) counter suddenly increased very quickly
(from 288 to 45427 in one second, 94471 the next second, and so on).
I was wondering if this happens in other platforms using this codec or if it is an MXS
issue only.

Best regards,
--
H?ctor Palacios


2013-03-25 12:10:58

by Marek Vasut

[permalink] [raw]
Subject: Re: BUG: soft lockup when recording audio on MX28EVK with ASoC sgtl5000

Dear Hector Palacios,

CCing Shawn, this might also explain the touchscreen issue.

> Hello,
>
> I just tried recording audio on Freescale's MX28EVK that uses ASoC sgtl5000
> (kernel v3.8) with:
>
> arecord -M -f cd sound.wav --duration 10
>
> and got a scheduler message:
>
> [ 789.041847] [sched_delayed] sched: RT throttling activated
>
> The system then becomes nearly unresponsive and after some seconds the
> kernel complains of a soft lockup.
>
> [ 904.211821] BUG: soft lockup - CPU#0 stuck for 22s! [mdev:279]
> [ 904.217693] Modules linked in:
> [ 904.220776] irq event stamp: 1576636
> [ 904.224363] hardirqs last enabled at (1576635): [<c000ee28>]
> __irq_svc+0x48/0x54 [ 904.231903] hardirqs last disabled at (1576636):
> [<c000ee14>] __irq_svc+0x34/0x54 [ 904.239422] softirqs last enabled at
> (1575782): [<c0026138>] __do_softirq+0x13c/0x220 [ 904.247388] softirqs
> last disabled at (1575771): [<c002630c>] irq_exit+0x8c/0x94 [ 904.254821]
> [ 904.256328] Pid: 279, comm: mdev
> [ 904.260967] CPU: 0 Not tainted (3.8.0-00041-gbdf34c0-dirty #49)
> [ 904.267272] PC is at cpu_arm926_switch_mm+0x8/0x20
> [ 904.272089] LR is at flush_old_exec+0x340/0x5c0
> [ 904.276644] pc : [<c001a5c8>] lr : [<c00da6a0>] psr: 00000013
> [ 904.276644] sp : c6f73e60 ip : 00000000 fp : c0634c10
> [ 904.288138] r10: c779dd20 r9 : c77ac654 r8 : c779d5a0
> [ 904.293378] r7 : c6f0ac00 r6 : c77ac400 r5 : c6f72000 r4 : c779dd20
> [ 904.299918] r3 : 60000013 r2 : 00000000 r1 : c779d5a0 r0 : 46f7c000
> [ 904.306461] Flags: nzcv IRQs on FIQs on Mode SVC_32 ISA ARM Segment
> user [ 904.313613] Control: 0005317f Table: 46f78000 DAC: 00000015
> [ 904.319427] [<c001510c>] (unwind_backtrace+0x0/0xf4) from [<c006c4a8>]
> (watchdog_timer_fn+0x124/0x160)
> [ 904.328795] [<c006c4a8>] (watchdog_timer_fn+0x124/0x160) from
> [<c0042784>] (__run_hrtimer+0x7c/0x1e8)
> [ 904.338061] [<c0042784>] (__run_hrtimer+0x7c/0x1e8) from [<c0042c9c>]
> (hrtimer_interrupt+0x110/0x310)
> [ 904.347329] [<c0042c9c>] (hrtimer_interrupt+0x110/0x310) from
> [<c001ab80>] (mxs_timer_interrupt+0x1c/0x2
> 8)
> [ 904.357033] [<c001ab80>] (mxs_timer_interrupt+0x1c/0x28) from
> [<c006cb38>] (handle_irq_event_percpu+0x5c
> /0x26c)
> [ 904.367169] [<c006cb38>] (handle_irq_event_percpu+0x5c/0x26c) from
> [<c006cd84>] (handle_irq_event+0x3c/0
> x5c)
> [ 904.377039] [<c006cd84>] (handle_irq_event+0x3c/0x5c) from [<c006f3b0>]
> (handle_level_irq+0x8c/0x118)
> [ 904.386300] [<c006f3b0>] (handle_level_irq+0x8c/0x118) from [<c006cacc>]
> (generic_handle_irq+0x28/0x30)
> [ 904.395741] [<c006cacc>] (generic_handle_irq+0x28/0x30) from
> [<c001009c>] (handle_IRQ+0x30/0x84)
> [ 904.404568] [<c001009c>] (handle_IRQ+0x30/0x84) from [<c00086ec>]
> (icoll_handle_irq+0x30/0x44)
> [ 904.413220] [<c00086ec>] (icoll_handle_irq+0x30/0x44) from [<c000ee24>]
> (__irq_svc+0x44/0x54)
> [ 904.421761] Exception stack(0xc6f73e18 to 0xc6f73e60)
> [ 904.426834] 3e00:
> 46f7c000 c779d5a0
> [ 904.435043] 3e20: 00000000 60000013 c779dd20 c6f72000 c77ac400 c6f0ac00
> c779d5a0 c77ac654
> [ 904.443250] 3e40: c779dd20 c0634c10 00000000 c6f73e60 c00da6a0 c001a5c8
> 00000013 ffffffff
> [ 904.451472] [<c000ee24>] (__irq_svc+0x44/0x54) from [<c001a5c8>]
> (cpu_arm926_switch_mm+0x8/0x20)
> [ 904.460298] [<c001a5c8>] (cpu_arm926_switch_mm+0x8/0x20) from
> [<c6e740c0>] (0xc6e740c0) [ 936.211821] BUG: soft lockup - CPU#0 stuck
> for 21s! [arecord:264] [ 936.217952] Modules linked in:
> [ 936.221038] irq event stamp: 6749868
> [ 936.224624] hardirqs last enabled at (6749867): [<c000ee28>]
> __irq_svc+0x48/0x54 [ 936.232163] hardirqs last disabled at (6749868):
> [<c000ee14>] __irq_svc+0x34/0x54 [ 936.239681] softirqs last enabled at
> (6749012): [<c0026138>] __do_softirq+0x13c/0x220 [ 936.247644] softirqs
> last disabled at (6748999): [<c002630c>] irq_exit+0x8c/0x94 [ 936.255077]
> [ 936.256586] Pid: 264, comm: arecord
> [ 936.261223] CPU: 0 Not tainted (3.8.0-00041-gbdf34c0-dirty #49)
> [ 936.267528] PC is at cpu_arm926_switch_mm+0x8/0x20
> [ 936.272352] LR is at T.1273+0xf4/0x150
> [ 936.276125] pc : [<c001a5c8>] lr : [<c004c9d4>] psr: 00000013
> [ 936.276125] sp : c6ed1d98 ip : 00000000 fp : c6ed1dc4
> [ 936.287618] r10: c0455e0c r9 : c6ec91e0 r8 : 00000001
> [ 936.292857] r7 : c7430000 r6 : 00000000 r5 : c062e870 r4 : c6ed0000
> [ 936.299398] r3 : c6ec91e0 r2 : 20000013 r1 : c6ec91e0 r0 : 46ec4000
> [ 936.305942] Flags: nzcv IRQs on FIQs on Mode SVC_32 ISA ARM Segment
> user [ 936.313092] Control: 0005317f Table: 4776c000 DAC: 00000015
> [ 936.318906] [<c001510c>] (unwind_backtrace+0x0/0xf4) from [<c006c4a8>]
> (watchdog_timer_fn+0x124/0x160)
> [ 936.328273] [<c006c4a8>] (watchdog_timer_fn+0x124/0x160) from
> [<c0042784>] (__run_hrtimer+0x7c/0x1e8)
> [ 936.337539] [<c0042784>] (__run_hrtimer+0x7c/0x1e8) from [<c0042c9c>]
> (hrtimer_interrupt+0x110/0x310)
> [ 936.346806] [<c0042c9c>] (hrtimer_interrupt+0x110/0x310) from
> [<c001ab80>] (mxs_timer_interrupt+0x1c/0x2
> 8)
> [ 936.356509] [<c001ab80>] (mxs_timer_interrupt+0x1c/0x28) from
> [<c006cb38>] (handle_irq_event_percpu+0x5c
> /0x26c)
> [ 936.366647] [<c006cb38>] (handle_irq_event_percpu+0x5c/0x26c) from
> [<c006cd84>] (handle_irq_event+0x3c/0
> x5c)
> [ 936.376519] [<c006cd84>] (handle_irq_event+0x3c/0x5c) from [<c006f3b0>]
> (handle_level_irq+0x8c/0x118)
> [ 936.385781] [<c006f3b0>] (handle_level_irq+0x8c/0x118) from [<c006cacc>]
> (generic_handle_irq+0x28/0x30)
> [ 936.395222] [<c006cacc>] (generic_handle_irq+0x28/0x30) from
> [<c001009c>] (handle_IRQ+0x30/0x84)
> [ 936.404050] [<c001009c>] (handle_IRQ+0x30/0x84) from [<c00086ec>]
> (icoll_handle_irq+0x30/0x44)
> [ 936.412701] [<c00086ec>] (icoll_handle_irq+0x30/0x44) from [<c000ee24>]
> (__irq_svc+0x44/0x54)
> [ 936.421243] Exception stack(0xc6ed1d50 to 0xc6ed1d98)
> [ 936.426320] 1d40: 46ec4000 c6ec91e0
> 20000013 c6ec91e0
> [ 936.434527] 1d60: c6ed0000 c062e870 00000000 c7430000 00000001 c6ec91e0
> c0455e0c c6ed1dc4
> [ 936.442727] 1d80: 00000000 c6ed1d98 c004c9d4 c001a5c8 00000013 ffffffff
> [ 936.449389] [<c000ee24>] (__irq_svc+0x44/0x54) from [<c001a5c8>]
> (cpu_arm926_switch_mm+0x8/0x20)
> [ 936.458217] [<c001a5c8>] (cpu_arm926_switch_mm+0x8/0x20) from
> [<c6e303c0>] (0xc6e303c0)
>
> The system does not completely die but it is extremely slow and almost
> unusable, I checked that the mxs-saif interrupt (184) counter suddenly
> increased very quickly (from 288 to 45427 in one second, 94471 the next
> second, and so on). I was wondering if this happens in other platforms
> using this codec or if it is an MXS issue only.
>
> Best regards,

Best regards,
Marek Vasut

2013-03-25 15:25:12

by Shawn Guo

[permalink] [raw]
Subject: Re: BUG: soft lockup when recording audio on MX28EVK with ASoC sgtl5000

On Mon, Mar 25, 2013 at 01:10:54PM +0100, Marek Vasut wrote:
> Dear Hector Palacios,
>
> CCing Shawn, this might also explain the touchscreen issue.
>
> > Hello,
> >
> > I just tried recording audio on Freescale's MX28EVK that uses ASoC sgtl5000
> > (kernel v3.8) with:
> >
> > arecord -M -f cd sound.wav --duration 10
> >
> > and got a scheduler message:
> >
> > [ 789.041847] [sched_delayed] sched: RT throttling activated

Hmm, I'm not sure if v3.8 is the first place where audio recording gets
broken. Does v3.7 even work for you?

Shawn

2013-03-25 16:53:59

by Hector Palacios

[permalink] [raw]
Subject: Re: BUG: soft lockup when recording audio on MX28EVK with ASoC sgtl5000

On 03/25/2013 04:25 PM, Shawn Guo wrote:
> On Mon, Mar 25, 2013 at 01:10:54PM +0100, Marek Vasut wrote:
>> Dear Hector Palacios,
>>
>> CCing Shawn, this might also explain the touchscreen issue.
>>
>>> Hello,
>>>
>>> I just tried recording audio on Freescale's MX28EVK that uses ASoC sgtl5000
>>> (kernel v3.8) with:
>>>
>>> arecord -M -f cd sound.wav --duration 10
>>>
>>> and got a scheduler message:
>>>
>>> [ 789.041847] [sched_delayed] sched: RT throttling activated
>
> Hmm, I'm not sure if v3.8 is the first place where audio recording gets
> broken. Does v3.7 even work for you?

No it doesn't. Same issue. Apparently a little different order (first the 'BUG soft
lockup', then the 'sched: RT throttling activated')

~# arecord -M -f cd sound.wav --duration 10
Recording WAVE 'sound.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
overrun!!! (at least 0.063 ms long)
[ 188.070000] BUG: soft lockup - CPU#0 stuck for 23s! [arecord:230]
[ 188.070000] Modules linked in:
[ 188.070000] irq event stamp: 2318718
[ 188.070000] hardirqs last enabled at (2318717): [<c000ee68>] __irq_svc+0x48/0x54
[ 188.070000] hardirqs last disabled at (2318718): [<c000ee54>] __irq_svc+0x34/0x54
[ 188.070000] softirqs last enabled at (2317860): [<c0025e98>] __do_softirq+0x13c/0x220
[ 188.070000] softirqs last disabled at (2317847): [<c002606c>] irq_exit+0x8c/0x94
[ 188.070000]
[ 188.070000] Pid: 230, comm: arecord
[ 188.070000] CPU: 0 Not tainted (3.7.0-00027-g46709ea-dirty #8)
[ 188.070000] PC is at __flush_whole_cache+0x4/0x18
[ 188.070000] LR is at unmap_kernel_range+0x10/0x2c
[ 188.070000] pc : [<c001a048>] lr : [<c00c30d4>] psr: 00000013
[ 188.070000] sp : cf7b3e68 ip : 00000000 fp : 00000000
[ 188.070000] r10: 00040000 r9 : cf6d4e00 r8 : c061a7dc
[ 188.070000] r7 : d0804000 r6 : d0940000 r5 : d0944000 r4 : d0940000
[ 188.070000] r3 : 20000008 r2 : 00000004 r1 : 00004000 r0 : d0940000
[ 188.070000] Flags: nzcv IRQs on FIQs on Mode SVC_32 ISA ARM Segment user
[ 188.070000] Control: 0005317f Table: 4ec2c000 DAC: 00000015
[ 188.070000] [<c00151ac>] (unwind_backtrace+0x0/0xf4) from [<c006bd84>]
(watchdog_timer_fn+0x128/0x168)
[ 188.070000] [<c006bd84>] (watchdog_timer_fn+0x128/0x168) from [<c00422cc>]
(__run_hrtimer+0x7c/0x1e8)
[ 188.070000] [<c00422cc>] (__run_hrtimer+0x7c/0x1e8) from [<c00427e4>]
(hrtimer_interrupt+0x110/0x310)
[ 188.070000] [<c00427e4>] (hrtimer_interrupt+0x110/0x310) from [<c001a780>]
(mxs_timer_interrupt+0x1c/0x28)
[ 188.070000] [<c001a780>] (mxs_timer_interrupt+0x1c/0x28) from [<c006c404>]
(handle_irq_event_percpu+0x5c/0x26c)
[ 188.070000] [<c006c404>] (handle_irq_event_percpu+0x5c/0x26c) from [<c006c650>]
(handle_irq_event+0x3c/0x5c)
[ 188.070000] [<c006c650>] (handle_irq_event+0x3c/0x5c) from [<c006ec14>]
(handle_level_irq+0x8c/0x118)
[ 188.070000] [<c006ec14>] (handle_level_irq+0x8c/0x118) from [<c006c398>]
(generic_handle_irq+0x28/0x30)
[ 188.070000] [<c006c398>] (generic_handle_irq+0x28/0x30) from [<c00100fc>]
(handle_IRQ+0x30/0x84)
[ 188.070000] [<c00100fc>] (handle_IRQ+0x30/0x84) from [<c00086ec>]
(icoll_handle_irq+0x30/0x44)
[ 188.070000] [<c00086ec>] (icoll_handle_irq+0x30/0x44) from [<c000ee64>]
(__irq_svc+0x44/0x54)
[ 188.070000] Exception stack(0xcf7b3e20 to 0xcf7b3e68)
[ 188.070000] 3e20: d0940000 00004000 00000004 20000008 d0940000 d0944000 d0940000
d0804000
[ 188.070000] 3e40: c061a7dc cf6d4e00 00040000 00000000 00000000 cf7b3e68 c00c30d4
c001a048
[ 188.070000] 3e60: 00000013 ffffffff
[ 188.070000] [<c000ee64>] (__irq_svc+0x44/0x54) from [<c001a048>]
(__flush_whole_cache+0x4/0x18)
[ 188.070000] [<c001a048>] (__flush_whole_cache+0x4/0x18) from [<cf76f900>] (0xcf76f900)
[ 215.620000] [sched_delayed] sched: RT throttling activated

--
H?ctor Palacios

2013-03-25 19:32:00

by Fabio Estevam

[permalink] [raw]
Subject: Re: BUG: soft lockup when recording audio on MX28EVK with ASoC sgtl5000

Hi Hector,

On Mon, Mar 25, 2013 at 7:52 AM, Hector Palacios
<[email protected]> wrote:
> Hello,
>
> I just tried recording audio on Freescale's MX28EVK that uses ASoC sgtl5000
> (kernel v3.8) with:
>
> arecord -M -f cd sound.wav --duration 10
>
> and got a scheduler message:
>
> [ 789.041847] [sched_delayed] sched: RT throttling activated

I have just tested arecord on 3.8,4 and I haven't seen the 'soft lockup' bug.

However, I see that mxs saif gets busy after the record and any
attempt to do an 'aplay' after the first arecord fails.

With the attached patch applied I am able to do arecord/aplay sequence
several times.

I don't have a cable handy here to actually test if the sound is
recorded properly or not.

Could you please test it against 3.8.4?

Thanks,

Fabio Estevam


Attachments:
0001-Do-not-check-busy.patch (2.68 kB)

2013-03-25 23:16:00

by Fabio Estevam

[permalink] [raw]
Subject: Re: BUG: soft lockup when recording audio on MX28EVK with ASoC sgtl5000

Hector,

On Mon, Mar 25, 2013 at 4:31 PM, Fabio Estevam <[email protected]> wrote:
> Hi Hector,
>
> On Mon, Mar 25, 2013 at 7:52 AM, Hector Palacios
> <[email protected]> wrote:
>> Hello,
>>
>> I just tried recording audio on Freescale's MX28EVK that uses ASoC sgtl5000
>> (kernel v3.8) with:
>>
>> arecord -M -f cd sound.wav --duration 10
>>
>> and got a scheduler message:
>>
>> [ 789.041847] [sched_delayed] sched: RT throttling activated
>
> I have just tested arecord on 3.8,4 and I haven't seen the 'soft lockup' bug.
>
> However, I see that mxs saif gets busy after the record and any
> attempt to do an 'aplay' after the first arecord fails.
>
> With the attached patch applied I am able to do arecord/aplay sequence
> several times.
>
> I don't have a cable handy here to actually test if the sound is
> recorded properly or not.
>
> Could you please test it against 3.8.4?

I managed to test arecord and it works with the following as follows:

1. Run alsamixer and select LINE_IN in the Capture element

2. Record with the following command line:

arecord -D hw:0,1 -d 10 -f S16_LE -r 44100 -c test.wav

3. Then listen test.wav on your PC or in your board itself.

The sequence above works fine.

Anyway, I will submit the patch I sent earlier as it prevents the
system to get unresponsive.

Regards,

Fabio Estevam

2013-03-26 11:50:19

by Hector Palacios

[permalink] [raw]
Subject: Re: BUG: soft lockup when recording audio on MX28EVK with ASoC sgtl5000

Hi Fabio,

On 03/26/2013 12:15 AM, Fabio Estevam wrote:
> Hector,
>
> On Mon, Mar 25, 2013 at 4:31 PM, Fabio Estevam <[email protected]> wrote:
>> Hi Hector,
>>
>> On Mon, Mar 25, 2013 at 7:52 AM, Hector Palacios
>> <[email protected]> wrote:
>>> Hello,
>>>
>>> I just tried recording audio on Freescale's MX28EVK that uses ASoC sgtl5000
>>> (kernel v3.8) with:
>>>
>>> arecord -M -f cd sound.wav --duration 10
>>>
>>> and got a scheduler message:
>>>
>>> [ 789.041847] [sched_delayed] sched: RT throttling activated
>>
>> I have just tested arecord on 3.8,4 and I haven't seen the 'soft lockup' bug.
>>
>> However, I see that mxs saif gets busy after the record and any
>> attempt to do an 'aplay' after the first arecord fails.
>>
>> With the attached patch applied I am able to do arecord/aplay sequence
>> several times.
>>
>> I don't have a cable handy here to actually test if the sound is
>> recorded properly or not.
>>
>> Could you please test it against 3.8.4?
>
> I managed to test arecord and it works with the following as follows:
>
> 1. Run alsamixer and select LINE_IN in the Capture element
>
> 2. Record with the following command line:
>
> arecord -D hw:0,1 -d 10 -f S16_LE -r 44100 -c test.wav

This command works on v3.8 even without your patch. I can arecord/aplay several times
without problems.

With my original command 'arecord [-M] -f cd sound.wav --duration 10', the soft lockup
appears both in v3.8 and v3.8.4 with and without your patch. So it looks like the
patch does not help here.

Regards,
--
Héctor Palacios