Skip to content

[HACK] ALSA: core: add traces in snd_power_ref_and_wait #3374

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
plbossart wants to merge 6 commits into from
Closed

[HACK] ALSA: core: add traces in snd_power_ref_and_wait #3374

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
f133656
ASoC: soc-core: wait for resume to complete
plbossart Jan 20, 2022
edc66ee
[HACK] ALSA: core: add traces in snd_power_change_state
plbossart Jan 18, 2022
ec99459
[HACK] ALSA: core: add traces in snd_power_ref_and_wait
plbossart Jan 19, 2022
1492724
[HACK] ASoC: soc-core: add traces for notifiers/workqueue
plbossart Jan 19, 2022
9f02c68
[HACK] ASoC: soc-dapm: add traces to see when resume gets stuck
plbossart Jan 20, 2022
dd03eb7
[HACK] ASoC: soc-dapm: more traces in dapm_seq_run()
plbossart Jan 20, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions include/sound/core.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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__);
}

/**
Expand Down
1 change: 1 addition & 0 deletions include/sound/soc.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
};
Expand Down
11 changes: 11 additions & 0 deletions sound/core/init.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
#include <linux/debugfs.h>
#include <linux/completion.h>
#include <linux/interrupt.h>
#include <linux/suspend.h>

#include <sound/core.h>
#include <sound/control.h>
Expand Down Expand Up @@ -1118,6 +1119,11 @@ 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);
while (1) {
Expand All @@ -1133,6 +1139,11 @@ int snd_power_ref_and_wait(struct snd_card *card)
snd_power_ref(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);
Expand Down
34 changes: 32 additions & 2 deletions sound/soc/soc-core.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down Expand Up @@ -639,6 +641,7 @@ int snd_soc_suspend(struct device *dev)
}

snd_soc_card_suspend_post(card);
card->in_suspend = 0;

return 0;
}
Expand All @@ -659,34 +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 */
snd_power_change_state(card->snd_card, SNDRV_CTL_POWER_D0);
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 */
Expand Down
47 changes: 47 additions & 0 deletions sound/soc/soc-dapm.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -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)
Expand All @@ -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)
Expand Down Expand Up @@ -1965,6 +1977,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);
Expand All @@ -1976,8 +1989,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
Expand All @@ -1988,6 +2005,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:
Expand Down Expand Up @@ -2029,6 +2048,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.
*/
Expand All @@ -2042,16 +2063,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);
}
Expand All @@ -2060,24 +2091,35 @@ 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)
async_schedule_domain(dapm_post_sequence_async, d,
&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)
Expand All @@ -2088,10 +2130,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;
Expand Down Expand Up @@ -2640,9 +2685,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);
Expand Down