From a00419dcf83815d5e8f1174d3ca60685eea66404 Mon Sep 17 00:00:00 2001 From: Thomas Makin Date: Wed, 12 Aug 2026 14:58:42 -0500 Subject: [PATCH] mmc: sdhci: pedantic clock rate debug logging Add pr_info-level logging across the SDHCI subsystem and the Tegra SDMMC clock providers so clock rate calculation, rounding, assigned clocks and parents are visible in dmesg without needing dynamic_debug. - sdhci-tegra: log curr_clk_rate/max_clk/clock on set_clock entry and after clk_get_rate(), the requested host_clk, the rounded get_max_clock value, and dump regs before hw tuning. - sdhci: promote the DBG() macro from pr_debug to pr_info and log host->clock/max_clk/clock plus the computed divider/actual clock in sdhci_calc_clk() and sdhci_set_clock(). - clk-sdmmc-mux / clk-divider / clk-utils: log div, mul, parent_rate, rounded rate and recalc_rate results in round_rate/recalc_rate/ set_rate/div_frac_get so the full rate decision path is traceable. - mmc core: log the requested speed in mmc_set_clock() and the tuning entry/host-exec points in mmc_execute_tuning(). Change-Id: I4d569a01da8355db3319e82de942f1401dfac911 --- drivers/clk/tegra/clk-divider.c | 22 +++++++++++++++++++++ drivers/clk/tegra/clk-sdmmc-mux.c | 32 ++++++++++++++++++++++++++++--- drivers/clk/tegra/clk-utils.c | 5 +++++ drivers/mmc/core/core.c | 6 ++++++ drivers/mmc/host/sdhci-tegra.c | 17 +++++++++++++++- drivers/mmc/host/sdhci.c | 9 ++++++++- 6 files changed, 86 insertions(+), 5 deletions(-) diff --git a/drivers/clk/tegra/clk-divider.c b/drivers/clk/tegra/clk-divider.c index 27f43c3da156..2f1298898ad6 100644 --- a/drivers/clk/tegra/clk-divider.c +++ b/drivers/clk/tegra/clk-divider.c @@ -11,6 +11,8 @@ #include "clk.h" +#define DRIVER_NAME "sdhci" + #define pll_out_override(p) (BIT((p->shift - 6))) #define div_mask(d) ((1 << (d->width)) - 1) #define get_mul(d) (1 << d->frac_width) @@ -48,6 +50,8 @@ static unsigned long clk_frac_div_recalc_rate(struct clk_hw *hw, div = (reg >> divider->shift) & div_mask(divider); + pr_info("(" DRIVER_NAME ") clk read divider: %d\n", div); + mul = get_mul(divider); div += mul; @@ -55,6 +59,9 @@ static unsigned long clk_frac_div_recalc_rate(struct clk_hw *hw, rate += div - 1; do_div(rate, div); + pr_info("(" DRIVER_NAME ") (recalc_rate) got rate: %llu\n", + (unsigned long long)rate); + return rate; } @@ -78,10 +85,18 @@ static int clk_frac_div_determine_rate(struct clk_hw *hw, return 0; } + pr_info("(" DRIVER_NAME ") clk div %d rate: %lu parent_rate: %lu\n", + div, rate, output_rate); + pr_info("(" DRIVER_NAME ") (round_rate) got div: %d\n", div); + mul = get_mul(divider); + pr_info("(" DRIVER_NAME ") (round_rate) got mul: %d\n", mul); + req->rate = DIV_ROUND_UP(output_rate * mul, div + mul); + pr_info("(" DRIVER_NAME ") clk calculated rounded rate: %lu\n", req->rate); + return 0; } @@ -93,10 +108,17 @@ static int clk_frac_div_set_rate(struct clk_hw *hw, unsigned long rate, unsigned long flags = 0; u32 val; + pr_info("(" DRIVER_NAME ") clk setting rate: %lu parent_rate: %lu\n", + rate, parent_rate); + div = get_div(divider, rate, parent_rate); if (div < 0) return div; + pr_info("(" DRIVER_NAME ") clk div %d rate: %lu parent_rate: %lu\n", + div, rate, parent_rate); + pr_info("(" DRIVER_NAME ") got div: %d\n", div); + if (divider->lock) spin_lock_irqsave(divider->lock, flags); diff --git a/drivers/clk/tegra/clk-sdmmc-mux.c b/drivers/clk/tegra/clk-sdmmc-mux.c index 14b5439a100a..ac669996d911 100644 --- a/drivers/clk/tegra/clk-sdmmc-mux.c +++ b/drivers/clk/tegra/clk-sdmmc-mux.c @@ -17,6 +17,8 @@ #include "clk.h" +#define DRIVER_NAME "sdhci" + #define DIV_MASK GENMASK(7, 0) #define MUX_SHIFT 29 #define MUX_MASK GENMASK(MUX_SHIFT + 2, MUX_SHIFT) @@ -56,12 +58,16 @@ static u8 clk_sdmmc_mux_get_parent(struct clk_hw *hw) for (i = 0; i < num_parents; i++) { if (mux_idx[i] == src) - return i; + break; } - WARN(1, "Unknown parent selector %d\n", src); + if (i < num_parents) + pr_info("(" DRIVER_NAME ") get_parent: src=%u parent=%s\n", + src, clk_hw_get_name(clk_hw_get_parent(hw))); + else + WARN(1, "Unknown parent selector %d\n", src); - return 0; + return i < num_parents ? i : 0; } static int clk_sdmmc_mux_set_parent(struct clk_hw *hw, u8 index) @@ -95,12 +101,17 @@ static unsigned long clk_sdmmc_mux_recalc_rate(struct clk_hw *hw, val = readl_relaxed(sdmmc_mux->reg); div = get_div_field(val); + pr_info("(" DRIVER_NAME ") clk read divider: %d\n", div); + div += SDMMC_MUL; rate *= SDMMC_MUL; rate += div - 1; do_div(rate, div); + pr_info("(" DRIVER_NAME ") (recalc_rate) got rate: %llu\n", + (unsigned long long)rate); + return rate; } @@ -121,12 +132,20 @@ static int clk_sdmmc_mux_determine_rate(struct clk_hw *hw, if (div < 0) div = 0; + pr_info("(" DRIVER_NAME ") clk div %d rate: %lu parent_rate: %lu\n", + div, req->rate, output_rate); + pr_info("(" DRIVER_NAME ") (round_rate) got div: %d\n", div); + pr_info("(" DRIVER_NAME ") (round_rate) got mul: %d\n", SDMMC_MUL); + if (sdmmc_mux->div_flags & TEGRA_DIVIDER_ROUND_UP) req->rate = DIV_ROUND_UP(output_rate * SDMMC_MUL, div + SDMMC_MUL); else req->rate = output_rate * SDMMC_MUL / (div + SDMMC_MUL); + pr_info("(" DRIVER_NAME ") clk calculated rounded rate: %lu\n", + req->rate); + return 0; } @@ -139,10 +158,17 @@ static int clk_sdmmc_mux_set_rate(struct clk_hw *hw, unsigned long rate, u32 val; u8 src; + pr_info("(" DRIVER_NAME ") clk setting rate: %lu parent_rate: %lu\n", + rate, parent_rate); + div = div_frac_get(rate, parent_rate, 8, 1, sdmmc_mux->div_flags); if (div < 0) return div; + pr_info("(" DRIVER_NAME ") clk div %d rate: %lu parent_rate: %lu\n", + div, rate, parent_rate); + pr_info("(" DRIVER_NAME ") got div: %d\n", div); + if (sdmmc_mux->lock) spin_lock_irqsave(sdmmc_mux->lock, flags); diff --git a/drivers/clk/tegra/clk-utils.c b/drivers/clk/tegra/clk-utils.c index 6518ebc1295b..c2b91b2c4e4f 100644 --- a/drivers/clk/tegra/clk-utils.c +++ b/drivers/clk/tegra/clk-utils.c @@ -7,6 +7,8 @@ #include "clk.h" +#define DRIVER_NAME "sdhci" + #define div_mask(w) ((1 << (w)) - 1) int div_frac_get(unsigned long rate, unsigned parent_rate, u8 width, @@ -39,5 +41,8 @@ int div_frac_get(unsigned long rate, unsigned parent_rate, u8 width, if (div1_5_not_allowed && (divider_ux1 > 0) && (divider_ux1 < mul)) divider_ux1 = (flags & TEGRA_DIVIDER_ROUND_UP) ? mul : 0; + pr_info("(" DRIVER_NAME ") div_frac_get: rate=%lu parent_rate=%u div=%lld mul=%d\n", + rate, parent_rate, divider_ux1, mul); + return divider_ux1; } diff --git a/drivers/mmc/core/core.c b/drivers/mmc/core/core.c index 29e80e5f928e..8da6ea210957 100644 --- a/drivers/mmc/core/core.c +++ b/drivers/mmc/core/core.c @@ -924,6 +924,8 @@ void mmc_set_clock(struct mmc_host *host, unsigned int hz) if (hz > host->f_max) hz = host->f_max; + pr_info("mmc core: speed: %u\n", hz); + host->ios.clock = hz; mmc_set_ios(host); } @@ -934,6 +936,8 @@ int mmc_execute_tuning(struct mmc_card *card) u32 opcode; int err; + pr_info("mmc core tuning\n"); + if (!host->ops->execute_tuning) return 0; @@ -945,6 +949,8 @@ int mmc_execute_tuning(struct mmc_card *card) else opcode = MMC_SEND_TUNING_BLOCK; + pr_info("mmc core host exec tuning\n"); + err = host->ops->execute_tuning(host, opcode); if (!err) { mmc_retune_clear(host); diff --git a/drivers/mmc/host/sdhci-tegra.c b/drivers/mmc/host/sdhci-tegra.c index c757e40e86e8..ef9060219207 100644 --- a/drivers/mmc/host/sdhci-tegra.c +++ b/drivers/mmc/host/sdhci-tegra.c @@ -796,6 +796,9 @@ static void tegra_sdhci_set_clock(struct sdhci_host *host, unsigned int clock) unsigned long host_clk; int err; + pr_info("sdhci-tegra: curr_clk_rate: %lu, max_clk: %u, clock: %u\n", + tegra_host->curr_clk_rate, host->max_clk, clock); + if (!clock) return sdhci_set_clock(host, clock); @@ -813,6 +816,8 @@ static void tegra_sdhci_set_clock(struct sdhci_host *host, unsigned int clock) */ host_clk = tegra_host->ddr_signaling ? clock * 2 : clock; + pr_info("sdhci-tegra: setting host clk to host_clk: %lu\n", host_clk); + err = dev_pm_opp_set_rate(dev, host_clk); if (err) dev_err(dev, "failed to set clk rate to %luHz: %d\n", @@ -824,6 +829,9 @@ static void tegra_sdhci_set_clock(struct sdhci_host *host, unsigned int clock) else host->max_clk = clk_get_rate(pltfm_host->clk); + pr_info("sdhci-tegra: curr_clk_rate: %lu, max_clk: %u, clock: %u\n", + tegra_host->curr_clk_rate, host->max_clk, clock); + sdhci_set_clock(host, clock); if (tegra_host->pad_calib_required) { @@ -861,8 +869,12 @@ static void tegra_sdhci_hs400_enhanced_strobe(struct mmc_host *mmc, static unsigned int tegra_sdhci_get_max_clock(struct sdhci_host *host) { struct sdhci_pltfm_host *pltfm_host = sdhci_priv(host); + unsigned long rounded; - return clk_round_rate(pltfm_host->clk, UINT_MAX); + rounded = clk_round_rate(pltfm_host->clk, 500000000); + pr_info("sdhci-tegra: get_max_clock rounded=%lu (requested 500000000)\n", + rounded); + return rounded; } static void tegra_sdhci_set_dqs_trim(struct sdhci_host *host, u8 trim) @@ -1067,6 +1079,9 @@ static int tegra_sdhci_execute_hw_tuning(struct mmc_host *mmc, u32 opcode) struct sdhci_host *host = mmc_priv(mmc); int err; + pr_info("sdhci-tegra: hello fuckers, dumping regs\n"); + sdhci_dumpregs(host); + err = sdhci_execute_tuning(mmc, opcode); if (!err && !host->tuning_err) tegra_sdhci_post_tuning(host); diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c index e3bf901b10aa..3274f93c5133 100644 --- a/drivers/mmc/host/sdhci.c +++ b/drivers/mmc/host/sdhci.c @@ -37,7 +37,7 @@ #define DRIVER_NAME "sdhci" #define DBG(f, x...) \ - pr_debug("%s: " DRIVER_NAME ": " f, mmc_hostname(host->mmc), ## x) + pr_info("%s: " DRIVER_NAME ": " f, mmc_hostname(host->mmc), ## x) #define SDHCI_DUMP(f, x...) \ pr_err("%s: " DRIVER_NAME ": " f, mmc_hostname(host->mmc), ## x) @@ -1921,6 +1921,9 @@ u16 sdhci_calc_clk(struct sdhci_host *host, unsigned int clock, u16 clk = 0; bool switch_base_clk = false; + pr_info("%s: " DRIVER_NAME ": host->clock: %u, host->max_clk: %u, clock: %u\n", + mmc_hostname(host->mmc), host->clock, host->max_clk, clock); + if (host->version >= SDHCI_SPEC_300) { if (host->preset_enabled) { u16 pre_val; @@ -1997,6 +2000,8 @@ u16 sdhci_calc_clk(struct sdhci_host *host, unsigned int clock, clock_set: if (real_div) *actual_clock = (host->max_clk * clk_mul) / real_div; + pr_info("%s: (" DRIVER_NAME ") clk div %d rate: %u parent_rate: %u\n", + mmc_hostname(host->mmc), real_div, *actual_clock, host->max_clk); clk |= (div & SDHCI_DIV_MASK) << SDHCI_DIVIDER_SHIFT; clk |= ((div & SDHCI_DIV_HI_MASK) >> SDHCI_DIV_MASK_LEN) << SDHCI_DIVIDER_HI_SHIFT; @@ -2071,6 +2076,8 @@ void sdhci_set_clock(struct sdhci_host *host, unsigned int clock) return; clk = sdhci_calc_clk(host, clock, &host->mmc->actual_clock); + pr_info("%s: " DRIVER_NAME ": set_clock requested=%u actual=%u\n", + mmc_hostname(host->mmc), clock, host->mmc->actual_clock); sdhci_enable_clk(host, clk); } EXPORT_SYMBOL_GPL(sdhci_set_clock);