Skip to content
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

Jump to bottom

ASoC: SOF: pcm: Improve debug and error prints #5252

Open
wants to merge 3 commits into
base: topic/sof-dev
Choose a base branch
from
+163 −147
Open

ASoC: SOF: pcm: Improve debug and error prints #5252

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
f763a79
ASoC: SOF: Relocate and rework functionality for PCM stream freeing
ujfalusi Nov 12, 2024
48bd7c5
ASoC: SOF: pcm: Move period/buffer configuration print after platform…
ujfalusi Nov 5, 2024
b3273cb
ASoC: SOF: pcm: Add snd_sof_pcm specific wrappers for dev_dbg() and d…
ujfalusi Nov 26, 2024
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
13 changes: 7 additions & 6 deletions sound/soc/sof/ipc3-pcm.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -117,22 +117,23 @@ static int sof_ipc3_pcm_hw_params(struct snd_soc_component *component,
if (platform_params->cont_update_posn)
pcm.params.cont_update_posn = 1;

dev_dbg(component->dev, "stream_tag %d", pcm.params.stream_tag);
spcm_dbg(spcm, substream->stream, "stream_tag %d\n",
pcm.params.stream_tag);

/* send hw_params IPC to the DSP */
ret = sof_ipc_tx_message(sdev->ipc, &pcm, sizeof(pcm),
&ipc_params_reply, sizeof(ipc_params_reply));
if (ret < 0) {
dev_err(component->dev, "HW params ipc failed for stream %d\n",
pcm.params.stream_tag);
spcm_err(spcm, substream->stream,
"STREAM_PCM_PARAMS ipc failed for stream_tag %d\n",
pcm.params.stream_tag);
return ret;
}

ret = snd_sof_set_stream_data_offset(sdev, &spcm->stream[substream->stream],
ipc_params_reply.posn_offset);
if (ret < 0) {
dev_err(component->dev, "%s: invalid stream data offset for PCM %d\n",
__func__, spcm->pcm.pcm_id);
spcm_err(spcm, substream->stream, "invalid stream data offset\n");
return ret;
}

Expand Down Expand Up @@ -171,7 +172,7 @@ static int sof_ipc3_pcm_trigger(struct snd_soc_component *component,
stream.hdr.cmd |= SOF_IPC_STREAM_TRIG_STOP;
break;
default:
dev_err(component->dev, "Unhandled trigger cmd %d\n", cmd);
spcm_err(spcm, substream->stream, "Unhandled trigger cmd %d\n", cmd);
return -EINVAL;
}

Expand Down
16 changes: 9 additions & 7 deletions sound/soc/sof/ipc4-pcm.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -313,7 +313,7 @@ static int sof_ipc4_chain_dma_trigger(struct snd_sof_dev *sdev,
set_fifo_size = false;
break;
default:
dev_err(sdev->dev, "Unexpected state %d", state);
spcm_err(spcm, direction, "Unexpected pipeline state %d\n", state);
return -EINVAL;
}

Expand All @@ -333,8 +333,8 @@ static int sof_ipc4_chain_dma_trigger(struct snd_sof_dev *sdev,
struct sof_ipc4_pipeline *pipeline = pipe_widget->private;

if (!pipeline->use_chain_dma) {
dev_err(sdev->dev,
"All pipelines in chained DMA stream should have use_chain_dma attribute set.");
spcm_err(spcm, direction,
"All pipelines in chained DMA path should have use_chain_dma attribute set.");
return -EINVAL;
}

Expand Down Expand Up @@ -389,12 +389,12 @@ static int sof_ipc4_trigger_pipelines(struct snd_soc_component *component,
int ret;
int i;

dev_dbg(sdev->dev, "trigger cmd: %d state: %d\n", cmd, state);

spcm = snd_sof_find_spcm_dai(component, rtd);
if (!spcm)
return -EINVAL;

spcm_dbg(spcm, substream->stream, "cmd: %d, state: %d\n", cmd, state);

pipeline_list = &spcm->stream[substream->stream].pipeline_list;

/* nothing to trigger if the list is empty */
Expand Down Expand Up @@ -465,7 +465,7 @@ static int sof_ipc4_trigger_pipelines(struct snd_soc_component *component,
*/
ret = sof_ipc4_set_multi_pipeline_state(sdev, SOF_IPC4_PIPE_PAUSED, trigger_list);
if (ret < 0) {
dev_err(sdev->dev, "failed to pause all pipelines\n");
spcm_err(spcm, substream->stream, "failed to pause all pipelines\n");
goto free;
}

Expand Down Expand Up @@ -494,7 +494,9 @@ static int sof_ipc4_trigger_pipelines(struct snd_soc_component *component,
/* else set the RUNNING/RESET state in the DSP */
ret = sof_ipc4_set_multi_pipeline_state(sdev, state, trigger_list);
if (ret < 0) {
dev_err(sdev->dev, "failed to set final state %d for all pipelines\n", state);
spcm_err(spcm, substream->stream,
"failed to set final state %d for all pipelines\n",
state);
/*
* workaround: if the firmware is crashed while setting the
* pipelines to reset state we must ignore the error code and
Expand Down
95 changes: 42 additions & 53 deletions sound/soc/sof/pcm.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -99,17 +99,16 @@ sof_pcm_setup_connected_widgets(struct snd_sof_dev *sdev, struct snd_soc_pcm_run
ret = snd_soc_dapm_dai_get_connected_widgets(dai, dir, &list,
dpcm_end_walk_at_be);
if (ret < 0) {
dev_err(sdev->dev, "error: dai %s has no valid %s path\n", dai->name,
snd_pcm_direction_name(dir));
spcm_err(spcm, dir, "dai %s has no valid %s path\n",
dai->name, snd_pcm_direction_name(dir));
return ret;
}

spcm->stream[dir].list = list;

ret = sof_widget_list_setup(sdev, spcm, params, platform_params, dir);
if (ret < 0) {
dev_err(sdev->dev, "error: failed widget list set up for pcm %d dir %d\n",
spcm->pcm.pcm_id, dir);
spcm_err(spcm, dir, "Widget list set up failed\n");
spcm->stream[dir].list = NULL;
snd_soc_dapm_dai_free_widgets(&list);
return ret;
Expand Down Expand Up @@ -139,6 +138,9 @@ static int sof_pcm_hw_params(struct snd_soc_component *component,
if (!spcm)
return -EINVAL;


spcm_dbg(spcm, substream->stream, "Entry: hw_params\n");

/*
* Handle repeated calls to hw_params() without free_pcm() in
* between. At least ALSA OSS emulation depends on this.
Expand All @@ -151,12 +153,9 @@ static int sof_pcm_hw_params(struct snd_soc_component *component,
spcm->prepared[substream->stream] = false;
}

dev_dbg(component->dev, "pcm: hw params stream %d dir %d\n",
spcm->pcm.pcm_id, substream->stream);

ret = snd_sof_pcm_platform_hw_params(sdev, substream, params, &platform_params);
if (ret < 0) {
dev_err(component->dev, "platform hw params failed\n");
spcm_err(spcm, substream->stream, "platform hw params failed\n");
return ret;
}

Expand Down Expand Up @@ -210,8 +209,8 @@ static int sof_pcm_stream_free(struct snd_sof_dev *sdev,
if (pcm_ops && pcm_ops->hw_free) {
ret = pcm_ops->hw_free(sdev->component, substream);
if (ret < 0) {
dev_err(sdev->dev, "%s: pcm_ops hw_free failed %d\n",
__func__, ret);
spcm_err(spcm, substream->stream,
"pcm_ops->hw_free failed %d\n", ret);
err = ret;
}
}
Expand All @@ -223,8 +222,8 @@ static int sof_pcm_stream_free(struct snd_sof_dev *sdev,
/* reset the DMA */
ret = snd_sof_pcm_platform_hw_free(sdev, substream);
if (ret < 0) {
dev_err(sdev->dev, "%s: platform hw free failed %d\n",
__func__, ret);
spcm_err(spcm, substream->stream,
"platform hw free failed %d\n", ret);
if (!err)
err = ret;
}
Expand All @@ -233,8 +232,8 @@ static int sof_pcm_stream_free(struct snd_sof_dev *sdev,
if (free_widget_list) {
ret = sof_widget_list_free(sdev, spcm, dir);
if (ret < 0) {
dev_err(sdev->dev, "%s: sof_widget_list_free failed %d\n",
__func__, ret);
spcm_err(spcm, substream->stream,
"sof_widget_list_free failed %d\n", ret);
if (!err)
err = ret;
}
Expand Down Expand Up @@ -285,8 +284,7 @@ static int sof_pcm_hw_free(struct snd_soc_component *component,
if (!spcm)
return -EINVAL;

dev_dbg(component->dev, "pcm: free stream %d dir %d\n",
spcm->pcm.pcm_id, substream->stream);
spcm_dbg(spcm, substream->stream, "Entry: hw_free\n");

ret = sof_pcm_stream_free(sdev, substream, spcm, substream->stream, true);

Expand All @@ -311,6 +309,8 @@ static int sof_pcm_prepare(struct snd_soc_component *component,
if (!spcm)
return -EINVAL;

spcm_dbg(spcm, substream->stream, "Entry: prepare\n");

if (spcm->prepared[substream->stream]) {
if (!spcm->pending_stop[substream->stream])
return 0;
Expand All @@ -324,15 +324,12 @@ static int sof_pcm_prepare(struct snd_soc_component *component,
return ret;
}

dev_dbg(component->dev, "pcm: prepare stream %d dir %d\n",
spcm->pcm.pcm_id, substream->stream);

/* set hw_params */
ret = sof_pcm_hw_params(component,
substream, &spcm->params[substream->stream]);
if (ret < 0) {
dev_err(component->dev,
"error: set pcm hw_params after resume\n");
spcm_err(spcm, substream->stream,
"failed to set hw_params after resume\n");
return ret;
}

Expand Down Expand Up @@ -362,8 +359,7 @@ static int sof_pcm_trigger(struct snd_soc_component *component,
if (!spcm)
return -EINVAL;

dev_dbg(component->dev, "pcm: trigger stream %d dir %d cmd %d\n",
spcm->pcm.pcm_id, substream->stream, cmd);
spcm_dbg(spcm, substream->stream, "Entry: trigger (cmd: %d)\n", cmd);

spcm->pending_stop[substream->stream] = false;

Expand Down Expand Up @@ -412,7 +408,7 @@ static int sof_pcm_trigger(struct snd_soc_component *component,
reset_hw_params = true;
break;
default:
dev_err(component->dev, "Unhandled trigger cmd %d\n", cmd);
spcm_err(spcm, substream->stream, "Unhandled trigger cmd %d\n", cmd);
return -EINVAL;
}

Expand Down Expand Up @@ -514,9 +510,7 @@ static int sof_pcm_open(struct snd_soc_component *component,
if (!spcm)
return -EINVAL;

dev_dbg(component->dev, "pcm: open stream %d dir %d\n",
spcm->pcm.pcm_id, substream->stream);

spcm_dbg(spcm, substream->stream, "Entry: open\n");

caps = &spcm->pcm.caps[substream->stream];

Expand Down Expand Up @@ -546,18 +540,16 @@ static int sof_pcm_open(struct snd_soc_component *component,

ret = snd_sof_pcm_platform_open(sdev, substream);
if (ret < 0) {
dev_err(component->dev, "error: pcm open failed %d\n", ret);
spcm_err(spcm, substream->stream,
"platform pcm open failed %d\n", ret);
return ret;
}

dev_dbg(component->dev, "period bytes min %zd, max %zd\n",
runtime->hw.period_bytes_min,
runtime->hw.period_bytes_max);
dev_dbg(component->dev, "period count min %d, max %d\n",
runtime->hw.periods_min,
runtime->hw.periods_max);
dev_dbg(component->dev, "buffer bytes max %zd\n",
runtime->hw.buffer_bytes_max);
spcm_dbg(spcm, substream->stream, "period bytes min %zd, max %zd\n",
runtime->hw.period_bytes_min, runtime->hw.period_bytes_max);
spcm_dbg(spcm, substream->stream, "period count min %d, max %d\n",
runtime->hw.periods_min, runtime->hw.periods_max);
spcm_dbg(spcm, substream->stream, "buffer bytes max %zd\n", runtime->hw.buffer_bytes_max);

return 0;
}
Expand All @@ -578,13 +570,12 @@ static int sof_pcm_close(struct snd_soc_component *component,
if (!spcm)
return -EINVAL;

dev_dbg(component->dev, "pcm: close stream %d dir %d\n",
spcm->pcm.pcm_id, substream->stream);
spcm_dbg(spcm, substream->stream, "Entry: close\n");

err = snd_sof_pcm_platform_close(sdev, substream);
if (err < 0) {
dev_err(component->dev, "error: pcm close failed %d\n",
err);
spcm_err(spcm, substream->stream,
"platform pcm close failed %d\n", err);
/*
* keep going, no point in preventing the close
* from happening
Expand Down Expand Up @@ -618,24 +609,23 @@ static int sof_pcm_new(struct snd_soc_component *component,
return 0;
}

dev_dbg(component->dev, "creating new PCM %s\n", spcm->pcm.pcm_name);
spcm_dbg(spcm, -1, "creating new PCM\n");

/* do we need to pre-allocate playback audio buffer pages */
if (!spcm->pcm.playback)
goto capture;

caps = &spcm->pcm.caps[stream];

/* pre-allocate playback audio buffer pages */
dev_dbg(component->dev,
"spcm: allocate %s playback DMA buffer size 0x%x max 0x%x\n",
caps->name, caps->buffer_size_min, caps->buffer_size_max);

if (!pcm->streams[stream].substream) {
dev_err(component->dev, "error: NULL playback substream!\n");
spcm_err(spcm, stream, "NULL playback substream!\n");
return -EINVAL;
}

/* pre-allocate playback audio buffer pages */
spcm_dbg(spcm, stream, "allocate %s playback DMA buffer size 0x%x max 0x%x\n",
caps->name, caps->buffer_size_min, caps->buffer_size_max);

snd_pcm_set_managed_buffer(pcm->streams[stream].substream,
SNDRV_DMA_TYPE_DEV_SG, sdev->dev,
0, le32_to_cpu(caps->buffer_size_max));
Expand All @@ -648,16 +638,15 @@ static int sof_pcm_new(struct snd_soc_component *component,

caps = &spcm->pcm.caps[stream];

/* pre-allocate capture audio buffer pages */
dev_dbg(component->dev,
"spcm: allocate %s capture DMA buffer size 0x%x max 0x%x\n",
caps->name, caps->buffer_size_min, caps->buffer_size_max);

if (!pcm->streams[stream].substream) {
dev_err(component->dev, "error: NULL capture substream!\n");
spcm_err(spcm, stream, "NULL capture substream!\n");
return -EINVAL;
}

/* pre-allocate capture audio buffer pages */
spcm_dbg(spcm, stream, "allocate %s capture DMA buffer size 0x%x max 0x%x\n",
caps->name, caps->buffer_size_min, caps->buffer_size_max);

snd_pcm_set_managed_buffer(pcm->streams[stream].substream,
SNDRV_DMA_TYPE_DEV_SG, sdev->dev,
0, le32_to_cpu(caps->buffer_size_max));
Expand Down
22 changes: 22 additions & 0 deletions sound/soc/sof/sof-audio.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -617,6 +617,28 @@ struct snd_sof_pcm *snd_sof_find_spcm_comp(struct snd_soc_component *scomp,
void snd_sof_pcm_period_elapsed(struct snd_pcm_substream *substream);
void snd_sof_pcm_init_elapsed_work(struct work_struct *work);

/*
* snd_sof_pcm specific wrappers for dev_dbg() and dev_err() to provide
* consistent and useful prints.
* The spcm_dbg() is prepared to handle a call without valid direction (dir == -1)
*/
#define spcm_dbg(__spcm, __dir, __fmt, ...) { \
if (__dir == -1) \
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ujfalusi this is really used only at the time of creation. Do we really need to special handle it just for that? In all practical cases, I think we're going to have the dir defined.

dev_dbg(__spcm->scomp->dev, "pcm%u (%s): " __fmt, \
__spcm->pcm.pcm_id, __spcm->pcm.pcm_name, \
##__VA_ARGS__); \
else \
dev_dbg(__spcm->scomp->dev, "pcm%u (%s), dir %d: " __fmt, \
__spcm->pcm.pcm_id, __spcm->pcm.pcm_name, __dir, \
##__VA_ARGS__); \
}

#define spcm_err(__spcm, __dir, __fmt, ...) \
dev_err(__spcm->scomp->dev, "%s: pcm%u (%s), dir %d: " __fmt, __func__, \
__spcm->pcm.pcm_id, \
__spcm->pcm.pcm_name, __dir, ##__VA_ARGS__)


#if IS_ENABLED(CONFIG_SND_SOC_SOF_COMPRESS)
void snd_sof_compr_fragment_elapsed(struct snd_compr_stream *cstream);
void snd_sof_compr_init_elapsed_work(struct work_struct *work);
Expand Down
Loading