From f13365629dd9c5e4916aff8ccf4f95d6dee42c68 Mon Sep 17 00:00:00 2001 From: Pierre-Louis Bossart Date: Thu, 20 Jan 2022 08:22:36 -0600 Subject: [PATCH 1/6] ASoC: soc-core: wait for resume to complete Provided by Takashi Iwai: https://github.com/thesofproject/linux/files/7902858/snd-power-lock-ignore-freezer-v2.diff.txt Signed-off-by: Pierre-Louis Bossart --- include/sound/soc.h | 1 + sound/core/init.c | 3 +++ sound/soc/soc-core.c | 6 +++++- 3 files changed, 9 insertions(+), 1 deletion(-) diff --git a/include/sound/soc.h b/include/sound/soc.h index 7a1650b303f140..a85dc10c5b285a 100644 --- a/include/sound/soc.h +++ b/include/sound/soc.h @@ -986,6 +986,7 @@ struct snd_soc_card { unsigned int disable_route_checks:1; unsigned int probed:1; unsigned int component_chaining:1; + unsigned int in_suspend:1; void *drvdata; }; diff --git a/sound/core/init.c b/sound/core/init.c index ac335f5906c6b4..baea8792f4fbf7 100644 --- a/sound/core/init.c +++ b/sound/core/init.c @@ -16,6 +16,7 @@ #include #include #include +#include #include #include @@ -1118,6 +1119,7 @@ int snd_power_ref_and_wait(struct snd_card *card) /* fastpath */ if (snd_power_get_state(card) == SNDRV_CTL_POWER_D0) return 0; + lock_system_sleep(); init_waitqueue_entry(&wait, current); add_wait_queue(&card->power_sleep, &wait); while (1) { @@ -1133,6 +1135,7 @@ int snd_power_ref_and_wait(struct snd_card *card) snd_power_ref(card); } remove_wait_queue(&card->power_sleep, &wait); + unlock_system_sleep(); return result; } EXPORT_SYMBOL_GPL(snd_power_ref_and_wait); diff --git a/sound/soc/soc-core.c b/sound/soc/soc-core.c index 434e61b46983cf..d1689a49a44334 100644 --- a/sound/soc/soc-core.c +++ b/sound/soc/soc-core.c @@ -557,6 +557,8 @@ int snd_soc_suspend(struct device *dev) if (!card->instantiated) return 0; + card->in_suspend = 1; + /* * Due to the resume being scheduled into a workqueue we could * suspend before that's finished - wait for it to complete. @@ -639,6 +641,7 @@ int snd_soc_suspend(struct device *dev) } snd_soc_card_suspend_post(card); + card->in_suspend = 0; return 0; } @@ -686,7 +689,8 @@ static void soc_resume_deferred(struct work_struct *work) snd_soc_dapm_sync(&card->dapm); /* userspace can access us now we are back as we were before */ - snd_power_change_state(card->snd_card, SNDRV_CTL_POWER_D0); + if (!card->in_suspend) + snd_power_change_state(card->snd_card, SNDRV_CTL_POWER_D0); } /* powers up audio subsystem after a suspend */ From edc66ee360be3df7aae17e49a1ec00ef7c0488e4 Mon Sep 17 00:00:00 2001 From: Pierre-Louis Bossart Date: Tue, 18 Jan 2022 11:12:03 -0600 Subject: [PATCH 2/6] [HACK] ALSA: core: add traces in snd_power_change_state Suggested by Takashi Iwai Signed-off-by: Pierre-Louis Bossart --- include/sound/core.h | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/include/sound/core.h b/include/sound/core.h index b7e9b58d3c7880..44a29b2c0d6526 100644 --- a/include/sound/core.h +++ b/include/sound/core.h @@ -151,8 +151,12 @@ static inline unsigned int snd_power_get_state(struct snd_card *card) static inline void snd_power_change_state(struct snd_card *card, unsigned int state) { + dev_warn(card->dev, "plb: snd_power_change_state: requesting state %d in %s\n", + state, __func__); WRITE_ONCE(card->power_state, state); + dev_warn(card->dev, "plb: snd_power_change_state: waking up power_sleep in %s\n", __func__); wake_up(&card->power_sleep); + dev_warn(card->dev, "plb: snd_power_change_state: done in %s\n", __func__); } /** From ec99459e4b871f112f9ef77cc4b386e011b7d952 Mon Sep 17 00:00:00 2001 From: Pierre-Louis Bossart Date: Tue, 18 Jan 2022 18:37:21 -0600 Subject: [PATCH 3/6] [HACK] ALSA: core: add traces in snd_power_ref_and_wait Add traces to see what happens when one task refuses to freeze. Signed-off-by: Pierre-Louis Bossart --- sound/core/init.c | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/sound/core/init.c b/sound/core/init.c index baea8792f4fbf7..37ffb5fc52c3bb 100644 --- a/sound/core/init.c +++ b/sound/core/init.c @@ -1119,6 +1119,10 @@ int snd_power_ref_and_wait(struct snd_card *card) /* fastpath */ if (snd_power_get_state(card) == SNDRV_CTL_POWER_D0) return 0; + + dev_warn(card->dev, "plb: %s: starting wait, power state %d\n", __func__, + snd_power_get_state(card)); + lock_system_sleep(); init_waitqueue_entry(&wait, current); add_wait_queue(&card->power_sleep, &wait); @@ -1136,6 +1140,10 @@ int snd_power_ref_and_wait(struct snd_card *card) } remove_wait_queue(&card->power_sleep, &wait); unlock_system_sleep(); + + dev_warn(card->dev, "plb: %s: wait complete, power state %d\n", __func__, + snd_power_get_state(card)); + return result; } EXPORT_SYMBOL_GPL(snd_power_ref_and_wait); From 14927240704d31671f597362b0e90a73a97cc306 Mon Sep 17 00:00:00 2001 From: Pierre-Louis Bossart Date: Wed, 19 Jan 2022 13:59:22 -0600 Subject: [PATCH 4/6] [HACK] ASoC: soc-core: add traces for notifiers/workqueue Somehow the code gets stuck somewhere while starting the flush on suspend. Traces seem to suggest the issue is either in dapm_mark_endpoints_dirty(card); or snd_soc_dapm_sync(&card->dapm); Signed-off-by: Pierre-Louis Bossart --- sound/soc/soc-core.c | 30 ++++++++++++++++++++++++++++-- 1 file changed, 28 insertions(+), 2 deletions(-) diff --git a/sound/soc/soc-core.c b/sound/soc/soc-core.c index d1689a49a44334..516943ce878ea6 100644 --- a/sound/soc/soc-core.c +++ b/sound/soc/soc-core.c @@ -662,35 +662,61 @@ static void soc_resume_deferred(struct work_struct *work) * our power state is still SNDRV_CTL_POWER_D3hot from suspend time, * so userspace apps are blocked from touching us */ - + pr_warn("plb: %s: start\n", __func__); dev_dbg(card->dev, "ASoC: starting resume work\n"); /* Bring us up into D2 so that DAPM starts enabling things */ snd_power_change_state(card->snd_card, SNDRV_CTL_POWER_D2); + pr_warn("plb: %s: 1\n", __func__); + snd_soc_card_resume_pre(card); + pr_warn("plb: %s: 2\n", __func__); + for_each_card_components(card, component) { if (snd_soc_component_is_suspended(component)) snd_soc_component_resume(component); } + pr_warn("plb: %s: 3\n", __func__); + soc_dapm_suspend_resume(card, SND_SOC_DAPM_STREAM_RESUME); + pr_warn("plb: %s: 4\n", __func__); + /* unmute any active DACs */ soc_playback_digital_mute(card, 0); + pr_warn("plb: %s: 5\n", __func__); + snd_soc_card_resume_post(card); + pr_warn("plb: %s: 6\n", __func__); + dev_dbg(card->dev, "ASoC: resume work completed\n"); + pr_warn("plb: %s: 7\n", __func__); + /* Recheck all endpoints too, their state is affected by suspend */ dapm_mark_endpoints_dirty(card); + + pr_warn("plb: %s: 7.5\n", __func__); + snd_soc_dapm_sync(&card->dapm); + pr_warn("plb: %s: 8\n", __func__); + /* userspace can access us now we are back as we were before */ - if (!card->in_suspend) + if (!card->in_suspend) { + pr_warn("plb: %s: 9\n", __func__); + snd_power_change_state(card->snd_card, SNDRV_CTL_POWER_D0); + + pr_warn("plb: %s: 10\n", __func__); + } + + pr_warn("plb: %s: done\n", __func__); } /* powers up audio subsystem after a suspend */ From 9f02c68df0b588d048f1c8d198c967d57b2107c5 Mon Sep 17 00:00:00 2001 From: Pierre-Louis Bossart Date: Thu, 20 Jan 2022 12:35:57 -0600 Subject: [PATCH 5/6] [HACK] ASoC: soc-dapm: add traces to see when resume gets stuck Signed-off-by: Pierre-Louis Bossart --- sound/soc/soc-dapm.c | 35 +++++++++++++++++++++++++++++++++++ 1 file changed, 35 insertions(+) diff --git a/sound/soc/soc-dapm.c b/sound/soc/soc-dapm.c index b06c5682445c03..42bdb69f34f4dd 100644 --- a/sound/soc/soc-dapm.c +++ b/sound/soc/soc-dapm.c @@ -1965,6 +1965,7 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) enum snd_soc_bias_level bias; int ret; + pr_warn("plb: %s: start\n", __func__); lockdep_assert_held(&card->dapm_mutex); trace_snd_soc_dapm_start(card); @@ -1976,8 +1977,12 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) d->target_bias_level = SND_SOC_BIAS_STANDBY; } + pr_warn("plb: %s: 1\n", __func__); + dapm_reset(card); + pr_warn("plb: %s: 2\n", __func__); + /* Check which widgets we need to power and store them in * lists indicating if they should be powered up or down. We * only check widgets that have been flagged as dirty but note @@ -1988,6 +1993,8 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) dapm_power_one_widget(w, &up_list, &down_list); } + pr_warn("plb: %s: 3\n", __func__); + for_each_card_widgets(card, w) { switch (w->id) { case snd_soc_dapm_pre: @@ -2029,6 +2036,8 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) } + pr_warn("plb: %s: 4\n", __func__); + /* Force all contexts in the card to the same bias state if * they're not ground referenced. */ @@ -2042,16 +2051,26 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) trace_snd_soc_dapm_walk_done(card); + pr_warn("plb: %s: 5\n", __func__); + /* Run card bias changes at first */ dapm_pre_sequence_async(&card->dapm, 0); + + pr_warn("plb: %s: 6\n", __func__); + /* Run other bias changes in parallel */ for_each_card_dapms(card, d) { if (d != &card->dapm && d->bias_level != d->target_bias_level) async_schedule_domain(dapm_pre_sequence_async, d, &async_domain); } + + pr_warn("plb: %s: 7\n", __func__); + async_synchronize_full_domain(&async_domain); + pr_warn("plb: %s: 8\n", __func__); + list_for_each_entry(w, &down_list, power_list) { dapm_seq_check_event(card, w, SND_SOC_DAPM_WILL_PMD); } @@ -2060,14 +2079,20 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) dapm_seq_check_event(card, w, SND_SOC_DAPM_WILL_PMU); } + pr_warn("plb: %s: 9\n", __func__); + /* Power down widgets first; try to avoid amplifying pops. */ dapm_seq_run(card, &down_list, event, false); dapm_widget_update(card); + pr_warn("plb: %s: 10\n", __func__); + /* Now power up. */ dapm_seq_run(card, &up_list, event, true); + pr_warn("plb: %s: 11\n", __func__); + /* Run all the bias changes in parallel */ for_each_card_dapms(card, d) { if (d != &card->dapm && d->bias_level != d->target_bias_level) @@ -2075,9 +2100,14 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) &async_domain); } async_synchronize_full_domain(&async_domain); + + pr_warn("plb: %s: 12\n", __func__); + /* Run card bias changes at last */ dapm_post_sequence_async(&card->dapm, 0); + pr_warn("plb: %s: 13\n", __func__); + /* do we need to notify any clients that DAPM event is complete */ for_each_card_dapms(card, d) { if (!d->component) @@ -2088,10 +2118,13 @@ static int dapm_power_widgets(struct snd_soc_card *card, int event) return ret; } + pr_warn("plb: %s: 15\n", __func__); + pop_dbg(card->dev, card->pop_time, "DAPM sequencing finished, waiting %dms\n", card->pop_time); pop_wait(card->pop_time); + pr_warn("plb: %s: done\n", __func__); trace_snd_soc_dapm_done(card); return 0; @@ -2640,9 +2673,11 @@ int snd_soc_dapm_sync(struct snd_soc_dapm_context *dapm) { int ret; + pr_warn("plb: %s: start\n", __func__); mutex_lock_nested(&dapm->card->dapm_mutex, SND_SOC_DAPM_CLASS_RUNTIME); ret = snd_soc_dapm_sync_unlocked(dapm); mutex_unlock(&dapm->card->dapm_mutex); + pr_warn("plb: %s: done\n", __func__); return ret; } EXPORT_SYMBOL_GPL(snd_soc_dapm_sync); From dd03eb7ba85026a89972679b6902e398256a9f98 Mon Sep 17 00:00:00 2001 From: Pierre-Louis Bossart Date: Thu, 20 Jan 2022 14:32:20 -0600 Subject: [PATCH 6/6] [HACK] ASoC: soc-dapm: more traces in dapm_seq_run() Signed-off-by: Pierre-Louis Bossart --- sound/soc/soc-dapm.c | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/sound/soc/soc-dapm.c b/sound/soc/soc-dapm.c index 42bdb69f34f4dd..55d3c23375788d 100644 --- a/sound/soc/soc-dapm.c +++ b/sound/soc/soc-dapm.c @@ -1652,11 +1652,15 @@ static void dapm_seq_run(struct snd_soc_card *card, int i; int *sort; + pr_warn("plb: %s: start\n", __func__); + if (power_up) sort = dapm_up_seq; else sort = dapm_down_seq; + pr_warn("plb: %s: 1\n", __func__); + list_for_each_entry_safe(w, n, list, power_list) { int ret = 0; @@ -1726,9 +1730,13 @@ static void dapm_seq_run(struct snd_soc_card *card, "ASoC: Failed to apply widget power: %d\n", ret); } + pr_warn("plb: %s: 2\n", __func__); + if (!list_empty(&pending)) dapm_seq_run_coalesced(card, &pending); + pr_warn("plb: %s: 3\n", __func__); + if (cur_dapm && cur_dapm->component) { for (i = 0; i < ARRAY_SIZE(dapm_up_seq); i++) if (sort[i] == cur_sort) @@ -1737,8 +1745,12 @@ static void dapm_seq_run(struct snd_soc_card *card, i, cur_subseq); } + pr_warn("plb: %s: 4\n", __func__); + for_each_card_dapms(card, d) soc_dapm_async_complete(d); + + pr_warn("plb: %s: done\n", __func__); } static void dapm_widget_update(struct snd_soc_card *card)