Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
10 changes: 10 additions & 0 deletions Kconfig.zephyr-log
Original file line number Diff line number Diff line change
Expand Up @@ -51,4 +51,14 @@ config SOF_LOG_LEVEL
default 3 if SOF_LOG_LEVEL_INF
default 4 if SOF_LOG_LEVEL_DBG

config SOF_LOG_DBG_BUFFER
bool "Log buffer state on each consume/produce call"
default n
help
Dumps buffer struct audio_stream values on each call to comp_update_buffer_consume()
and comp_update_buffer_produce().
WARNING: Produces too much log output which usually results in many log messaged been
dropped! Also, if selected log backend formats log messages at runtime, enabling this
option results in significant CPU load!

endmenu
3 changes: 3 additions & 0 deletions app/boards/intel_adsp_ace15_mtpm.conf
Original file line number Diff line number Diff line change
Expand Up @@ -88,3 +88,6 @@ CONFIG_CLOCK_CONTROL=y
CONFIG_DEBUG_COREDUMP=y
CONFIG_DEBUG_COREDUMP_BACKEND_INTEL_ADSP_MEM_WINDOW=y
CONFIG_DEBUG_COREDUMP_MEMORY_DUMP_MIN=y

CONFIG_PROBE=y
CONFIG_PROBE_DMA_MAX=2
8 changes: 8 additions & 0 deletions src/audio/buffer.c
Original file line number Diff line number Diff line change
Expand Up @@ -228,11 +228,13 @@ void comp_update_buffer_produce(struct comp_buffer __sparse_cache *buffer, uint3

/* return if no bytes */
if (!bytes) {
#if CONFIG_SOF_LOG_DBG_BUFFER
Copy link
Contributor

Choose a reason for hiding this comment

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

it build nothing as default with buf_dbg, if change build log level, then it will print lot of log messages, I just mean default there is no cycle cost, and enable it indeed cost too much, not sure need a config to just cover is expensive or not.

buf_dbg(buffer, "comp_update_buffer_produce(), no bytes to produce, source->comp.id = %u, source->comp.type = %u, sink->comp.id = %u, sink->comp.type = %u",
buffer->source ? dev_comp_id(buffer->source) : (unsigned int)UINT32_MAX,
buffer->source ? dev_comp_type(buffer->source) : (unsigned int)UINT32_MAX,
buffer->sink ? dev_comp_id(buffer->sink) : (unsigned int)UINT32_MAX,
buffer->sink ? dev_comp_type(buffer->sink) : (unsigned int)UINT32_MAX);
#endif
return;
}

Expand All @@ -242,6 +244,7 @@ void comp_update_buffer_produce(struct comp_buffer __sparse_cache *buffer, uint3
notifier_event(cache_to_uncache(buffer), NOTIFIER_ID_BUFFER_PRODUCE,
NOTIFIER_TARGET_CORE_LOCAL, &cb_data, sizeof(cb_data));

#if CONFIG_SOF_LOG_DBG_BUFFER
buf_dbg(buffer, "comp_update_buffer_produce(), ((buffer->avail << 16) | buffer->free) = %08x, ((buffer->id << 16) | buffer->size) = %08x",
(audio_stream_get_avail_bytes(&buffer->stream) << 16) |
audio_stream_get_free_bytes(&buffer->stream),
Expand All @@ -251,6 +254,7 @@ void comp_update_buffer_produce(struct comp_buffer __sparse_cache *buffer, uint3
(char *)audio_stream_get_addr(&buffer->stream)) << 16 |
((char *)audio_stream_get_wptr(&buffer->stream) -
(char *)audio_stream_get_addr(&buffer->stream)));
#endif
}

void comp_update_buffer_consume(struct comp_buffer __sparse_cache *buffer, uint32_t bytes)
Expand All @@ -263,11 +267,13 @@ void comp_update_buffer_consume(struct comp_buffer __sparse_cache *buffer, uint3

/* return if no bytes */
if (!bytes) {
#if CONFIG_SOF_LOG_DBG_BUFFER
buf_dbg(buffer, "comp_update_buffer_consume(), no bytes to consume, source->comp.id = %u, source->comp.type = %u, sink->comp.id = %u, sink->comp.type = %u",
buffer->source ? dev_comp_id(buffer->source) : (unsigned int)UINT32_MAX,
buffer->source ? dev_comp_type(buffer->source) : (unsigned int)UINT32_MAX,
buffer->sink ? dev_comp_id(buffer->sink) : (unsigned int)UINT32_MAX,
buffer->sink ? dev_comp_type(buffer->sink) : (unsigned int)UINT32_MAX);
#endif
return;
}

Expand All @@ -276,6 +282,7 @@ void comp_update_buffer_consume(struct comp_buffer __sparse_cache *buffer, uint3
notifier_event(cache_to_uncache(buffer), NOTIFIER_ID_BUFFER_CONSUME,
NOTIFIER_TARGET_CORE_LOCAL, &cb_data, sizeof(cb_data));

#if CONFIG_SOF_LOG_DBG_BUFFER
buf_dbg(buffer, "comp_update_buffer_consume(), (buffer->avail << 16) | buffer->free = %08x, (buffer->id << 16) | buffer->size = %08x, (buffer->r_ptr - buffer->addr) << 16 | (buffer->w_ptr - buffer->addr)) = %08x",
(audio_stream_get_avail_bytes(&buffer->stream) << 16) |
audio_stream_get_free_bytes(&buffer->stream),
Expand All @@ -284,6 +291,7 @@ void comp_update_buffer_consume(struct comp_buffer __sparse_cache *buffer, uint3
(char *)audio_stream_get_addr(&buffer->stream)) << 16 |
((char *)audio_stream_get_wptr(&buffer->stream) -
(char *)audio_stream_get_addr(&buffer->stream)));
#endif
}

/*
Expand Down
4 changes: 2 additions & 2 deletions src/audio/module_adapter/module_adapter.c
Original file line number Diff line number Diff line change
Expand Up @@ -858,7 +858,7 @@ static int module_adapter_audio_stream_copy_1to1(struct comp_dev *dev)
buffer_stream_writeback(sink_c, mod->output_buffers[0].size);

if (mod->output_buffers[0].size)
audio_stream_produce(&sink_c->stream, mod->output_buffers[0].size);
comp_update_buffer_produce(sink_c, mod->output_buffers[0].size);

/* release all buffers */
buffer_release(sink_c);
Expand Down Expand Up @@ -973,7 +973,7 @@ static int module_adapter_audio_stream_type_copy(struct comp_dev *dev)
if (!mod->skip_sink_buffer_writeback)
buffer_stream_writeback(sink_c, mod->output_buffers[i].size);
if (mod->output_buffers[i].size)
audio_stream_produce(&sink_c->stream, mod->output_buffers[i].size);
comp_update_buffer_produce(sink_c, mod->output_buffers[i].size);
}

mod->total_data_produced += mod->output_buffers[0].size;
Expand Down
101 changes: 97 additions & 4 deletions src/probe/probe.c
Original file line number Diff line number Diff line change
Expand Up @@ -121,6 +121,7 @@ static int probe_dma_buffer_init(struct probe_dma_buf *buffer, uint32_t size,
return 0;
}

#if !CONFIG_ZEPHYR_NATIVE_DRIVERS
Copy link
Contributor

Choose a reason for hiding this comment

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

Just a nitpick, I find it slightly annoying that this in #if the condition is negated, but in all the following ones the native drivers version comes first.

/**
* \brief Request DMA and initialize DMA for probes with correct alignment,
* size and specific channel.
Expand Down Expand Up @@ -191,7 +192,67 @@ static int probe_dma_init(struct probe_dma_ext *dma, uint32_t direction)

return 0;
}
#else
static int probe_dma_init(struct probe_dma_ext *dma, uint32_t direction)
{
uint32_t addr_align;
uint32_t channel;
struct dma_config dma_cfg;
struct dma_block_config dma_block_cfg;
int err = 0;

channel = ((union ipc4_connector_node_id)dma->stream_tag).f.v_index;

/* request DMA in the dir LMEM->HMEM with shared access */
dma->dc.dmac = dma_get(direction, 0, DMA_DEV_HOST,
DMA_ACCESS_SHARED);
if (!dma->dc.dmac) {
tr_err(&pr_tr, "probe_dma_init(): dma->dc.dmac = NULL");
return -ENODEV;
}

/* get required address alignment for dma buffer */
err = dma_get_attribute(dma->dc.dmac->z_dev, DMA_ATTR_BUFFER_ADDRESS_ALIGNMENT,
&addr_align);
if (err < 0)
return err;

channel = dma_request_channel(dma->dc.dmac->z_dev, &channel);
if (channel < 0) {
tr_err(&pr_tr, "probe_dma_init(): dma_request_channel() failed");
return -EINVAL;
}
dma->dc.chan = &dma->dc.dmac->chan[channel];

/* initialize dma buffer */
err = probe_dma_buffer_init(&dma->dmapb, PROBE_BUFFER_LOCAL_SIZE, addr_align);
if (err < 0)
return err;

dma_cfg.block_count = 1;
dma_cfg.source_data_size = sizeof(uint32_t);
dma_cfg.dest_data_size = sizeof(uint32_t);
dma_cfg.head_block = &dma_block_cfg;
dma_block_cfg.block_size = (uint32_t)dma->dmapb.size;

switch (direction) {
case DMA_DIR_LMEM_TO_HMEM:
dma_cfg.channel_direction = MEMORY_TO_HOST;
dma_block_cfg.source_address = (uint32_t)dma->dmapb.addr;
break;
case DMA_DIR_HMEM_TO_LMEM:
dma_cfg.channel_direction = HOST_TO_MEMORY;
dma_block_cfg.dest_address = (uint32_t)dma->dmapb.addr;
break;
}

err = dma_config(dma->dc.dmac->z_dev, dma->dc.chan->index, &dma_cfg);
Copy link
Collaborator

Choose a reason for hiding this comment

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

return dma_config(...)

if (err < 0)
return err;

return 0;
}
#endif
/**
* \brief Stop, deinit and free DMA and buffer used by probes.
*
Expand All @@ -200,14 +261,20 @@ static int probe_dma_init(struct probe_dma_ext *dma, uint32_t direction)
static int probe_dma_deinit(struct probe_dma_ext *dma)
{
int err = 0;

#if CONFIG_ZEPHYR_NATIVE_DRIVERS
err = dma_stop(dma->dc.dmac->z_dev, dma->dc.chan->index);
#else
err = dma_stop_legacy(dma->dc.chan);
#endif
if (err < 0) {
tr_err(&pr_tr, "probe_dma_deinit(): dma_stop() failed");
return err;
}

#if CONFIG_ZEPHYR_NATIVE_DRIVERS
dma_release_channel(dma->dc.dmac->z_dev, dma->dc.chan->index);
#else
dma_channel_put_legacy(dma->dc.chan);
#endif
Copy link
Contributor

Choose a reason for hiding this comment

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

just a suggestion, use one #if from line 264 - 277, this can remove one more "#if #else #endif", overhead is duplicated err message.

Copy link
Collaborator

Choose a reason for hiding this comment

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

just a suggestion, use one #if from line 264 - 277, this can remove one more "#if #else #endif", overhead is duplicated err message.

@btian1 The difference is purely for the reader - the compilation result is the same. And in its present form the difference between the two cases is easier to see, so, I'd keep it as is. In general, however, yes, the fewer preprocessor conditionals we use, especially in .c, the better

dma_put(dma->dc.dmac);

rfree((void *)dma->dmapb.addr);
Expand Down Expand Up @@ -249,10 +316,15 @@ static enum task_state probe_task(void *data)
avail = _probe->ext_dma.dmapb.end_addr - _probe->ext_dma.dmapb.r_ptr;

if (avail > 0)
#if CONFIG_ZEPHYR_NATIVE_DRIVERS
err = dma_reload(_probe->ext_dma.dc.dmac->z_dev,
_probe->ext_dma.dc.chan->index, 0, 0, avail);
#else
err = dma_copy_to_host_nowait(&_probe->ext_dma.dc,
&_probe->ext_dma.config, 0,
(void *)_probe->ext_dma.dmapb.r_ptr,
avail);
#endif
else
return SOF_TASK_STATE_RESCHEDULE;

Expand Down Expand Up @@ -307,8 +379,11 @@ int probe_init(const struct probe_dma *probe_dma)
_probe->ext_dma.stream_tag = PROBE_DMA_INVALID;
return err;
}

#if CONFIG_ZEPHYR_NATIVE_DRIVERS
err = dma_start(_probe->ext_dma.dc.dmac->z_dev, _probe->ext_dma.dc.chan->index);
#else
err = dma_start_legacy(_probe->ext_dma.dc.chan);
#endif
if (err < 0) {
tr_err(&pr_tr, "probe_init(): failed to start extraction dma");

Expand Down Expand Up @@ -885,9 +960,17 @@ static void probe_cb_produce(void *arg, enum notify_id type, void *data)
}
dma = &_probe->inject_dma[j];
/* get avail data info */
#if CONFIG_ZEPHYR_NATIVE_DRIVERS
struct dma_status stat;

ret = dma_get_status(dma->dc.dmac->z_dev, dma->dc.chan->index, &stat);
dma->dmapb.avail = stat.pending_length;
free_bytes = stat.free;
#else
ret = dma_get_data_size_legacy(dma->dc.chan,
&dma->dmapb.avail,
&free_bytes);
#endif
if (ret < 0) {
tr_err(&pr_tr, "probe_cb_produce(): dma_get_data_size() failed, ret = %u",
ret);
Expand Down Expand Up @@ -929,10 +1012,15 @@ static void probe_cb_produce(void *arg, enum notify_id type, void *data)

/* check if copy_bytes is still valid for dma copy */
if (copy_bytes > 0) {
#if CONFIG_ZEPHYR_NATIVE_DRIVERS
ret = dma_reload(dma->dc.dmac->z_dev,
dma->dc.chan->index, 0, 0, copy_bytes);
#else
ret = dma_copy_to_host_nowait(&dma->dc,
&dma->config, 0,
(void *)dma->dmapb.r_ptr,
copy_bytes);
#endif
if (ret < 0)
goto err;

Expand Down Expand Up @@ -1076,7 +1164,7 @@ int probe_point_add(uint32_t count, const struct probe_point *probe)

fw_logs = enable_logs(&probe[i]);

if (!fw_logs && probe[i].purpose == PROBE_PURPOSE_EXTRACTION) {
if (!fw_logs) {
#if CONFIG_IPC_MAJOR_4
dev = ipc_get_comp_by_id(ipc_get(),
IPC4_COMP_ID(buf_id->fields.module_id,
Expand Down Expand Up @@ -1161,7 +1249,12 @@ int probe_point_add(uint32_t count, const struct probe_point *probe)

return -EINVAL;
}
#if CONFIG_ZEPHYR_NATIVE_DRIVERS
if (dma_start(_probe->inject_dma[j].dc.dmac->z_dev,
_probe->inject_dma[j].dc.chan->index) < 0) {
#else
if (dma_start_legacy(_probe->inject_dma[j].dc.chan) < 0) {
#endif
Copy link
Collaborator

Choose a reason for hiding this comment

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

this confuses at least some editors. They don't understand that only one of the ifs is compiled, so they interpret it as

if (x) {
if (y) {

and keep trying to "fix" alignment for a nested if and also gets confused about too few closing braces. Not something critical and not even an issue for everybody, but at least we did modify one such code fragment for this reason to read

#if X
if (a)
#else
if (b)
#endif
{

This contradicts style but at least the editor is happy about balanced braces

tr_err(&pr_tr, "probe_point_add(): failed to start dma");

return -EBUSY;
Expand Down