On Fri, 25 Aug 2017 07:31:04 +0200, Kuninori Morimoto wrote:
Hi Takashi-san, Mark
I noticed snd_soc_dapm_stream_event() is called strange timing if I unbind sound device during playing
aplay xxx.wav & echo xxxx > /sys/bus/platform/drivers/xxx/unbind
...
Unable to handle kernel paging request at virtual address dead000000000220 Mem abort info:
(snip)
PC is at soc_dapm_dai_stream_event.isra.14+0x20/0xd0 LR is at snd_soc_dapm_stream_event+0x74/0xa8
(snip)
[<ffff000008715610>] soc_dapm_dai_stream_event.isra.14+0x20/0xd0 [<ffff00000871989c>] snd_soc_dapm_stream_event+0x74/0xa8 [<ffff00000871b23c>] close_delayed_work+0x3c/0x50 [<ffff0000080bbd6c>] process_one_work+0x1ac/0x318 [<ffff0000080bbf20>] worker_thread+0x48/0x420 [<ffff0000080c201c>] kthread+0xfc/0x128 [<ffff0000080842f0>] ret_from_fork+0x10/0x18 Code: b40005c9 a9bf7bfd 91048120 910003fd (f9409121) ---[ end trace 6739a0ea1013e0b2 ]---
This snd_soc_dapm_stream_event() was called from close_delayed_work() and it was set on soc_pcm_close()
static int soc_pcm_close(struct snd_pcm_substream *substream) { ... if (substream->stream == SNDRV_PCM_STREAM_PLAYBACK) { if (snd_soc_runtime_ignore_pmdown_time(rtd)) { ... } else { /* start delayed pop wq here for playback streams */ rtd->pop_wait = 1; => queue_delayed_work(system_power_efficient_wq, &rtd->delayed_work, msecs_to_jiffies(rtd->pmdown_time)); } ... }
But, this soc_pcm_close() is called *after* flush_delayed_work() of soc_cleanup_card_resources(). It seems this close function seems called from snd_card_free() and this rtd will be freed on soc_remove_pcm_runtimes().
static int soc_cleanup_card_resources(struct snd_soc_card *card) { ...
/* make sure any delayed work runs */ list_for_each_entry(rtd, &card->rtd_list, list) { => flush_delayed_work(&rtd->delayed_work); }
/* free the ALSA card at first; this syncs with pending operations */ => snd_card_free(card->snd_card); ... => soc_remove_pcm_runtimes(card); ... }
Because of this, delayed called close_delayed_work() will call soc_dapm_dai_stream_event() and it access to already freed rtd, and kernel will die. I don't know why, but it seems this close is wokring on other thread (?), but I'm not sure.
It's just a race, so sometimes it may succeed, I guess.
Q1. does this close function run on other thread ?
Depends.
Q2. I can avoid this delayed close by setting rtd->pmdown_time = 0; before snd_card_free(). but is this correct approach ?
Basically yes -- supposing the driver / the hardware handles already correctly the DAPM shutdown path beforehand.
Or, on the real hotplugged device, even accessing the whole should be suppressed after the device disconnection. So, this might even not be sufficient.
But in anyway, you'd better to sync before the actual resource free. A patch below would add the sync point at PCM free so that the Oops above can be avoided, I suppose.
--- a/sound/soc/soc-pcm.c +++ b/sound/soc/soc-pcm.c @@ -2632,6 +2632,16 @@ static int dpcm_fe_dai_close(struct snd_pcm_substream *fe_substream) return ret; }
+static void soc_pcm_private_free(struct snd_pcm *pcm) +{ + struct snd_soc_pcm_runtime *rtd = pcm->private_data; + struct snd_soc_platform *platform = rtd->platform; + + flush_delayed_work(&rtd->delayed_work); + if (platform->driver->pcm_free) + if (platform->driver->pcm_free(pcm); +} + /* create a new pcm */ int soc_new_pcm(struct snd_soc_pcm_runtime *rtd, int num) { @@ -2757,7 +2767,7 @@ int soc_new_pcm(struct snd_soc_pcm_runtime *rtd, int num) } }
- pcm->private_free = platform->driver->pcm_free; + pcm->private_free = soc_pcm_private_free; out: dev_info(rtd->card->dev, "%s <-> %s mapping ok\n", (rtd->num_codecs > 1) ? "multicodec" : rtd->codec_dai->name,
I can avoid this delayed calling close_delayed_work() by local patch, but then, re-bind doesn't work correctly.
/* * custom kernel for avoiding close_delayed_work() */
aplay xxx.wav & echo xxxx > /sys/bus/platform/drivers/rcar_sound/unbind
/* unbind codec and card drivers here */
/* * try re-bind */ /* re-bind codec and card drivers here */
echo xxxx > /sys/bus/platform/drivers/rcar_sound/bind
rcar_sound ec500000.sound: probed asoc-simple-card sound: ak4613-hifi <-> ec500000.sound mapping ok
aplay xxx.wav
Playing WAVE '/home/Calm_16bit_48k.wav' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo ALSA lib pcm_params.c:2162:(snd1_pcm_hw_refine_slave) Slave PCM not usable aplay: set_params:1204: Broken configuration for this PCM: no configurations available
Do you know why or have hint to solve these issue ?
It's hard to say only from that... But judging from your description, it must be relevant with the stale DAPM setup that was left untouched at the previous driver unbind? That is, the driver doesn't fully initialize the hardware at probe.
thanks,
Takashi