[PATCH v3 01/10] spi: dw: Convert calls to debug to log_*

[Sean Anderson]

This allows different log levels to be enabled or disabled depending on the
desired level of verbosity. In particular, it allows for general debug
information to be printed while excluding more verbose logging which may
interfere with timing.

log_xxx was chosen over dev_xxx because it shows more information (such as
the calling function) and it can be enabled and disabled at run-time.

Signed-off-by: Sean Anderson <seanga2 at gmail.com>
Tested-by Eugeniy Paltsev <Eugeniy.Paltsev at synopsys.com>
---

Changes in v3:
- Lower the log level of some messages
- Prefix user-facing logs with SPI@<address>
- Reword error messages as "message (error %d)"

Changes in v2:
- New

 drivers/spi/designware_spi.c | 36 +++++++++++++++++++-----------------
 1 file changed, 19 insertions(+), 17 deletions(-)

diff --git a/drivers/spi/designware_spi.c b/drivers/spi/designware_spi.c
index 2559aac2e9..c4efb5d7c4 100644
--- a/drivers/spi/designware_spi.c
+++ b/drivers/spi/designware_spi.c
@@ -9,6 +9,7 @@
  * Copyright (c) 2009, Intel Corporation.
  */
 
+#define LOG_CATEGORY UCLASS_SPI
 #include <common.h>
 #include <log.h>
 #include <asm-generic/gpio.h>
@@ -139,7 +140,8 @@ static int request_gpio_cs(struct udevice *bus)
 		return 0;
 
 	if (ret < 0) {
-		printf("Error: %d: Can't get %s gpio!\n", ret, bus->name);
+		log_err("SPI@%p: Couldn't request gpio! (error %d)\n",
+			priv->regs, ret);
 		return ret;
 	}
 
@@ -148,7 +150,7 @@ static int request_gpio_cs(struct udevice *bus)
 				      GPIOD_IS_OUT | GPIOD_IS_OUT_ACTIVE);
 	}
 
-	debug("%s: used external gpio for CS management\n", __func__);
+	log_debug("Using external gpio for CS management\n");
 #endif
 	return 0;
 }
@@ -162,8 +164,7 @@ static int dw_spi_ofdata_to_platdata(struct udevice *bus)
 	/* Use 500KHz as a suitable default */
 	plat->frequency = dev_read_u32_default(bus, "spi-max-frequency",
 					       500000);
-	debug("%s: regs=%p max-frequency=%d\n", __func__, plat->regs,
-	      plat->frequency);
+	log_info("SPI@%p max-frequency=%d\n", plat->regs, plat->frequency);
 
 	return request_gpio_cs(bus);
 }
@@ -196,7 +197,7 @@ static void spi_hw_init(struct dw_spi_priv *priv)
 		priv->fifo_len = (fifo == 1) ? 0 : fifo;
 		dw_write(priv, DW_SPI_TXFLTR, 0);
 	}
-	debug("%s: fifo_len=%d\n", __func__, priv->fifo_len);
+	log_debug("fifo_len=%d\n", priv->fifo_len);
 }
 
 /*
@@ -221,8 +222,7 @@ __weak int dw_spi_get_clk(struct udevice *bus, ulong *rate)
 	if (!*rate)
 		goto err_rate;
 
-	debug("%s: get spi controller clk via device tree: %lu Hz\n",
-	      __func__, *rate);
+	log_debug("Got clock via device tree: %lu Hz\n", *rate);
 
 	return 0;
 
@@ -247,14 +247,16 @@ static int dw_spi_reset(struct udevice *bus)
 		if (ret == -ENOENT || ret == -ENOTSUPP)
 			return 0;
 
-		dev_warn(bus, "Can't get reset: %d\n", ret);
+		log_warning("SPI@%p: Couldn't find/assert reset device (error %d)\n",
+			    priv->regs, ret);
 		return ret;
 	}
 
 	ret = reset_deassert_bulk(&priv->resets);
 	if (ret) {
 		reset_release_bulk(&priv->resets);
-		dev_err(bus, "Failed to reset: %d\n", ret);
+		log_err("SPI@%p: Failed to de-assert reset for SPI (error %d)\n",
+			priv->regs, ret);
 		return ret;
 	}
 
@@ -333,7 +335,7 @@ static void dw_writer(struct dw_spi_priv *priv)
 				txw = *(u16 *)(priv->tx);
 		}
 		dw_write(priv, DW_SPI_DR, txw);
-		debug("%s: tx=0x%02x\n", __func__, txw);
+		log_content("tx=0x%02x\n", txw);
 		priv->tx += priv->bits_per_word >> 3;
 	}
 }
@@ -345,7 +347,7 @@ static void dw_reader(struct dw_spi_priv *priv)
 
 	while (max--) {
 		rxw = dw_read(priv, DW_SPI_DR);
-		debug("%s: rx=0x%02x\n", __func__, rxw);
+		log_content("rx=0x%02x\n", rxw);
 
 		/* Care about rx if the transfer's original "rx" is not null */
 		if (priv->rx_end - priv->len) {
@@ -400,7 +402,7 @@ static int dw_spi_xfer(struct udevice *dev, unsigned int bitlen,
 
 	/* spi core configured to do 8 bit transfers */
 	if (bitlen % 8) {
-		debug("Non byte aligned SPI transfer.\n");
+		log_err("Non byte aligned SPI transfer.\n");
 		return -1;
 	}
 
@@ -427,7 +429,7 @@ static int dw_spi_xfer(struct udevice *dev, unsigned int bitlen,
 	cr0 |= (priv->tmode << SPI_TMOD_OFFSET);
 
 	priv->len = bitlen >> 3;
-	debug("%s: rx=%p tx=%p len=%d [bytes]\n", __func__, rx, tx, priv->len);
+	log_debug("rx=%p tx=%p len=%d [bytes]\n", rx, tx, priv->len);
 
 	priv->tx = (void *)tx;
 	priv->tx_end = priv->tx + priv->len;
@@ -437,7 +439,7 @@ static int dw_spi_xfer(struct udevice *dev, unsigned int bitlen,
 	/* Disable controller before writing control registers */
 	spi_enable_chip(priv, 0);
 
-	debug("%s: cr0=%08x\n", __func__, cr0);
+	log_debug("cr0=%08x\n", cr0);
 	/* Reprogram cr0 only if changed */
 	if (dw_read(priv, DW_SPI_CTRL0) != cr0)
 		dw_write(priv, DW_SPI_CTRL0, cr0);
@@ -497,8 +499,8 @@ static int dw_spi_set_speed(struct udevice *bus, uint speed)
 	spi_enable_chip(priv, 1);
 
 	priv->freq = speed;
-	debug("%s: regs=%p speed=%d clk_div=%d\n", __func__, priv->regs,
-	      priv->freq, clk_div);
+	log_debug("SPI@%p speed=%d clk_div=%d\n", priv->regs, priv->freq,
+		  clk_div);
 
 	return 0;
 }
@@ -513,7 +515,7 @@ static int dw_spi_set_mode(struct udevice *bus, uint mode)
 	 * real transfer function.
 	 */
 	priv->mode = mode;
-	debug("%s: regs=%p, mode=%d\n", __func__, priv->regs, priv->mode);
+	log_debug("SPI@%p mode=%d\n", priv->regs, priv->mode);
 
 	return 0;
 }
-- 
2.28.0