[alsa-devel] ALSA hang on 4.13.0-rc7
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
On 2017.08.30 at 12:03 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
I've attached the output of "alsa-info.sh --no-upload".
On 2017.08.30 at 12:05 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 12:03 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
I've attached the output of "alsa-info.sh --no-upload".
With lock debugging on:
DEBUG_LOCKS_WARN_ON(depth <= 0) ------------[ cut here ]------------ WARNING: CPU: 0 PID: 494 at kernel/locking/lockdep.c:3617 lock_release+0x3bc/0x780 CPU: 0 PID: 494 Comm: mplayer Not tainted 4.13.0-rc7-00015-g36fde05f3fb5-dirty #58 Hardware name: System manufacturer System Product Name/M4A78T-E, BIOS 3503 04/13/2011 task: ffff880212943a80 task.stack: ffffc90000f98000 RIP: 0010:lock_release+0x3bc/0x780 RSP: 0018:ffffc90000f9bc80 EFLAGS: 00010082 RAX: 000000000000001f RBX: ffff88021515c400 RCX: 0000000000000000 RDX: ffffffff8111005e RSI: 0000000000000001 RDI: ffffffff820335a0 RBP: ffffc90000f9bcf8 R08: 0000000000000001 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000000 R12: ffff8802150d8b40 R13: ffffc90000f9bd18 R14: ffff880212943a80 R15: ffff880212943a80 FS: 00007f2f4d021780(0000) GS:ffff88021fc00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 000055b8dfaf4c10 CR3: 00000001e7d34000 CR4: 00000000000006f0 Call Trace: ? snd_pcm_drain+0x295/0x500 __mutex_unlock_slowpath+0x3e/0x2e0 ? snd_pcm_drain+0x282/0x500 mutex_unlock+0xd/0x20 snd_pcm_drain+0x295/0x500 ? do_task_dead+0x40/0x40 snd_pcm_kernel_ioctl+0x369/0x560 snd_pcm_oss_sync+0x53/0x480 snd_pcm_oss_ioctl+0x861/0x1700 ? mntput+0x8c/0x400 SyS_ioctl+0xa8/0x900 ? trace_hardirqs_on_thunk+0x1a/0x1c entry_SYSCALL_64_fastpath+0x18/0xad RIP: 0033:0x7f2f4dd76b07 RSP: 002b:00007ffe051df0b8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010 RAX: ffffffffffffffda RBX: 000055b8e2351a60 RCX: 00007f2f4dd76b07 RDX: 0000000000000000 RSI: 0000000000005001 RDI: 0000000000000004 RBP: 0000000000000003 R08: 00007f2f4de15af8 R09: 00007f2f4d021780 R10: 0000000000000059 R11: 0000000000000246 R12: 000055b8dfe94de0 R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000001000 Code: 2b c5 34 00 85 c0 48 8b 4d b8 74 25 44 8b 05 64 c2 f3 01 45 85 c0 75 19 48 c7 c6 8b 58 dd 81 48 c7 c7 8c 23 dd 81 e8 9d bd 00 00 <0f> ff 48 8b 4d b8 48 89 4d b8 e8 f5 c4 34 00 85 c0 0f 84 7f fe ---[ end trace 5f19aa03d29c4872 ]---
On Wed, 30 Aug 2017 12:03:34 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
Is this a regression?
Takashi
On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 12:03:34 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
Is this a regression?
Yes. 4.11 is fine.
On Wed, 30 Aug 2017 13:33:40 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 12:03:34 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
Is this a regression?
Yes. 4.11 is fine.
And 4.12?
Takashi
On 2017.08.30 at 13:34 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:33:40 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 12:03:34 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
Is this a regression?
Yes. 4.11 is fine.
And 4.12?
Just build it and yes 4.12 is fine, too.
(Before you ask, I have intention to bisect the issue. It would be too annoying with the all the required reboots.
But if you want I can run scripts/faddr2line on the backtraces.)
On Wed, 30 Aug 2017 13:42:41 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:34 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:33:40 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 12:03:34 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
Is this a regression?
Yes. 4.11 is fine.
And 4.12?
Just build it and yes 4.12 is fine, too.
(Before you ask, I have intention to bisect the issue. It would be too annoying with the all the required reboots.
That'd be really appreciated. We had lots of changes since 4.12 regarding PCM core stuff, so narrowing down would be a great help.
But if you want I can run scripts/faddr2line on the backtraces.)
Let's try to narrow at first a bit. For such a problem, the trace itself is often too late, not the cause itself.
thanks,
Takashi
On 2017.08.30 at 13:46 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:42:41 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:34 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:33:40 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 12:03:34 +0200, Markus Trippelsdorf wrote:
On my system ALSA sometimes hangs:
sysrq: SysRq : Show Blocked State task PC stack pid father output:ALSA def D 0 171 1 0x00000000 Call Trace: ? __schedule+0x17c/0x720 ? schedule_preempt_disabled+0x2d/0x80 ? __mutex_lock_slowpath+0x141/0x420 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_pcm_common_ioctl1+0x2f/0x1400 ? snd_card_file_remove+0x76/0x120 ? snd_pcm_playback_ioctl+0x1c7/0x560 ? dput+0xb6/0x1e0 ? SyS_ioctl+0xa7/0x860 ? task_work_run+0x70/0xa0 ? entry_SYSCALL_64_fastpath+0x13/0x94
Only a reboot will fix the issue.
Is this a regression?
The issue started with:
commit 68b4acd322494444803a3f49884ae889c8ec6689 (HEAD, refs/bisect/bad) Author: Takashi Iwai tiwai@suse.de Date: Tue May 24 15:07:39 2016 +0200
ALSA: pcm: Apply power lock globally to common ioctls
On Wed, 30 Aug 2017 14:26:51 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:46 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:42:41 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:34 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:33:40 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 12:03:34 +0200, Markus Trippelsdorf wrote: > > On my system ALSA sometimes hangs: > > sysrq: SysRq : Show Blocked State > task PC stack pid father > output:ALSA def D 0 171 1 0x00000000 > Call Trace: > ? __schedule+0x17c/0x720 > ? schedule_preempt_disabled+0x2d/0x80 > ? __mutex_lock_slowpath+0x141/0x420 > ? snd_pcm_common_ioctl1+0x2f/0x1400 > ? snd_pcm_common_ioctl1+0x2f/0x1400 > ? snd_card_file_remove+0x76/0x120 > ? snd_pcm_playback_ioctl+0x1c7/0x560 > ? dput+0xb6/0x1e0 > ? SyS_ioctl+0xa7/0x860 > ? task_work_run+0x70/0xa0 > ? entry_SYSCALL_64_fastpath+0x13/0x94 > > Only a reboot will fix the issue.
Is this a regression?
The issue started with:
commit 68b4acd322494444803a3f49884ae889c8ec6689 (HEAD, refs/bisect/bad) Author: Takashi Iwai tiwai@suse.de Date: Tue May 24 15:07:39 2016 +0200
ALSA: pcm: Apply power lock globally to common ioctls
Thanks, that looks fitting with your problem description. I'll take a deeper look.
Takashi
On Wed, 30 Aug 2017 14:33:36 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 14:26:51 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:46 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:42:41 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:34 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:33:40 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote: > On Wed, 30 Aug 2017 12:03:34 +0200, > Markus Trippelsdorf wrote: > > > > On my system ALSA sometimes hangs: > > > > sysrq: SysRq : Show Blocked State > > task PC stack pid father > > output:ALSA def D 0 171 1 0x00000000 > > Call Trace: > > ? __schedule+0x17c/0x720 > > ? schedule_preempt_disabled+0x2d/0x80 > > ? __mutex_lock_slowpath+0x141/0x420 > > ? snd_pcm_common_ioctl1+0x2f/0x1400 > > ? snd_pcm_common_ioctl1+0x2f/0x1400 > > ? snd_card_file_remove+0x76/0x120 > > ? snd_pcm_playback_ioctl+0x1c7/0x560 > > ? dput+0xb6/0x1e0 > > ? SyS_ioctl+0xa7/0x860 > > ? task_work_run+0x70/0xa0 > > ? entry_SYSCALL_64_fastpath+0x13/0x94 > > > > Only a reboot will fix the issue. > > Is this a regression?
The issue started with:
commit 68b4acd322494444803a3f49884ae889c8ec6689 (HEAD, refs/bisect/bad) Author: Takashi Iwai tiwai@suse.de Date: Tue May 24 15:07:39 2016 +0200
ALSA: pcm: Apply power lock globally to common ioctlsThanks, that looks fitting with your problem description. I'll take a deeper look.
Could you try the patch below?
thanks,
Takashi
-- 8< -- From: Takashi Iwai tiwai@suse.de Subject: [PATCH] ALSA: pcm: Fix power lock unbalance via OSS emulation
PCM OSS emulation issues the drain ioctl without power lock. It used to work in the earlier kernels as the power lock was taken inside snd_pcm_drain() itself. But since 68b4acd32249 ("ALSA: pcm: Apply power lock globally to common ioctls"), the power lock is taken outside the function. Due to that change, the call via OSS emulation leads to the unbalanced power lock, thus it deadlocks.
As a quick fix, just take the power lock before snd_pcm_drain() call for OSS emulation path. A better cleanup will follow later.
Fixes: 68b4acd32249 ("ALSA: pcm: Apply power lock globally to common ioctls") Reported-by: Markus Trippelsdorf markus@trippelsdorf.de Signed-off-by: Takashi Iwai tiwai@suse.de --- sound/core/pcm_native.c | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-)
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c index 22995cb3bd44..cf0433f80067 100644 --- a/sound/core/pcm_native.c +++ b/sound/core/pcm_native.c @@ -3064,6 +3064,7 @@ int snd_pcm_kernel_ioctl(struct snd_pcm_substream *substream, { snd_pcm_uframes_t *frames = arg; snd_pcm_sframes_t result; + int err; switch (cmd) { case SNDRV_PCM_IOCTL_FORWARD: @@ -3083,7 +3084,10 @@ int snd_pcm_kernel_ioctl(struct snd_pcm_substream *substream, case SNDRV_PCM_IOCTL_START: return snd_pcm_start_lock_irq(substream); case SNDRV_PCM_IOCTL_DRAIN: - return snd_pcm_drain(substream, NULL); + snd_power_lock(substream->pcm->card); + err = snd_pcm_drain(substream, NULL); + snd_power_unlock(substream->pcm->card); + return err; case SNDRV_PCM_IOCTL_DROP: return snd_pcm_drop(substream); case SNDRV_PCM_IOCTL_DELAY:
On 2017.08.30 at 14:56 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 14:33:36 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 14:26:51 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:46 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:42:41 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:34 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:33:40 +0200, Markus Trippelsdorf wrote: > > On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote: > > On Wed, 30 Aug 2017 12:03:34 +0200, > > Markus Trippelsdorf wrote: > > > > > > On my system ALSA sometimes hangs: > > > > > > sysrq: SysRq : Show Blocked State > > > task PC stack pid father > > > output:ALSA def D 0 171 1 0x00000000 > > > Call Trace: > > > ? __schedule+0x17c/0x720 > > > ? schedule_preempt_disabled+0x2d/0x80 > > > ? __mutex_lock_slowpath+0x141/0x420 > > > ? snd_pcm_common_ioctl1+0x2f/0x1400 > > > ? snd_pcm_common_ioctl1+0x2f/0x1400 > > > ? snd_card_file_remove+0x76/0x120 > > > ? snd_pcm_playback_ioctl+0x1c7/0x560 > > > ? dput+0xb6/0x1e0 > > > ? SyS_ioctl+0xa7/0x860 > > > ? task_work_run+0x70/0xa0 > > > ? entry_SYSCALL_64_fastpath+0x13/0x94 > > > > > > Only a reboot will fix the issue. > > > > Is this a regression?
The issue started with:
commit 68b4acd322494444803a3f49884ae889c8ec6689 (HEAD, refs/bisect/bad) Author: Takashi Iwai tiwai@suse.de Date: Tue May 24 15:07:39 2016 +0200
ALSA: pcm: Apply power lock globally to common ioctlsThanks, that looks fitting with your problem description. I'll take a deeper look.
Could you try the patch below?
Yes, it fixes the problem. Thanks.
On Wed, 30 Aug 2017 15:04:44 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 14:56 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 14:33:36 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 14:26:51 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:46 +0200, Takashi Iwai wrote:
On Wed, 30 Aug 2017 13:42:41 +0200, Markus Trippelsdorf wrote:
On 2017.08.30 at 13:34 +0200, Takashi Iwai wrote: > On Wed, 30 Aug 2017 13:33:40 +0200, > Markus Trippelsdorf wrote: > > > > On 2017.08.30 at 13:23 +0200, Takashi Iwai wrote: > > > On Wed, 30 Aug 2017 12:03:34 +0200, > > > Markus Trippelsdorf wrote: > > > > > > > > On my system ALSA sometimes hangs: > > > > > > > > sysrq: SysRq : Show Blocked State > > > > task PC stack pid father > > > > output:ALSA def D 0 171 1 0x00000000 > > > > Call Trace: > > > > ? __schedule+0x17c/0x720 > > > > ? schedule_preempt_disabled+0x2d/0x80 > > > > ? __mutex_lock_slowpath+0x141/0x420 > > > > ? snd_pcm_common_ioctl1+0x2f/0x1400 > > > > ? snd_pcm_common_ioctl1+0x2f/0x1400 > > > > ? snd_card_file_remove+0x76/0x120 > > > > ? snd_pcm_playback_ioctl+0x1c7/0x560 > > > > ? dput+0xb6/0x1e0 > > > > ? SyS_ioctl+0xa7/0x860 > > > > ? task_work_run+0x70/0xa0 > > > > ? entry_SYSCALL_64_fastpath+0x13/0x94 > > > > > > > > Only a reboot will fix the issue. > > > > > > Is this a regression?
The issue started with:
commit 68b4acd322494444803a3f49884ae889c8ec6689 (HEAD, refs/bisect/bad) Author: Takashi Iwai tiwai@suse.de Date: Tue May 24 15:07:39 2016 +0200
ALSA: pcm: Apply power lock globally to common ioctlsThanks, that looks fitting with your problem description. I'll take a deeper look.
Could you try the patch below?
Yes, it fixes the problem. Thanks.
Great, the fix is merged now. Will be included in the next pull request for 4.13-rc8 or final.
Thanks for a quick bisection and testing!
Takashi
participants (3)
-
Markus Trippelsdorf -
qTakashi Iwai -
Takashi Iwai