Commit 852f2ed1 authored by Peter Ujfalusi's avatar Peter Ujfalusi Committed by Fabio Baltieri
Browse files

drivers: dma: dma_dw_common: Improve context information in log prints



The LOG_* macros already print the module name and the function, printting
again the __func__ have no additional benefit.

The debug prints lack context which can be used to identify the channel
which the message was printed for.
For example:
<inf> dma_dw_common: dw_dma_stop: dw_dma_stop: dma 0 channel drain time out

when multiple channels from multiple controllers are used we don't know
the exact channel that has been stopped:
<inf> dma_dw_common: dw_dma_stop: dma@7c000: channel 0 drain time out
<inf> dma_dw_common: dw_dma_stop: dma@7d000: channel 0 drain time out

Convert all LOG prints to add usable context to them and use the following
pattern wherever it is possible:
dma_dw_common: <function name>: <DMA device name>: message
for example:
<inf> dma_dw_common: dw_dma_stop: dma@7c000: channel 0 config

The parameter list of dw_dma_avail_data_size() and dw_dma_free_data_size()
extended to pass the dev pointer.

Signed-off-by: default avatarPeter Ujfalusi <peter.ujfalusi@linux.intel.com>
parent 83926830
Loading
Loading
Loading
Loading
+70 −71
Original line number Diff line number Diff line
@@ -38,7 +38,7 @@ void dw_dma_isr(const struct device *dev)

	status_intr = dw_read(dev_cfg->base, DW_INTR_STATUS);
	if (!status_intr) {
		LOG_ERR("status_intr = %d", status_intr);
		LOG_ERR("%s: status_intr = %d", dev->name, status_intr);
	}

	/* get the source of our IRQ. */
@@ -48,7 +48,7 @@ void dw_dma_isr(const struct device *dev)
	/* TODO: handle errors, just clear them atm */
	status_err = dw_read(dev_cfg->base, DW_STATUS_ERR);
	if (status_err) {
		LOG_ERR("status_err = %d\n", status_err);
		LOG_ERR("%s: status_err = %d\n", dev->name, status_err);
		dw_write(dev_cfg->base, DW_CLEAR_ERR, status_err);
	}

@@ -63,7 +63,8 @@ void dw_dma_isr(const struct device *dev)
		chan_data = &dev_data->chan[channel];

		if (chan_data->dma_blkcallback) {
			LOG_DBG("Dispatching block complete callback");
			LOG_DBG("%s: Dispatching block complete callback fro channel %d", dev->name,
				channel);

			/* Ensure the linked list (chan_data->lli) is
			 * freed in the user callback function once
@@ -87,7 +88,8 @@ void dw_dma_isr(const struct device *dev)
		chan_data->state = DW_DMA_IDLE;

		if (chan_data->dma_tfrcallback) {
			LOG_DBG("Dispatching transfer callback");
			LOG_DBG("%s: Dispatching transfer callback for channel %d", dev->name,
				channel);
			chan_data->dma_tfrcallback(dev,
						   chan_data->tfruser_data,
						   channel, DMA_STATUS_COMPLETE);
@@ -134,7 +136,7 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
	int ret = 0;

	if (channel >= DW_CHAN_COUNT) {
		LOG_ERR("%s: invalid dma channel %d", __func__, channel);
		LOG_ERR("%s: invalid dma channel %d", dev->name, channel);
		ret = -EINVAL;
		goto out;
	}
@@ -142,15 +144,13 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
	struct dw_dma_chan_data *chan_data = &dev_data->chan[channel];

	if (chan_data->state != DW_DMA_IDLE && chan_data->state != DW_DMA_PREPARED) {
		LOG_ERR("%s: dma %s channel %d must be inactive to "
			"reconfigure, currently %d", __func__, dev->name,
		LOG_ERR("%s: channel %d must be inactive to reconfigure, currently %d", dev->name,
			channel, chan_data->state);
		ret = -EBUSY;
		goto out;
	}

	LOG_DBG("%s: dma %s channel %d config",
	       __func__, dev->name, channel);
	LOG_DBG("%s: channel %d config", dev->name, channel);

	__ASSERT_NO_MSG(cfg->source_data_size == cfg->dest_data_size);
	__ASSERT_NO_MSG(cfg->source_burst_length == cfg->dest_burst_length);
@@ -160,23 +160,23 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
	if (cfg->source_data_size != 1 && cfg->source_data_size != 2 &&
	    cfg->source_data_size != 4 && cfg->source_data_size != 8 &&
	    cfg->source_data_size != 16) {
		LOG_ERR("%s: dma %s channel %d 'invalid source_data_size' value %d",
			__func__, dev->name, channel, cfg->source_data_size);
		LOG_ERR("%s: channel %d 'invalid source_data_size' value %d", dev->name, channel,
			cfg->source_data_size);
		ret = -EINVAL;
		goto out;
	}

	if (cfg->block_count > CONFIG_DMA_DW_LLI_POOL_SIZE) {
		LOG_ERR("%s: dma %s channel %d scatter gather list larger than"
		LOG_ERR("%s: channel %d scatter gather list larger than"
			" descriptors in pool, consider increasing CONFIG_DMA_DW_LLI_POOL_SIZE",
			__func__, dev->name, channel);
			dev->name, channel);
		ret = -EINVAL;
		goto out;
	}

	/* burst_size = (2 ^ msize) */
	msize = find_msb_set(cfg->source_burst_length) - 1;
	LOG_DBG("%s: dma %s channel %d m_size=%d", __func__, dev->name, channel, msize);
	LOG_DBG("%s: channel %d m_size=%d", dev->name, channel, msize);
	__ASSERT_NO_MSG(msize < 5);

	/* default channel config */
@@ -200,7 +200,7 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
	block_cfg = cfg->head_block;
	for (int i = 0; i < cfg->block_count; i++) {
		__ASSERT_NO_MSG(block_cfg != NULL);
		LOG_DBG("copying block_cfg %p to lli_desc %p", block_cfg, lli_desc);
		LOG_DBG("%s: copying block_cfg %p to lli_desc %p", dev->name, block_cfg, lli_desc);

		/* write CTL_LO for each lli */
		switch (cfg->source_data_size) {
@@ -226,13 +226,13 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
			lli_desc->ctrl_lo |= DW_CTLL_SRC_WIDTH(2);
			break;
		default:
			LOG_ERR("%s: dma %s channel %d invalid src width %d",
			       __func__, dev->name, channel, cfg->source_data_size);
			LOG_ERR("%s: channel %d invalid src width %d", dev->name, channel,
				cfg->source_data_size);
			ret = -EINVAL;
			goto out;
		}

		LOG_DBG("source data size: lli_desc %p, ctrl_lo %x",
		LOG_DBG("%s: source data size: lli_desc %p, ctrl_lo %x", dev->name,
			lli_desc, lli_desc->ctrl_lo);

		switch (cfg->dest_data_size) {
@@ -258,13 +258,14 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
			lli_desc->ctrl_lo |= DW_CTLL_DST_WIDTH(2);
			break;
		default:
			LOG_ERR("%s: dma %s channel %d invalid dest width %d",
				__func__, dev->name, channel, cfg->dest_data_size);
			LOG_ERR("%s: channel %d invalid dest width %d", dev->name, channel,
				cfg->dest_data_size);
			ret = -EINVAL;
			goto out;
		}

		LOG_DBG("dest data size: lli_desc %p, ctrl_lo %x", lli_desc, lli_desc->ctrl_lo);
		LOG_DBG("%s: dest data size: lli_desc %p, ctrl_lo %x", dev->name,
			lli_desc, lli_desc->ctrl_lo);

		lli_desc->ctrl_lo |= DW_CTLL_SRC_MSIZE(msize) |
			DW_CTLL_DST_MSIZE(msize);
@@ -273,7 +274,8 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
			lli_desc->ctrl_lo |= DW_CTLL_INT_EN; /* enable interrupt */
		}

		LOG_DBG("msize, int_en: lli_desc %p, ctrl_lo %x", lli_desc, lli_desc->ctrl_lo);
		LOG_DBG("%s: msize, int_en: lli_desc %p, ctrl_lo %x", dev->name,
			lli_desc, lli_desc->ctrl_lo);

		/* config the SINC and DINC fields of CTL_LO,
		 * SRC/DST_PER fields of CFG_HI
@@ -283,11 +285,11 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
			lli_desc->ctrl_lo |= DW_CTLL_FC_M2M | DW_CTLL_SRC_INC |
				DW_CTLL_DST_INC;
#if CONFIG_DMA_DW_HW_LLI
			LOG_DBG("setting LLP_D_EN, LLP_S_EN in lli_desc->ctrl_lo %x",
			LOG_DBG("%s: setting LLP_D_EN, LLP_S_EN in lli_desc->ctrl_lo %x", dev->name,
				lli_desc->ctrl_lo);
			lli_desc->ctrl_lo |=
				DW_CTLL_LLP_S_EN | DW_CTLL_LLP_D_EN;
			LOG_DBG("lli_desc->ctrl_lo %x", lli_desc->ctrl_lo);
			LOG_DBG("%s: lli_desc->ctrl_lo %x", dev->name, lli_desc->ctrl_lo);
#endif
#if CONFIG_DMA_DW
			chan_data->cfg_lo |= DW_CFGL_SRC_SW_HS;
@@ -332,23 +334,24 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
#endif
			break;
		default:
			LOG_ERR("%s: dma %s channel %d invalid direction %d",
			       __func__, dev->name, channel, cfg->channel_direction);
			LOG_ERR("%s: channel %d invalid direction %d", dev->name, channel,
				cfg->channel_direction);
			ret = -EINVAL;
			goto out;
		}

		LOG_DBG("direction: lli_desc %p, ctrl_lo %x, cfg_hi %x, cfg_lo %x",
		LOG_DBG("%s: direction: lli_desc %p, ctrl_lo %x, cfg_hi %x, cfg_lo %x", dev->name,
			lli_desc, lli_desc->ctrl_lo, chan_data->cfg_hi, chan_data->cfg_lo);

		dw_dma_mask_address(block_cfg, lli_desc, cfg->channel_direction);

		LOG_DBG("mask address: lli_desc %p, ctrl_lo %x, cfg_hi %x, cfg_lo %x",
			lli_desc, lli_desc->ctrl_lo, chan_data->cfg_hi, chan_data->cfg_lo);
		LOG_DBG("%s: mask address: lli_desc %p, ctrl_lo %x, cfg_hi %x, cfg_lo %x",
			dev->name, lli_desc, lli_desc->ctrl_lo, chan_data->cfg_hi,
			chan_data->cfg_lo);

		if (block_cfg->block_size > DW_CTLH_BLOCK_TS_MASK) {
			LOG_ERR("%s: dma %s channel %d block size too big %d",
			       __func__, dev->name, channel, block_cfg->block_size);
			LOG_ERR("%s: channel %d block size too big %d", dev->name, channel,
				block_cfg->block_size);
			ret = -EINVAL;
			goto out;
		}
@@ -357,15 +360,16 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
		lli_desc->ctrl_hi |= DW_CTLH_CLASS(dev_data->channel_data->chan[channel].class) |
			(block_cfg->block_size & DW_CTLH_BLOCK_TS_MASK);

		LOG_DBG("block_size, class: lli_desc %p, ctrl_lo %x, cfg_hi %x, cfg_lo %x",
			lli_desc, lli_desc->ctrl_lo, chan_data->cfg_hi, chan_data->cfg_lo);
		LOG_DBG("%s: block_size, class: lli_desc %p, ctrl_lo %x, cfg_hi %x, cfg_lo %x",
			dev->name, lli_desc, lli_desc->ctrl_lo, chan_data->cfg_hi,
			chan_data->cfg_lo);

		chan_data->ptr_data.buffer_bytes += block_cfg->block_size;

		/* set next descriptor in list */
		lli_desc->llp = (uintptr_t)(lli_desc + 1);

		LOG_DBG("lli_desc llp %x", lli_desc->llp);
		LOG_DBG("%s: lli_desc llp %x", dev->name, lli_desc->llp);

		/* next descriptor */
		lli_desc++;
@@ -383,9 +387,10 @@ int dw_dma_config(const struct device *dev, uint32_t channel,
	} else {
		lli_desc_tail->llp = 0;
#if CONFIG_DMA_DW_HW_LLI
		LOG_DBG("Clearing LLP_S_EN, LLP_D_EN from tail LLI %x", lli_desc_tail->ctrl_lo);
		LOG_DBG("%s: Clearing LLP_S_EN, LLP_D_EN from tail LLI %x", dev->name,
			lli_desc_tail->ctrl_lo);
		lli_desc_tail->ctrl_lo &= ~(DW_CTLL_LLP_S_EN | DW_CTLL_LLP_D_EN);
		LOG_DBG("ctrl_lo %x", lli_desc_tail->ctrl_lo);
		LOG_DBG("%s: ctrl_lo %x", dev->name, lli_desc_tail->ctrl_lo);
#endif
	}

@@ -458,18 +463,15 @@ int dw_dma_start(const struct device *dev, uint32_t channel)

	/* validate channel state */
	if (chan_data->state != DW_DMA_PREPARED) {
		LOG_ERR("%s: dma %s channel %d not ready ena 0x%x status 0x%x",
		       __func__, dev->name, channel,
		       dw_read(dev_cfg->base, DW_DMA_CHAN_EN),
		       chan_data->state);
		LOG_ERR("%s: channel %d not ready ena 0x%x status 0x%x", dev->name, channel,
			dw_read(dev_cfg->base, DW_DMA_CHAN_EN), chan_data->state);
		ret = -EBUSY;
		goto out;
	}

	/* is valid stream */
	if (!chan_data->lli) {
		LOG_ERR("%s: dma %s channel %d invalid stream",
		       __func__, dev->name, channel);
		LOG_ERR("%s: channel %d invalid stream", dev->name, channel);
		ret = -EINVAL;
		goto out;
	}
@@ -484,10 +486,10 @@ int dw_dma_start(const struct device *dev, uint32_t channel)

	if (masked_ctrl_lo) {
		llp = (uint32_t)lli;
		LOG_DBG("Setting llp");
		LOG_DBG("%s: Setting llp", dev->name);
	}
	dw_write(dev_cfg->base, DW_LLP(channel), llp);
	LOG_DBG("ctrl_lo %x, masked ctrl_lo %x, LLP %x",
	LOG_DBG("%s: ctrl_lo %x, masked ctrl_lo %x, LLP %x", dev->name,
		lli->ctrl_lo, masked_ctrl_lo, dw_read(dev_cfg->base, DW_LLP(channel)));
#endif /* CONFIG_DMA_DW_HW_LLI */

@@ -511,20 +513,20 @@ int dw_dma_start(const struct device *dev, uint32_t channel)
	dw_write(dev_cfg->base, DW_CFG_HIGH(channel), chan_data->cfg_hi);

#ifdef CONFIG_DMA_64BIT
	LOG_DBG("start: sar %llx, dar %llx, ctrl_lo %x, ctrl_hi %x, cfg_lo %x, cfg_hi %x, llp %x",
		lli->sar, lli->dar, lli->ctrl_lo, lli->ctrl_hi, chan_data->cfg_lo,
	LOG_DBG("%s: sar %llx, dar %llx, ctrl_lo %x, ctrl_hi %x, cfg_lo %x, cfg_hi %x, llp %x",
		dev->name, lli->sar, lli->dar, lli->ctrl_lo, lli->ctrl_hi, chan_data->cfg_lo,
		chan_data->cfg_hi, dw_read(dev_cfg->base, DW_LLP(channel))
		);
#else
	LOG_DBG("start: sar %x, dar %x, ctrl_lo %x, ctrl_hi %x, cfg_lo %x, cfg_hi %x, llp %x",
		lli->sar, lli->dar, lli->ctrl_lo, lli->ctrl_hi, chan_data->cfg_lo,
	LOG_DBG("%s: sar %x, dar %x, ctrl_lo %x, ctrl_hi %x, cfg_lo %x, cfg_hi %x, llp %x",
		dev->name, lli->sar, lli->dar, lli->ctrl_lo, lli->ctrl_hi, chan_data->cfg_lo,
		chan_data->cfg_hi, dw_read(dev_cfg->base, DW_LLP(channel))
		);
#endif /* CONFIG_DMA_64BIT */

#ifdef CONFIG_DMA_DW_HW_LLI
	if (lli->ctrl_lo & DW_CTLL_D_SCAT_EN) {
		LOG_DBG("configuring DW_DSR");
		LOG_DBG("%s: configuring DW_DSR", dev->name);
		uint32_t words_per_tfr = (lli->ctrl_hi & DW_CTLH_BLOCK_TS_MASK) >>
			((lli->ctrl_lo & DW_CTLL_DST_WIDTH_MASK) >> DW_CTLL_DST_WIDTH_SHIFT);
		dw_write(dev_cfg->base, DW_DSR(channel),
@@ -574,8 +576,7 @@ int dw_dma_stop(const struct device *dev, uint32_t channel)
	int i;
#endif

	LOG_DBG("%s: dma %s channel %d stop",
		__func__, dev->name, channel);
	LOG_DBG("%s: channel %d stop", dev->name, channel);

	/* Validate the channel state */
	if (chan_data->state != DW_DMA_ACTIVE &&
@@ -595,7 +596,7 @@ int dw_dma_stop(const struct device *dev, uint32_t channel)
	bool fifo_empty = WAIT_FOR(dw_read(dev_cfg->base, DW_CFG_LOW(channel)) & DW_CFGL_FIFO_EMPTY,
				DW_DMA_TIMEOUT, k_busy_wait(DW_DMA_TIMEOUT/10));
	if (!fifo_empty) {
		LOG_WRN("%s: dma %d channel drain time out", __func__, channel);
		LOG_WRN("%s: channel %d drain time out", dev->name, channel);

		/* Continue even if draining timed out to make sure that the channel is going to be
		 * disabled.
@@ -611,7 +612,7 @@ int dw_dma_stop(const struct device *dev, uint32_t channel)
	bool is_disabled = WAIT_FOR(!(dw_read(dev_cfg->base, DW_DMA_CHAN_EN) & DW_CHAN(channel)),
				    DW_DMA_TIMEOUT, k_busy_wait(DW_DMA_TIMEOUT/10));
	if (!is_disabled) {
		LOG_ERR("%s: dma %d channel disable timeout", __func__, channel);
		LOG_ERR("%s: channel %d disable timeout", dev->name, channel);
		return -ETIMEDOUT;
	}

@@ -647,8 +648,7 @@ int dw_dma_resume(const struct device *dev, uint32_t channel)
		goto out;
	}

	LOG_DBG("%s: dma %s channel %d resume",
		__func__, dev->name, channel);
	LOG_DBG("%s: channel %d resume", dev->name, channel);

	dw_write(dev_cfg->base, DW_CFG_LOW(channel), chan_data->cfg_lo);

@@ -680,8 +680,7 @@ int dw_dma_suspend(const struct device *dev, uint32_t channel)
	}


	LOG_DBG("%s: dma %s channel %d suspend",
		__func__, dev->name, channel);
	LOG_DBG("%s: channel %d suspend", dev->name, channel);

	dw_write(dev_cfg->base, DW_CFG_LOW(channel),
		      chan_data->cfg_lo | DW_CFGL_SUSPEND);
@@ -713,13 +712,12 @@ int dw_dma_setup(const struct device *dev)
	}

	if (!i) {
		LOG_ERR("%s: dma %s setup failed",
			__func__, dev->name);
		LOG_ERR("%s: setup failed", dev->name);
		ret = -EIO;
		goto out;
	}

	LOG_DBG("%s: dma %s", __func__, dev->name);
	LOG_DBG("%s: ENTER", dev->name);

	for (i = 0; i <  DW_CHAN_COUNT; i++) {
		dw_read(dev_cfg->base, DW_DMA_CHAN_EN);
@@ -754,7 +752,7 @@ out:
	return ret;
}

static int dw_dma_avail_data_size(uint32_t base,
static int dw_dma_avail_data_size(const struct device *dev, uint32_t base,
				  struct dw_dma_chan_data *chan_data,
				  uint32_t channel)
{
@@ -777,17 +775,17 @@ static int dw_dma_avail_data_size(uint32_t base,
		if (delta) {
			size = chan_data->ptr_data.buffer_bytes;
		} else {
			LOG_DBG("%s size is 0!", __func__);
			LOG_DBG("%s: channel %d: size is 0!", dev->name, channel);
		}
	}

	LOG_DBG("DAR %x reader 0x%x free 0x%x avail 0x%x", write_ptr, read_ptr,
		chan_data->ptr_data.buffer_bytes - size, size);
	LOG_DBG("%s: channel %d: DAR %x reader 0x%x free 0x%x avail 0x%x", dev->name, channel,
		write_ptr, read_ptr, chan_data->ptr_data.buffer_bytes - size, size);

	return size;
}

static int dw_dma_free_data_size(uint32_t base,
static int dw_dma_free_data_size(const struct device *dev, uint32_t base,
				 struct dw_dma_chan_data *chan_data,
				 uint32_t channel)
{
@@ -809,12 +807,12 @@ static int dw_dma_free_data_size(uint32_t base,
		if (delta) {
			size = chan_data->ptr_data.buffer_bytes;
		} else {
			LOG_DBG("%s size is 0!", __func__);
			LOG_DBG("%s: channel %d: size is 0!", dev->name, channel);
		}
	}

	LOG_DBG("SAR %x writer 0x%x free 0x%x avail 0x%x", read_ptr, write_ptr, size,
		chan_data->ptr_data.buffer_bytes - size);
	LOG_DBG("%s: channel %d: SAR %x writer 0x%x free 0x%x avail 0x%x", dev->name, channel,
		read_ptr, write_ptr, size, chan_data->ptr_data.buffer_bytes - size);

	return size;
}
@@ -834,16 +832,17 @@ int dw_dma_get_status(const struct device *dev, uint32_t channel,

	if (chan_data->direction == MEMORY_TO_MEMORY ||
	    chan_data->direction == PERIPHERAL_TO_MEMORY) {
		stat->pending_length = dw_dma_avail_data_size(dev_cfg->base, chan_data, channel);
		stat->pending_length = dw_dma_avail_data_size(dev, dev_cfg->base, chan_data,
							      channel);
		stat->free = chan_data->ptr_data.buffer_bytes - stat->pending_length;

	} else {
		stat->free = dw_dma_free_data_size(dev_cfg->base, chan_data, channel);
		stat->free = dw_dma_free_data_size(dev, dev_cfg->base, chan_data, channel);
		stat->pending_length = chan_data->ptr_data.buffer_bytes - stat->free;
	}
#if CONFIG_DMA_DW_HW_LLI
	if (!(dw_read(dev_cfg->base, DW_DMA_CHAN_EN) & DW_CHAN(channel))) {
		LOG_ERR("xrun detected");
		LOG_ERR("%s: xrun detected", dev->name);
		return -EPIPE;
	}
#endif