[PATCH v2 05/14] mmc: Use logging instead of printf()

[Quentin Schulz]

Hi Simon,

On 7/21/24 5:25 PM, Simon Glass wrote:
> The code makes quite a few uses of __func__ which puts the function
> name into the resulting SPL image. Use the log subsystem instead, to
> reduce size.
> 
> The CONFIG_LOGF_FUNC option can be used to enable the function name.
> 

If I didn't misread the code, I believe that __func__ is **always** in 
the image whenever LOG is defined, just that it may not be printed?

c.f. 
https://source.denx.de/u-boot/u-boot/-/blob/master/include/log.h?ref_type=heads#L196-L206

> Signed-off-by: Simon Glass <sjg at chromium.org>
> ---
> 
> Changes in v2:
> - Various updates to log messages
> - Drop an unnecessary cast
> 
>   drivers/mmc/sdhci.c | 46 +++++++++++++++++++--------------------------
>   1 file changed, 19 insertions(+), 27 deletions(-)
> 
> diff --git a/drivers/mmc/sdhci.c b/drivers/mmc/sdhci.c
> index 560b7e889c7..eb5a144f8d4 100644
> --- a/drivers/mmc/sdhci.c
> +++ b/drivers/mmc/sdhci.c
> @@ -32,8 +32,7 @@ static void sdhci_reset(struct sdhci_host *host, u8 mask)
>   	sdhci_writeb(host, mask, SDHCI_SOFTWARE_RESET);
>   	while (sdhci_readb(host, SDHCI_SOFTWARE_RESET) & mask) {
>   		if (timeout == 0) {
> -			printf("%s: Reset 0x%x never completed.\n",
> -			       __func__, (int)mask);
> +			log_warning("Reset %x never completed\n", mask);

If log_* functions aren't changing the meaning of printf formats, please 
keep the 0x prefix to highlight it is hex digits as there's some overlap 
in hex and dec digits. This applies to all 0x%x that were changed to %x 
in this patch.

>   			return;
>   		}
>   		timeout--;
> @@ -139,8 +138,7 @@ static int sdhci_transfer_data(struct sdhci_host *host, struct mmc_data *data)
>   	do {
>   		stat = sdhci_readl(host, SDHCI_INT_STATUS);
>   		if (stat & SDHCI_INT_ERROR) {
> -			pr_debug("%s: Error detected in status(0x%X)!\n",
> -				 __func__, stat);
> +			log_debug("Error detected in status(%x)!\n", stat);
>   			return -EIO;
>   		}
>   		if (!transfer_done && (stat & rdy)) {
> @@ -173,7 +171,7 @@ static int sdhci_transfer_data(struct sdhci_host *host, struct mmc_data *data)
>   		if (timeout-- > 0)
>   			udelay(10);
>   		else {
> -			printf("%s: Transfer data timeout\n", __func__);
> +			log_err("Transfer data timeout\n");
>   			return -ETIMEDOUT;
>   		}
>   	} while (!(stat & SDHCI_INT_DATA_END));
> @@ -232,7 +230,7 @@ static int sdhci_send_command(struct mmc *mmc, struct mmc_cmd *cmd,
>   
>   	while (sdhci_readl(host, SDHCI_PRESENT_STATE) & mask) {
>   		if (time >= cmd_timeout) {
> -			printf("%s: MMC: %d busy ", __func__, mmc_dev);
> +			log_warning("mmc%d busy ", mmc_dev);
>   			if (2 * cmd_timeout <= SDHCI_CMD_MAX_TIMEOUT) {
>   				cmd_timeout += cmd_timeout;
>   				printf("timeout increasing to: %u ms.\n",

I would suggest to migrate this to the same log level as the busy 
message. Same for the puts(timeout) which is outside of this git context.

> @@ -316,8 +314,8 @@ static int sdhci_send_command(struct mmc *mmc, struct mmc_cmd *cmd,
>   		}
>   
>   		if (get_timer(start) >= SDHCI_READ_STATUS_TIMEOUT) {
> -			printf("%s: Timeout for status update: %08x %08x\n",
> -			       __func__, stat, mask);
> +			log_warning("Timeout for status update: %08x %08x\n",
> +				    stat, mask);
>   			return -ETIMEDOUT;
>   		}
>   	} while ((stat & mask) != mask);
> @@ -358,7 +356,7 @@ static int sdhci_execute_tuning(struct udevice *dev, uint opcode)
>   	struct mmc *mmc = mmc_get_mmc_dev(dev);
>   	struct sdhci_host *host = mmc->priv;
>   
> -	debug("%s\n", __func__);
> +	log_debug("sdhci tuning\n");
>   
>   	if (host->ops && host->ops->platform_execute_tuning) {
>   		err = host->ops->platform_execute_tuning(mmc, opcode);
> @@ -380,8 +378,7 @@ int sdhci_set_clock(struct mmc *mmc, unsigned int clock)
>   	while (sdhci_readl(host, SDHCI_PRESENT_STATE) &
>   			   (SDHCI_CMD_INHIBIT | SDHCI_DATA_INHIBIT)) {
>   		if (timeout == 0) {
> -			printf("%s: Timeout to wait cmd & data inhibit\n",
> -			       __func__);
> +			log_err("Timeout waiting for cmd & data inhibit\n");
>   			return -EBUSY;
>   		}
>   
> @@ -397,7 +394,7 @@ int sdhci_set_clock(struct mmc *mmc, unsigned int clock)
>   	if (host->ops && host->ops->set_delay) {
>   		ret = host->ops->set_delay(host);
>   		if (ret) {
> -			printf("%s: Error while setting tap delay\n", __func__);
> +			log_err("Error while setting tap delay\n");
>   			return ret;
>   		}
>   	}
> @@ -405,7 +402,7 @@ int sdhci_set_clock(struct mmc *mmc, unsigned int clock)
>   	if (host->ops && host->ops->config_dll) {
>   		ret = host->ops->config_dll(host, clock, false);
>   		if (ret) {
> -			printf("%s: Error while configuring dll\n", __func__);
> +			log_err("Error configuring dll\n");
>   			return ret;
>   		}
>   	}
> @@ -456,7 +453,7 @@ int sdhci_set_clock(struct mmc *mmc, unsigned int clock)
>   	if (host->ops && host->ops->config_dll) {
>   		ret = host->ops->config_dll(host, clock, true);
>   		if (ret) {
> -			printf("%s: Error while configuring dll\n", __func__);
> +			log_err("Error enabling dll\n");

Is this really only about enabling the DLL?

In rockchip_sdhci, the function does a lot more when enable=true than 
enable=false so I feel like it's a bit disingenuous to downgrade 
config_dll(..., 1) to "enabling dll".

Also not sure what made you decide on the log level but aside from the 
aforementioned issues, looks good to me.

Cheers,
Quentin