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

Heinrich Schuchardt
2020-08-08T05:14:39Z

On 8/7/20 4:43 PM, Sean Anderson wrote:
> 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.
>
> Signed-off-by: Sean Anderson <seanga2@gmail.com>
> ---/
>
> Changes in v2:
> - New
>
> drivers/spi/designware_spi.c | 33 ++++++++++++++++-----------------
> 1 file changed, 16 insertions(+), 17 deletions(-)
>
> diff --git a/drivers/spi/designware_spi.c b/drivers/spi/designware_spi.c
> index c9b14f9029..f7ea3edaab 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,7 @@ 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("Error: %d: Can't get %s gpio!\n", ret, bus->name);

Thanks for caring to convert this to the more flexible logging.

Error: -23: Can't get spi at 53000000 gpio!

Shouldn't we remove one colon:

Error -23: Can't get spi at 53000000 gpio!

> return ret;
> }
>
> @@ -148,7 +149,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_info("Using external gpio for CS management\n");

On systems with CONFIG_LOG=n log_info() messages are always printed. By
default the function name is not printed in log messages.

Showing this message to the end-user of the device on every boot
provides no benefit.

log_debug() seems more adequate.

> #endif
> return 0;
> }
> @@ -162,8 +163,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("regs=%p max-frequency=%d\n", plat->regs, plat->frequency);

The output will look like this:

regs=0x1234 max-frequency=2000000

Such a message appearing on every boot will be irritating for end-users.

Please, use log_debug() here.

Can we replace 'regs=' by 'SPI@' for all messages?

>
> return request_gpio_cs(bus);
> }
> @@ -196,7 +196,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 +221,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 spi controller clk via device tree: %lu Hz\n", *rate);

%s/spi/SPI/

>
> return 0;
>
> @@ -247,14 +246,14 @@ 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("Can't get reset: %d\n", ret);

This message does not tell me that there is a problem with SPI. Please,
provide a useful text.

> 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("Failed to reset: %d\n", ret);

What shall I do when reading a message like:

"Failed to reset: -23".

Please, provide a more informative text.

> return ret;
> }
>
> @@ -333,7 +332,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 +344,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 +399,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 +426,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);

Please, use log_debug_io() here.

>
> priv->tx = (void *)tx;
> priv->tx_end = priv->tx + priv->len;
> @@ -437,7 +436,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);

log_debug_io()

Best regards

Heinrich

> /* Reprogram cr0 only if changed */
> if (dw_read(priv, DW_SPI_CTRL0) != cr0)
> dw_write(priv, DW_SPI_CTRL0, cr0);
> @@ -497,8 +496,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("regs=%p speed=%d clk_div=%d\n", priv->regs, priv->freq,
> + clk_div);
>
> return 0;
> }
> @@ -513,7 +512,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("regs=%p, mode=%d\n", priv->regs, priv->mode);
>
> return 0;
> }
>