lock-up when loading desktop

Discussion:

Arthur Marsh

2014-10-13 01:00:40 UTC

I have been experiencing a lock-up situation on a dual-core P4 machine
since some time after kernel 3.17.0 was released.

After the lock-up, it takes a couple of reboots into a known good kernel
(3.17.0) to successfully boot as the corruption seems to hit the hard disks.

After doing a git-bisect I received the following result:

git bisect bad
257f8cce5d40b811d229ed71602882baa0012808 is the first bad commit
commit 257f8cce5d40b811d229ed71602882baa0012808
Author: Takashi Iwai <***@suse.de>
Date: Fri Aug 29 15:32:29 2014 +0200

ALSA: pcm: Allow nonatomic trigger operations

Currently, many PCM operations are performed in a critical section
protected by spinlock, typically the trigger and pointer callbacks are
assumed to be atomic. This is basically because some trigger action
(e.g. PCM stop after drain or xrun) is done in the interrupt handler.
If a driver runs in a threaded irq, however, this doesn't have to be
atomic. And many devices want to handle trigger in a non-atomic
context due to lengthy communications.

This patch tries all PCM calls operational in non-atomic context.
What it does is very simple: replaces the substream spinlock with the
corresponding substream mutex when pcm->nonatomic flag is set. The
driver that wants to use the non-atomic PCM ops just needs to set the
flag and keep the rest as is. (Of course, it must not handle any PCM
ops in irq context.)

Note that the code doesn't check whether it's atomic-safe or not, but
trust in 100% that the driver sets pcm->nonatomic correctly.

One possible problem is the case where linked PCM substreams have
inconsistent nonatomic states. For avoiding this, snd_pcm_link()
returns an error if one tries to link an inconsistent PCM substream.

Signed-off-by: Takashi Iwai <***@suse.de>

:040000 040000 e395bf17236b9d109745444ae818b2ecdc21f206
e002045c29bc96fe0a99c81db9c905db04e87e03 M include
:040000 040000 44044ea9f3c2aacbd488524c060554256c2b2ceb
77d1a1e452b9321876f9e1a8f6926f11814a9cd9 M sound

git bisect log
git bisect start
# bad: [ca321885b0511a85e2d1cd40caafedbeb18f4af6] Merge
git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
git bisect bad ca321885b0511a85e2d1cd40caafedbeb18f4af6
# good: [bfe01a5ba2490f299e1d2d5508cbbbadd897bbe9] Linux 3.17
git bisect good bfe01a5ba2490f299e1d2d5508cbbbadd897bbe9
# good: [f86dc4b04dd5292cae3708c16ca6e46dbb5c95fa] Merge tag
'defconfig-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
git bisect good f86dc4b04dd5292cae3708c16ca6e46dbb5c95fa
# good: [5e5f6dc10546f5c03bc572e3ba3089af30c66e2d] arm64: mm: enable
HAVE_RCU_TABLE_FREE logic
git bisect good 5e5f6dc10546f5c03bc572e3ba3089af30c66e2d
# good: [4d9708ea5e5a45973df7cf965805fdfb185dd5bf] Merge tag
'media/v3.18-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media
git bisect good 4d9708ea5e5a45973df7cf965805fdfb185dd5bf
# bad: [e98d6e7f7625ed60c7bc1d39aeb2375ed3918fd5] Merge tag
'devicetree-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/glikely/linux
git bisect bad e98d6e7f7625ed60c7bc1d39aeb2375ed3918fd5
# good: [bdf20b4291eaa3b327398b8dd330065ad8e6d3ce] Merge remote-tracking
branches 'asoc/fix/88pm860x', 'asoc/fix/fsl', 'asoc/fix/imx',
'asoc/fix/mc13783', 'asoc/fix/rockchip' and 'asoc/fix/simple' into
asoc-linus
git bisect good bdf20b4291eaa3b327398b8dd330065ad8e6d3ce
# good: [3db3525196a992da628fb210776d73ec4bb59460] mmc: sdhci-acpi: Get
UID directly from acpi_device
git bisect good 3db3525196a992da628fb210776d73ec4bb59460
# bad: [3d0fdc86e4b500dfcfbf2f68039d2d6853536c2e] ALSA: ctxfi: added
reference of snd_card
git bisect bad 3d0fdc86e4b500dfcfbf2f68039d2d6853536c2e
# bad: [7fd4394dfe1db02ba904dfa1048f718cbca822d1] Merge branch
'topic/pcm-nonatomic' into for-next
git bisect bad 7fd4394dfe1db02ba904dfa1048f718cbca822d1
# good: [c77900e63abd9e2bdf385ba846a22858a0ed50a7] ALSA: hda/realtek -
move DELL2_MIC_NO_PRESENCE quirk for alc255
git bisect good c77900e63abd9e2bdf385ba846a22858a0ed50a7
# good: [d89c6c0c91af0344b52dd21ca48dd29821fee677] ALSA: hda - Add
TLV_DB_SCALE_MUTE bit for relevant controls
git bisect good d89c6c0c91af0344b52dd21ca48dd29821fee677
# good: [dd38dc1a9bf780b619ab93b3d7a5e90ebad441f5] ALSA: virtuoso: add
one more headphone impedance setting
git bisect good dd38dc1a9bf780b619ab93b3d7a5e90ebad441f5
# bad: [7af142f752116e86adbe2073f2922d8265a77709] ALSA: pcm: Uninline
snd_pcm_stream_lock() and _unlock()
git bisect bad 7af142f752116e86adbe2073f2922d8265a77709
# bad: [257f8cce5d40b811d229ed71602882baa0012808] ALSA: pcm: Allow
nonatomic trigger operations
git bisect bad 257f8cce5d40b811d229ed71602882baa0012808
# first bad commit: [257f8cce5d40b811d229ed71602882baa0012808] ALSA:
pcm: Allow nonatomic trigger operations

The problem still exists with the Linus git head as of earlier today,
but only seems to get triggered when loading the desktop (which is
actually an ancient KDE 3.51 with a library recompiled to work with
newer kernels).

The soundcard on the machine is:

00:0a.0 Multimedia audio controller: Creative Labs SB Audigy (rev 04)
Subsystem: Creative Labs SB Audigy 2 ZS (SB0350)
Flags: bus master, medium devsel, latency 32, IRQ 18
I/O ports at 8400 [size=64]
Capabilities: <access denied>
Kernel driver in use: snd_emu10k1

00:0a.1 Input device controller: Creative Labs SB Audigy Game Port (rev 04)
Subsystem: Creative Labs SB Audigy Game Port
Flags: bus master, medium devsel, latency 32
I/O ports at 8000 [size=8]
Capabilities: <access denied>
Kernel driver in use: Emu10k1_gameport

00:0a.2 FireWire (IEEE 1394): Creative Labs SB Audigy FireWire Port (rev
04) (prog-if 10 [OHCI])
Subsystem: Creative Labs SB Audigy FireWire Port
Flags: bus master, medium devsel, latency 32, IRQ 19
Memory at bc800000 (32-bit, non-prefetchable) [size=2K]
Memory at bc000000 (32-bit, non-prefetchable) [size=16K]
Capabilities: <access denied>
Kernel driver in use: firewire_ohci

I have not looked at the "first bad patch", only built against it.

I am happy to supply further build and machine details, and run extra
tests to help identify the problem.

Takashi Iwai

2014-10-13 06:00:37 UTC

Permalink

At Mon, 13 Oct 2014 11:30:40 +1030,

Post by Arthur Marsh
I have been experiencing a lock-up situation on a dual-core P4 machine
since some time after kernel 3.17.0 was released.
After the lock-up, it takes a couple of reboots into a known good kernel
(3.17.0) to successfully boot as the corruption seems to hit the hard disks.
git bisect bad
257f8cce5d40b811d229ed71602882baa0012808 is the first bad commit
commit 257f8cce5d40b811d229ed71602882baa0012808
Date: Fri Aug 29 15:32:29 2014 +0200
ALSA: pcm: Allow nonatomic trigger operations
Currently, many PCM operations are performed in a critical section
protected by spinlock, typically the trigger and pointer callbacks are
assumed to be atomic. This is basically because some trigger action
(e.g. PCM stop after drain or xrun) is done in the interrupt handler.
If a driver runs in a threaded irq, however, this doesn't have to be
atomic. And many devices want to handle trigger in a non-atomic
context due to lengthy communications.
This patch tries all PCM calls operational in non-atomic context.
What it does is very simple: replaces the substream spinlock with the
corresponding substream mutex when pcm->nonatomic flag is set. The
driver that wants to use the non-atomic PCM ops just needs to set the
flag and keep the rest as is. (Of course, it must not handle any PCM
ops in irq context.)
Note that the code doesn't check whether it's atomic-safe or not, but
trust in 100% that the driver sets pcm->nonatomic correctly.
One possible problem is the case where linked PCM substreams have
inconsistent nonatomic states. For avoiding this, snd_pcm_link()
returns an error if one tries to link an inconsistent PCM substream.
:040000 040000 e395bf17236b9d109745444ae818b2ecdc21f206
e002045c29bc96fe0a99c81db9c905db04e87e03 M include
:040000 040000 44044ea9f3c2aacbd488524c060554256c2b2ceb
77d1a1e452b9321876f9e1a8f6926f11814a9cd9 M sound
git bisect log
git bisect start
# bad: [ca321885b0511a85e2d1cd40caafedbeb18f4af6] Merge
git://git.kernel.org/pub/scm/linux/kernel/git/davem/net
git bisect bad ca321885b0511a85e2d1cd40caafedbeb18f4af6
# good: [bfe01a5ba2490f299e1d2d5508cbbbadd897bbe9] Linux 3.17
git bisect good bfe01a5ba2490f299e1d2d5508cbbbadd897bbe9
# good: [f86dc4b04dd5292cae3708c16ca6e46dbb5c95fa] Merge tag
'defconfig-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
git bisect good f86dc4b04dd5292cae3708c16ca6e46dbb5c95fa
# good: [5e5f6dc10546f5c03bc572e3ba3089af30c66e2d] arm64: mm: enable
HAVE_RCU_TABLE_FREE logic
git bisect good 5e5f6dc10546f5c03bc572e3ba3089af30c66e2d
# good: [4d9708ea5e5a45973df7cf965805fdfb185dd5bf] Merge tag
'media/v3.18-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media
git bisect good 4d9708ea5e5a45973df7cf965805fdfb185dd5bf
# bad: [e98d6e7f7625ed60c7bc1d39aeb2375ed3918fd5] Merge tag
'devicetree-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/glikely/linux
git bisect bad e98d6e7f7625ed60c7bc1d39aeb2375ed3918fd5
# good: [bdf20b4291eaa3b327398b8dd330065ad8e6d3ce] Merge remote-tracking
branches 'asoc/fix/88pm860x', 'asoc/fix/fsl', 'asoc/fix/imx',
'asoc/fix/mc13783', 'asoc/fix/rockchip' and 'asoc/fix/simple' into
asoc-linus
git bisect good bdf20b4291eaa3b327398b8dd330065ad8e6d3ce
# good: [3db3525196a992da628fb210776d73ec4bb59460] mmc: sdhci-acpi: Get
UID directly from acpi_device
git bisect good 3db3525196a992da628fb210776d73ec4bb59460
# bad: [3d0fdc86e4b500dfcfbf2f68039d2d6853536c2e] ALSA: ctxfi: added
reference of snd_card
git bisect bad 3d0fdc86e4b500dfcfbf2f68039d2d6853536c2e
# bad: [7fd4394dfe1db02ba904dfa1048f718cbca822d1] Merge branch
'topic/pcm-nonatomic' into for-next
git bisect bad 7fd4394dfe1db02ba904dfa1048f718cbca822d1
# good: [c77900e63abd9e2bdf385ba846a22858a0ed50a7] ALSA: hda/realtek -
move DELL2_MIC_NO_PRESENCE quirk for alc255
git bisect good c77900e63abd9e2bdf385ba846a22858a0ed50a7
# good: [d89c6c0c91af0344b52dd21ca48dd29821fee677] ALSA: hda - Add
TLV_DB_SCALE_MUTE bit for relevant controls
git bisect good d89c6c0c91af0344b52dd21ca48dd29821fee677
# good: [dd38dc1a9bf780b619ab93b3d7a5e90ebad441f5] ALSA: virtuoso: add
one more headphone impedance setting
git bisect good dd38dc1a9bf780b619ab93b3d7a5e90ebad441f5
# bad: [7af142f752116e86adbe2073f2922d8265a77709] ALSA: pcm: Uninline
snd_pcm_stream_lock() and _unlock()
git bisect bad 7af142f752116e86adbe2073f2922d8265a77709
# bad: [257f8cce5d40b811d229ed71602882baa0012808] ALSA: pcm: Allow
nonatomic trigger operations
git bisect bad 257f8cce5d40b811d229ed71602882baa0012808
pcm: Allow nonatomic trigger operations
The problem still exists with the Linus git head as of earlier today,
but only seems to get triggered when loading the desktop (which is
actually an ancient KDE 3.51 with a library recompiled to work with
newer kernels).
00:0a.0 Multimedia audio controller: Creative Labs SB Audigy (rev 04)
Subsystem: Creative Labs SB Audigy 2 ZS (SB0350)
Flags: bus master, medium devsel, latency 32, IRQ 18
I/O ports at 8400 [size=64]
Capabilities: <access denied>
Kernel driver in use: snd_emu10k1
00:0a.1 Input device controller: Creative Labs SB Audigy Game Port (rev 04)
Subsystem: Creative Labs SB Audigy Game Port
Flags: bus master, medium devsel, latency 32
I/O ports at 8000 [size=8]
Capabilities: <access denied>
Kernel driver in use: Emu10k1_gameport
00:0a.2 FireWire (IEEE 1394): Creative Labs SB Audigy FireWire Port (rev
04) (prog-if 10 [OHCI])
Subsystem: Creative Labs SB Audigy FireWire Port
Flags: bus master, medium devsel, latency 32, IRQ 19
Memory at bc800000 (32-bit, non-prefetchable) [size=2K]
Memory at bc000000 (32-bit, non-prefetchable) [size=16K]
Capabilities: <access denied>
Kernel driver in use: firewire_ohci
I have not looked at the "first bad patch", only built against it.
I am happy to supply further build and machine details, and run extra
tests to help identify the problem.

So you have only emu10k1 as the sound card? At best, give
alsa-info.sh output. I've tested emu10k1 on my machine for long time,
so it's strange that such a problem happens.

Unfortunately, I'm traveling in the whole this week, so cannot debug
so much locally with the machine.

In anyway, please make sure that the sound driver is really the
culprit. For example, add the sound driver modules to blacklist, boot
and confirm that the boot works. Then remove the blacklist again and
reconfirm that the boot hangs.

Once when you confirm it, try to revert two commits:
7af142f752116e86adbe2073f2922d8265a77709
257f8cce5d40b811d229ed71602882baa0012808

Let me know whether this makes booting again.

thanks,

Takashi

Takashi Iwai

2014-10-13 12:40:15 UTC

Permalink

At Mon, 13 Oct 2014 22:06:34 +1030,

Post by Takashi Iwai
At Mon, 13 Oct 2014 11:30:40 +1030,
So you have only emu10k1 as the sound card? At best, give
alsa-info.sh output. I've tested emu10k1 on my machine for long time,
so it's strange that such a problem happens.
Unfortunately, I'm traveling in the whole this week, so cannot debug
so much locally with the machine.
In anyway, please make sure that the sound driver is really the
culprit. For example, add the sound driver modules to blacklist, boot
and confirm that the boot works. Then remove the blacklist again and
reconfirm that the boot hangs.
7af142f752116e86adbe2073f2922d8265a77709
257f8cce5d40b811d229ed71602882baa0012808
Let me know whether this makes booting again.
thanks,
Takashi

Obtain alsa-info.sh output from my working 3.17.0 kernel set-up;
Boot into 3.17.0+ and attempt to run alsa-info.sh - dumps occurred as
shown in attached photos, even corrupted the machine's BIOS;
Attempt to blacklist sound drivers, ran 3.17.0+ without lock-up,
obtained alsa-info.sh output;
Applied 2 reversions listed above to current 3.17.0+ Linus git head, had
to remove a few other sound cards from the menuconfig to let the kernel
build, removed blacklisting and rebooted into kernel with reversions
applied.
Ran alsa-info.sh and received dmesg output as shown below, was able to
bring up the desktop session without lock-up.

OK, then could you check whether reverting only the last one (of two)
does *NOT* fix the issue? I think it shouldn't, but let us confirm.

The alsa-info.sh shows the lockdep messages. I assume that it's seen
even before 3.17+?

Last but not least, please check whether nonatomic flag is set wrongly
by some reason like the patch below. (Check the kernel message after
boot or try to playback some PCM).

Takashi

---
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index 85fe1a216225..9c7cbd1b839e 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -2275,6 +2275,9 @@ static int snd_pcm_open(struct file *file, struct snd_pcm *pcm, int stream)
int err;
wait_queue_t wait;

+ if (WARN_ON(pcm->nonatomic))
+ return -EINVAL;
+
if (pcm == NULL) {
err = -ENODEV;
goto __error1;

Arthur Marsh

2014-10-13 13:04:41 UTC

Permalink

Post by Takashi Iwai
OK, then could you check whether reverting only the last one (of two)
does *NOT* fix the issue? I think it shouldn't, but let us confirm.

Thanks for the feedback. Sorry, I'm not good on git commands. Having
applied the two reversions previously, how do I get my git tree back to
the same state as Linus' git head (ie undo the reversions)?

I could then apply the second reversion only and test that.

Post by Takashi Iwai
The alsa-info.sh shows the lockdep messages. I assume that it's seen
even before 3.17+?

I didn't see ALSA-related lockdep messages in 3.17.0 or earlier, and
have had the lockdep validator option enabled on kernels for several
months now.

Post by Takashi Iwai
Last but not least, please check whether nonatomic flag is set wrongly
by some reason like the patch below. (Check the kernel message after
boot or try to playback some PCM).
Takashi
---
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index 85fe1a216225..9c7cbd1b839e 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -2275,6 +2275,9 @@ static int snd_pcm_open(struct file *file, struct snd_pcm *pcm, int stream)
int err;
wait_queue_t wait;
+ if (WARN_ON(pcm->nonatomic))
+ return -EINVAL;
+
if (pcm == NULL) {
err = -ENODEV;
goto __error1;

I can apply this patch, but I'm not entirely sure how to check for the
state of the nonatomic flag.

Regards,

Arthur.

Takashi Iwai

2014-10-13 14:25:18 UTC

Permalink

At Mon, 13 Oct 2014 23:34:41 +1030,

Post by Arthur Marsh

Post by Takashi Iwai
OK, then could you check whether reverting only the last one (of two)
does *NOT* fix the issue? I think it shouldn't, but let us confirm.

Suppose your tree is now with two reverts, just run "git reset --hard
HEAD~". Then it goes back in a single commit.

Post by Arthur Marsh
I could then apply the second reversion only and test that.

Post by Takashi Iwai
The alsa-info.sh shows the lockdep messages. I assume that it's seen
even before 3.17+?

I didn't see ALSA-related lockdep messages in 3.17.0 or earlier, and
have had the lockdep validator option enabled on kernels for several
months now.

OK, so it's a new message. But this appears after you reverted two
commits, right? Then the lock code base in sound core should be
identical with 3.17. Strange. Do you see anything when you run

git diff v3.17.. sound/core/pcm_native.c

on the tree with two reverts?

Post by Arthur Marsh

I can apply this patch, but I'm not entirely sure how to check for the
state of the nonatomic flag.

If it were wrongly set, the PCM open would show the kernel warning and
abort immediately, so you'll notice soon.

One more test would be to check the direct merge to 3.17 as I've
tested.

- Go to git tree, check out some branch
% git checkout -b sound-test

- Reset to vanilla 3.17
% git reset --hard v3.17

- Merge only the sound changes onto it
% git merge fd1a2a90d08b0052fa52bd36cebd0592c9e537c2

Give any merge messages as you like.

- Compile and retest whether the same problem happens with this one.

thanks!

Takashi

Takashi Iwai

2014-10-13 20:57:59 UTC

Permalink

At Tue, 14 Oct 2014 04:38:58 +1030,

Post by Takashi Iwai
At Mon, 13 Oct 2014 23:34:41 +1030,

Post by Arthur Marsh

Post by Takashi Iwai
OK, then could you check whether reverting only the last one (of two)
does *NOT* fix the issue? I think it shouldn't, but let us confirm.

Suppose your tree is now with two reverts, just run "git reset --hard
HEAD~". Then it goes back in a single commit.

Post by Arthur Marsh
I could then apply the second reversion only and test that.

Post by Takashi Iwai
The alsa-info.sh shows the lockdep messages. I assume that it's seen
even before 3.17+?

I didn't see ALSA-related lockdep messages in 3.17.0 or earlier, and
have had the lockdep validator option enabled on kernels for several
months now.

OK, so it's a new message. But this appears after you reverted two
commits, right? Then the lock code base in sound core should be
identical with 3.17. Strange. Do you see anything when you run
git diff v3.17.. sound/core/pcm_native.c
on the tree with two reverts?

Post by Arthur Marsh

I can apply this patch, but I'm not entirely sure how to check for the
state of the nonatomic flag.

If it were wrongly set, the PCM open would show the kernel warning and
abort immediately, so you'll notice soon.
One more test would be to check the direct merge to 3.17 as I've
tested.
- Go to git tree, check out some branch
% git checkout -b sound-test
- Reset to vanilla 3.17
% git reset --hard v3.17
- Merge only the sound changes onto it
% git merge fd1a2a90d08b0052fa52bd36cebd0592c9e537c2
Give any merge messages as you like.
- Compile and retest whether the same problem happens with this one.
thanks!
Takashi

Wait... which patch is this? Could you test without this (but with
the patch below)?

I then rebuilt that kernel, and installed it.
It booted and played its start-up sound of a MIDI file fine, but when I
attempted to run alsa-info.sh it locked up (see first photo), and after
aplay some-file.wav
had a similar lock-up (see second photo)

I looked at the relevant code now, and this indeed seems like a
deadlock. But it's nothing new, the code is a decade old. I wonder
why it appears out of sudden. Maybe the change of the spin lock path
triggers.

The patch below is the fix, just removing the superfluous spinlock.

I can supply a dmesg output of the machine with the test kernel before
attempting anything that might cause a lock-up if it's of use to you.
PS, how do I get my git repositary out of "sound-test" branch and return
to Linus' git head?

Just do "git checkout master"

Takashi

---
diff --git a/sound/pci/emu10k1/emu10k1_callback.c b/sound/pci/emu10k1/emu10k1_callback.c
index 3f3ef38d9b6e..874cd76c7b7f 100644
--- a/sound/pci/emu10k1/emu10k1_callback.c
+++ b/sound/pci/emu10k1/emu10k1_callback.c
@@ -85,6 +85,8 @@ snd_emu10k1_ops_setup(struct snd_emux *emux)
* get more voice for pcm
*
* terminate most inactive voice and give it as a pcm voice.
+ *
+ * voice_lock is already held.
*/
int
snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
@@ -92,12 +94,10 @@ snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
struct snd_emux *emu;
struct snd_emux_voice *vp;
struct best_voice best[V_END];
- unsigned long flags;
int i;

emu = hw->synth;

- spin_lock_irqsave(&emu->voice_lock, flags);
lookup_voices(emu, hw, best, 1); /* no OFF voices */
for (i = 0; i < V_END; i++) {
if (best[i].voice >= 0) {
@@ -113,11 +113,9 @@ snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
vp->emu->num_voices--;
vp->ch = -1;
vp->state = SNDRV_EMUX_ST_OFF;
- spin_unlock_irqrestore(&emu->voice_lock, flags);
return ch;
}
}
- spin_unlock_irqrestore(&emu->voice_lock, flags);

/* not found */
return -ENOMEM;

Takashi Iwai

2014-10-13 21:14:14 UTC

Permalink

At Mon, 13 Oct 2014 22:57:59 +0200,

Post by Takashi Iwai
At Tue, 14 Oct 2014 04:38:58 +1030,

Post by Takashi Iwai
At Mon, 13 Oct 2014 23:34:41 +1030,

Post by Arthur Marsh

Post by Takashi Iwai
OK, then could you check whether reverting only the last one (of two)
does *NOT* fix the issue? I think it shouldn't, but let us confirm.

Suppose your tree is now with two reverts, just run "git reset --hard
HEAD~". Then it goes back in a single commit.

Post by Arthur Marsh
I could then apply the second reversion only and test that.

Post by Takashi Iwai
The alsa-info.sh shows the lockdep messages. I assume that it's seen
even before 3.17+?

I didn't see ALSA-related lockdep messages in 3.17.0 or earlier, and
have had the lockdep validator option enabled on kernels for several
months now.

OK, so it's a new message. But this appears after you reverted two
commits, right? Then the lock code base in sound core should be
identical with 3.17. Strange. Do you see anything when you run
git diff v3.17.. sound/core/pcm_native.c
on the tree with two reverts?

Post by Arthur Marsh

I can apply this patch, but I'm not entirely sure how to check for the
state of the nonatomic flag.

If it were wrongly set, the PCM open would show the kernel warning and
abort immediately, so you'll notice soon.
One more test would be to check the direct merge to 3.17 as I've
tested.
- Go to git tree, check out some branch
% git checkout -b sound-test
- Reset to vanilla 3.17
% git reset --hard v3.17
- Merge only the sound changes onto it
% git merge fd1a2a90d08b0052fa52bd36cebd0592c9e537c2
Give any merge messages as you like.
- Compile and retest whether the same problem happens with this one.
thanks!
Takashi

Wait... which patch is this? Could you test without this (but with
the patch below)?

I looked at the relevant code now, and this indeed seems like a
deadlock. But it's nothing new, the code is a decade old. I wonder
why it appears out of sudden. Maybe the change of the spin lock path
triggers.
The patch below is the fix, just removing the superfluous spinlock.

Also below is another thing I spotted now, but this is likely
irrelevant from the lockup, supposedly. In anyway, try this one
together with the previous patch, too.

Takashi

---
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index 85fe1a216225..bfe1cf6b492f 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -818,7 +818,7 @@ static int snd_pcm_action_group(struct action_ops *ops,
/* unlock streams */
snd_pcm_group_for_each_entry(s1, substream) {
if (s1 != substream) {
- if (s->pcm->nonatomic)
+ if (s1->pcm->nonatomic)
mutex_unlock(&s1->self_group.mutex);
else
spin_unlock(&s1->self_group.lock);

Arthur Marsh

2014-10-14 06:24:08 UTC

Permalink

Post by Takashi Iwai

had a similar lock-up (see second photo)

I looked at the relevant code now, and this indeed seems like a
deadlock. But it's nothing new, the code is a decade old. I wonder
why it appears out of sudden. Maybe the change of the spin lock path
triggers.
The patch below is the fix, just removing the superfluous spinlock.

After applying *both*:

---
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index 85fe1a216225..bfe1cf6b492f 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -818,7 +818,7 @@ static int snd_pcm_action_group(struct action_ops *ops,
/* unlock streams */
snd_pcm_group_for_each_entry(s1, substream) {
if (s1 != substream) {
- if (s->pcm->nonatomic)
+ if (s1->pcm->nonatomic)
mutex_unlock(&s1->self_group.mutex);
else
spin_unlock(&s1->self_group.lock);

Post by Takashi Iwai
Also below is another thing I spotted now, but this is likely
irrelevant from the lockup, supposedly. In anyway, try this one
together with the previous patch, too.
Takashi
---
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index 85fe1a216225..bfe1cf6b492f 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -818,7 +818,7 @@ static int snd_pcm_action_group(struct action_ops *ops,
/* unlock streams */
snd_pcm_group_for_each_entry(s1, substream) {
if (s1 != substream) {
- if (s->pcm->nonatomic)
+ if (s1->pcm->nonatomic)
mutex_unlock(&s1->self_group.mutex);
else
spin_unlock(&s1->self_group.lock);

against current Linus git head,

I can run alsa-info.sh successfully and launch the desktop and play
sounds generally (tested with MIDI and running aplay somefile.wav)

Thank you very much for the patches!

Regards,

Arthur.

Arthur Marsh

2014-10-14 03:26:36 UTC

Permalink

Post by Takashi Iwai

# git reset --hard HEAD~
HEAD is now at 77c688a Merge branch 'for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/viro/vfs
am64:/usr/src/linux# git revert 7af142f752116e86adbe2073f2922d8265a77709
[master 927ab0d] Revert "ALSA: pcm: Uninline snd_pcm_stream_lock() and
_unlock()"
Your name and email address were configured automatically based
on your username and hostname. Please check that they are accurate.
git config --global user.name "Your Name"
git commit --amend --reset-author
2 files changed, 73 insertions(+), 72 deletions(-)
am64:/usr/src/linux# git revert 257f8cce5d40b811d229ed71602882baa0012808
[master e59721c] Revert "ALSA: pcm: Allow nonatomic trigger operations"
Your name and email address were configured automatically based
on your username and hostname. Please check that they are accurate.
git config --global user.name "Your Name"
git commit --amend --reset-author
3 files changed, 19 insertions(+), 116 deletions(-)
am64:/usr/src/linux# git diff v3.17.. sound/core/pcm_native.c
am64:/usr/src/linux# git reset --hard HEAD~
HEAD is now at 927ab0d Revert "ALSA: pcm: Uninline snd_pcm_stream_lock()
and _unlock()"
am64:/usr/src/linux# git reset --hard v3.17
Checking out files: 100% (6352/6352), done.
HEAD is now at bfe01a5 Linux 3.17
am64:/usr/src/linux# git checkout -b sound-test
Switched to a new branch 'sound-test'
am64:/usr/src/linux# git merge fd1a2a90d08b0052fa52bd36cebd0592c9e537c2
Updating bfe01a5..fd1a2a9
Fast-forward
[big list of files]
/usr/src/linux# patch -p1 <../sound.patch
patching file sound/core/pcm_native.c

Wait... which patch is this?

This one:

---
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index 85fe1a216225..9c7cbd1b839e 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -2275,6 +2275,9 @@ static int snd_pcm_open(struct file *file, struct
snd_pcm *pcm, int stream)
int err;
wait_queue_t wait;

+ if (WARN_ON(pcm->nonatomic))
+ return -EINVAL;
+
if (pcm == NULL) {
err = -ENODEV;
goto __error1;

Post by Takashi Iwai
Could you test without this (but with
the patch below)?

OK.

Post by Takashi Iwai
I looked at the relevant code now, and this indeed seems like a
deadlock. But it's nothing new, the code is a decade old. I wonder
why it appears out of sudden. Maybe the change of the spin lock path
triggers.
The patch below is the fix, just removing the superfluous spinlock.

Just do "git checkout master"

Thanks!

Post by Takashi Iwai
Takashi
---
diff --git a/sound/pci/emu10k1/emu10k1_callback.c b/sound/pci/emu10k1/emu10k1_callback.c
index 3f3ef38d9b6e..874cd76c7b7f 100644
--- a/sound/pci/emu10k1/emu10k1_callback.c
+++ b/sound/pci/emu10k1/emu10k1_callback.c
@@ -85,6 +85,8 @@ snd_emu10k1_ops_setup(struct snd_emux *emux)
* get more voice for pcm
*
* terminate most inactive voice and give it as a pcm voice.
+ *
+ * voice_lock is already held.
*/
int
snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
@@ -92,12 +94,10 @@ snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
struct snd_emux *emu;
struct snd_emux_voice *vp;
struct best_voice best[V_END];
- unsigned long flags;
int i;
emu = hw->synth;
- spin_lock_irqsave(&emu->voice_lock, flags);
lookup_voices(emu, hw, best, 1); /* no OFF voices */
for (i = 0; i < V_END; i++) {
if (best[i].voice >= 0) {
@@ -113,11 +113,9 @@ snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
vp->emu->num_voices--;
vp->ch = -1;
vp->state = SNDRV_EMUX_ST_OFF;
- spin_unlock_irqrestore(&emu->voice_lock, flags);
return ch;
}
}
- spin_unlock_irqrestore(&emu->voice_lock, flags);
/* not found */
return -ENOMEM;

I'll apply the above patch only first and report the results.

Thanks again,

Arthur.

Arthur Marsh

2014-10-14 07:01:48 UTC

Permalink

Post by Arthur Marsh

Post by Takashi Iwai
---
diff --git a/sound/pci/emu10k1/emu10k1_callback.c
b/sound/pci/emu10k1/emu10k1_callback.c
index 3f3ef38d9b6e..874cd76c7b7f 100644
--- a/sound/pci/emu10k1/emu10k1_callback.c
+++ b/sound/pci/emu10k1/emu10k1_callback.c
@@ -85,6 +85,8 @@ snd_emu10k1_ops_setup(struct snd_emux *emux)
* get more voice for pcm
*
* terminate most inactive voice and give it as a pcm voice.
+ *
+ * voice_lock is already held.
*/
int
snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
@@ -92,12 +94,10 @@ snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
struct snd_emux *emu;
struct snd_emux_voice *vp;
struct best_voice best[V_END];
- unsigned long flags;
int i;
emu = hw->synth;
- spin_lock_irqsave(&emu->voice_lock, flags);
lookup_voices(emu, hw, best, 1); /* no OFF voices */
for (i = 0; i < V_END; i++) {
if (best[i].voice >= 0) {
@@ -113,11 +113,9 @@ snd_emu10k1_synth_get_voice(struct snd_emu10k1 *hw)
vp->emu->num_voices--;
vp->ch = -1;
vp->state = SNDRV_EMUX_ST_OFF;
- spin_unlock_irqrestore(&emu->voice_lock, flags);
return ch;
}
}
- spin_unlock_irqrestore(&emu->voice_lock, flags);
/* not found */
return -ENOMEM;

I'll apply the above patch only first and report the results.
Thanks again,
Arthur.

With only the above emu10k1_callback.c patch and not the pcm_native.c
patch, I experience a lock-up when running alsa-info.sh

Regards,

Arthur.

Takashi Iwai

2014-10-14 07:12:13 UTC

Permalink

At Tue, 14 Oct 2014 17:31:48 +1030,

Post by Arthur Marsh

I'll apply the above patch only first and report the results.
Thanks again,
Arthur.

With only the above emu10k1_callback.c patch and not the pcm_native.c
patch, I experience a lock-up when running alsa-info.sh

OK, good to know. I'll put proper comments about it.

thanks,

Takashi

Arthur Marsh

2014-10-13 18:08:58 UTC

Permalink

Post by Takashi Iwai
At Mon, 13 Oct 2014 23:34:41 +1030,

Post by Arthur Marsh

Post by Takashi Iwai
OK, then could you check whether reverting only the last one (of two)
does *NOT* fix the issue? I think it shouldn't, but let us confirm.

Suppose your tree is now with two reverts, just run "git reset --hard
HEAD~". Then it goes back in a single commit.

Post by Arthur Marsh
I could then apply the second reversion only and test that.

Post by Takashi Iwai
The alsa-info.sh shows the lockdep messages. I assume that it's seen
even before 3.17+?

I didn't see ALSA-related lockdep messages in 3.17.0 or earlier, and
have had the lockdep validator option enabled on kernels for several
months now.

OK, so it's a new message. But this appears after you reverted two
commits, right? Then the lock code base in sound core should be
identical with 3.17. Strange. Do you see anything when you run
git diff v3.17.. sound/core/pcm_native.c
on the tree with two reverts?

Post by Arthur Marsh

I can apply this patch, but I'm not entirely sure how to check for the
state of the nonatomic flag.

If it were wrongly set, the PCM open would show the kernel warning and
abort immediately, so you'll notice soon.
One more test would be to check the direct merge to 3.17 as I've
tested.
- Go to git tree, check out some branch
% git checkout -b sound-test
- Reset to vanilla 3.17
% git reset --hard v3.17
- Merge only the sound changes onto it
% git merge fd1a2a90d08b0052fa52bd36cebd0592c9e537c2
Give any merge messages as you like.
- Compile and retest whether the same problem happens with this one.
thanks!
Takashi

OK

# git reset --hard HEAD~
HEAD is now at 77c688a Merge branch 'for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/viro/vfs
am64:/usr/src/linux# git revert 7af142f752116e86adbe2073f2922d8265a77709
[master 927ab0d] Revert "ALSA: pcm: Uninline snd_pcm_stream_lock() and
_unlock()"
Committer: root <***@am64.localdomain>
Your name and email address were configured automatically based
on your username and hostname. Please check that they are accurate.
You can suppress this message by setting them explicitly:

git config --global user.name "Your Name"
git config --global user.email ***@example.com

After doing this, you may fix the identity used for this commit with:

git commit --amend --reset-author

2 files changed, 73 insertions(+), 72 deletions(-)
am64:/usr/src/linux# git revert 257f8cce5d40b811d229ed71602882baa0012808
[master e59721c] Revert "ALSA: pcm: Allow nonatomic trigger operations"
Committer: root <***@am64.localdomain>
Your name and email address were configured automatically based
on your username and hostname. Please check that they are accurate.
You can suppress this message by setting them explicitly:

git config --global user.name "Your Name"
git config --global user.email ***@example.com

After doing this, you may fix the identity used for this commit with:

git commit --amend --reset-author

3 files changed, 19 insertions(+), 116 deletions(-)
am64:/usr/src/linux# git diff v3.17.. sound/core/pcm_native.c
am64:/usr/src/linux# git reset --hard HEAD~
HEAD is now at 927ab0d Revert "ALSA: pcm: Uninline snd_pcm_stream_lock()
and _unlock()"
am64:/usr/src/linux# git reset --hard v3.17
Checking out files: 100% (6352/6352), done.
HEAD is now at bfe01a5 Linux 3.17
am64:/usr/src/linux# git checkout -b sound-test
Switched to a new branch 'sound-test'
am64:/usr/src/linux# git merge fd1a2a90d08b0052fa52bd36cebd0592c9e537c2
Updating bfe01a5..fd1a2a9
Fast-forward
[big list of files]

/usr/src/linux# patch -p1 <../sound.patch
patching file sound/core/pcm_native.c

I then rebuilt that kernel, and installed it.

It booted and played its start-up sound of a MIDI file fine, but when I
attempted to run alsa-info.sh it locked up (see first photo), and after
rebooting again and trying to run:

aplay some-file.wav

had a similar lock-up (see second photo)

I can supply a dmesg output of the machine with the test kernel before
attempting anything that might cause a lock-up if it's of use to you.

PS, how do I get my git repositary out of "sound-test" branch and return
to Linus' git head?

Regards,

Arthur.

Arthur Marsh

2014-10-13 11:36:34 UTC

Permalink

OK, steps I took:

Obtain alsa-info.sh output from my working 3.17.0 kernel set-up;

Boot into 3.17.0+ and attempt to run alsa-info.sh - dumps occurred as
shown in attached photos, even corrupted the machine's BIOS;

Attempt to blacklist sound drivers, ran 3.17.0+ without lock-up,
obtained alsa-info.sh output;

Applied 2 reversions listed above to current 3.17.0+ Linus git head, had
to remove a few other sound cards from the menuconfig to let the kernel
build, removed blacklisting and rebooted into kernel with reversions
applied.

Ran alsa-info.sh and received dmesg output as shown below, was able to
bring up the desktop session without lock-up.

Regards,

Arthur.