On 8/8/20 1:14 AM, Heinrich Schuchardt wrote:
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.
It was quite difficult to debug without these changes, since turning on debug statements caused the fifos to over/underflow.
Error: -23: Can't get spi@53000000 gpio!
Shouldn't we remove one colon:
Error -23: Can't get spi@53000000 gpio!
Sure.
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.
Ok. I was generally unsure what log level to default to. README.log doesn't really make it clear semantically which log levels should be used.
#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.
Ok.
Can we replace 'regs=' by 'SPI@' for all messages?
Sure.
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/
Ok.
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.
Perhaps "Couldn't find or assert reset device configured for SPI"?
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.
Perhaps "SPI: failed to deassert reset (error %d)"?
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);} @@ -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");@@ -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.
When should log_content/log_io be used? Here, we only log metadata about the transfer. I would expect this to be a higher log level than (for example) the actual log of the content as done in dw_reader/writer. In addition, I am confused as to when log_io should be used over log_content. The only clear-cut case I can see is perhaps that replacing dw_write with something like
static inline void dw_write(struct dw_spi_priv *priv, u32 offset, u32 val) { log_io("%x = %x", offset, val); __raw_writel(val, priv->regs + offset); }
Is log_content intended for higher-level interfaces?
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()
Same comments/questions as above.
--Sean