Linux/AM3358: MMC debug info

user4140430

Part Number: AM3358

Tool/software: Linux

HI everyone.

we use linux-4.1.13,and enable MMC_DEBUG & dynamic_debug.

echo -n 'module omap +p'>/sys/kernel/debug/dynamic_debug/control
echo -n 'module omap_hsmmc +p'>/sys/kernel/debug/dynamic_debug/control

we use SDIO wifi card to transmit data and find the log as follow, no omap or omap_hsmmc 's debug info:

[ 1402.792973] mmc1: starting CMD53 arg 9a20f215 flags 000001b5
[ 1402.792987] mmc1: blksz 256 blocks 21 flags 00000100 tsac 1000 ms nsac 0
[ 1402.793293] mmc1: req done (CMD53): 0: 00002000 00000000 00000000 00000000
[ 1402.793309] mmc1: 5376 bytes transferred: 0
[ 1402.793383] mport:0x1103c, len:3584
[ 1402.793395] blk_mode:1, ioport:69692
[ 1402.793414] mmc1: starting CMD53 arg 9a20780e flags 000001b5
[ 1402.793427] mmc1: blksz 256 blocks 14 flags 00000100 tsac 1000 ms nsac 0
[ 1402.793642] mmc1: req done (CMD53): 0: 00002000 00000000 00000000 00000000
[ 1402.793658] mmc1: 3584 bytes transferred: 0

Although, we use got the debug info in linux-3.2

[ 703.873779] mmc1: starting CMD53 arg 12000d00 flags 000001b5
[ 703.873809] mmc1: blksz 256 blocks 1 flags 00000200 tsac 1000 ms nsac 0
[ 703.873809] omap_hsmmc omap_hsmmc.2: mmc1: CMD53, argument 0x12000d00
[ 703.873840] omap_hsmmc omap_hsmmc.2: IRQ Status is 1
[ 703.873840] omap_hsmmc omap_hsmmc.2: IRQ Status is 2
[ 703.873870] mmc1: req done (CMD53): 0: 00002000 00000000 00000000 00000000
[ 703.873870] mmc1: 256 bytes transferred: 0

the info is build info dynamic debug:

root@arm:~# cat /sys/kernel/debug/dynamic_debug/control | grep mmc
drivers/mmc/core/core.c:158 [mmc_core]mmc_request_done =p "%s: req done <CMD%u>: %d: %08x %08x %08x %08x\012"
drivers/mmc/core/core.c:164 [mmc_core]mmc_request_done =p "%s: req done (CMD%u): %d: %08x %08x %08x %08x\012"
drivers/mmc/core/core.c:169 [mmc_core]mmc_request_done =p "%s: %d bytes transferred: %d\012"
drivers/mmc/core/core.c:177 [mmc_core]mmc_request_done =p "%s: (CMD%u): %d: %08x %08x %08x %08x\012"
drivers/mmc/core/core.c:201 [mmc_core]mmc_start_request =p "<%s: starting CMD%u arg %08x flags %08x>\012"
drivers/mmc/core/core.c:206 [mmc_core]mmc_start_request =p "%s: starting CMD%u arg %08x flags %08x\012"
drivers/mmc/core/core.c:214 [mmc_core]mmc_start_request =p "%s: blksz %d blocks %d flags %08x tsac %d ms nsac %d\012"
drivers/mmc/core/core.c:220 [mmc_core]mmc_start_request =p "%s: CMD%u arg %08x flags %08x\012"
drivers/mmc/core/core.c:657 [mmc_core]mmc_interrupt_hpi =p "%s: HPI cannot be sent. Card state=%d\012"
drivers/mmc/core/core.c:473 [mmc_core]mmc_wait_for_req_done =p "%s: req failed (CMD%u): %d, retrying...\012"
drivers/mmc/core/core.c:2278 [mmc_core]mmc_calc_max_discard =p "%s: calculated max. discard sectors %u for timeout %u ms\012"
drivers/mmc/core/core.c:999 [mmc_core]mmc_set_ios =p "%s: clock %uHz busmode %u powermode %u cs %u Vdd %u width %u timing %u\012"
drivers/mmc/core/core.c:1633 [mmc_core]mmc_power_up =p "Initial signal voltage of 3.3v\012"
drivers/mmc/core/core.c:1635 [mmc_core]mmc_power_up =p "Initial signal voltage of 1.8v\012"
drivers/mmc/core/core.c:1637 [mmc_core]mmc_power_up =p "Initial signal voltage of 1.2v\012"
drivers/mmc/core/core.c:1574 [mmc_core]mmc_set_signal_voltage =p "%s: Signal voltage switch failed, power cycling card\012"
drivers/mmc/core/core.c:2401 [mmc_core]_mmc_detect_card_removed =p "%s: card removed too slowly\012"
drivers/mmc/core/core.c:2406 [mmc_core]_mmc_detect_card_removed =p "%s: card remove detected\012"
drivers/mmc/core/host.c:329 [mmc_core]mmc_of_parse =p "\042bus-width\042 property is missing, assuming 1 bit.\012"
drivers/mmc/core/sdio_io.c:118 [mmc_core]sdio_disable_func =p "SDIO: Disabling device %s...\012"
drivers/mmc/core/sdio_io.c:130 [mmc_core]sdio_disable_func =p "SDIO: Disabled device %s\012"
drivers/mmc/core/sdio_io.c:135 [mmc_core]sdio_disable_func =p "SDIO: Failed to disable device %s\012"
drivers/mmc/core/sdio_io.c:68 [mmc_core]sdio_enable_func =p "SDIO: Enabling device %s...\012"
drivers/mmc/core/sdio_io.c:93 [mmc_core]sdio_enable_func =p "SDIO: Enabled device %s\012"
drivers/mmc/core/sdio_io.c:98 [mmc_core]sdio_enable_func =p "SDIO: Failed to enable device %s\012"
drivers/mmc/core/sdio_irq.c:52 [mmc_core]process_sdio_pending_irqs =p "%s: error %d reading SDIO_CCCR_INTx\012"
drivers/mmc/core/sdio_irq.c:121 [mmc_core]sdio_irq_thread =p "%s: IRQ thread started (poll period = %lu jiffies)\012"
drivers/mmc/core/sdio_irq.c:188 [mmc_core]sdio_irq_thread =p "%s: IRQ thread exiting with code %d\012"
drivers/mmc/core/sdio_irq.c:277 [mmc_core]sdio_claim_irq =p "SDIO: Enabling IRQ for %s...\012"
drivers/mmc/core/sdio_irq.c:280 [mmc_core]sdio_claim_irq =p "SDIO: IRQ for %s already in use.\012"
drivers/mmc/core/sdio_irq.c:320 [mmc_core]sdio_release_irq =p "SDIO: Disabling IRQ for %s...\012"
drivers/mmc/core/quirks.c:94 [mmc_core]mmc_fixup_device =p "calling %pf\012"
drivers/mmc/card/block.c:431 [mmc_block]ioctl_do_sanitize =p "%s: %s - SANITIZE IN PROGRESS...\012"
drivers/mmc/card/block.c:442 [mmc_block]ioctl_do_sanitize =p "%s: %s - SANITIZE COMPLETED\012"
drivers/mmc/card/sdio_uart.c:1091 [sdio_uart]sdio_uart_probe =p "%s: Register ID = 0x%02x, Exp ID = 0x%02x\012"
drivers/mmc/card/sdio_uart.c:1096 [sdio_uart]sdio_uart_probe =p "%s: regs offset = 0x%x\012"
drivers/mmc/card/sdio_uart.c:1102 [sdio_uart]sdio_uart_probe =p "%s: clk %d baudcode %u 4800-div %u\012"
drivers/mmc/host/sdhci.c:86 [sdhci]sdhci_dumpregs =p "sdhci: =========== REGISTER DUMP (%s)===========\012"
drivers/mmc/host/sdhci.c:90 [sdhci]sdhci_dumpregs =p "sdhci: Sys addr: 0x%08x | Version: 0x%08x\012"
drivers/mmc/host/sdhci.c:93 [sdhci]sdhci_dumpregs =p "sdhci: Blk size: 0x%08x | Blk cnt: 0x%08x\012"
drivers/mmc/host/sdhci.c:96 [sdhci]sdhci_dumpregs =p "sdhci: Argument: 0x%08x | Trn mode: 0x%08x\012"
drivers/mmc/host/sdhci.c:99 [sdhci]sdhci_dumpregs =p "sdhci: Present: 0x%08x | Host ctl: 0x%08x\012"
drivers/mmc/host/sdhci.c:102 [sdhci]sdhci_dumpregs =p "sdhci: Power: 0x%08x | Blk gap: 0x%08x\012"
drivers/mmc/host/sdhci.c:105 [sdhci]sdhci_dumpregs =p "sdhci: Wake-up: 0x%08x | Clock: 0x%08x\012"
drivers/mmc/host/sdhci.c:108 [sdhci]sdhci_dumpregs =p "sdhci: Timeout: 0x%08x | Int stat: 0x%08x\012"
drivers/mmc/host/sdhci.c:111 [sdhci]sdhci_dumpregs =p "sdhci: Int enab: 0x%08x | Sig enab: 0x%08x\012"
drivers/mmc/host/sdhci.c:114 [sdhci]sdhci_dumpregs =p "sdhci: AC12 err: 0x%08x | Slot int: 0x%08x\012"
drivers/mmc/host/sdhci.c:117 [sdhci]sdhci_dumpregs =p "sdhci: Caps: 0x%08x | Caps_1: 0x%08x\012"
drivers/mmc/host/sdhci.c:120 [sdhci]sdhci_dumpregs =p "sdhci: Cmd: 0x%08x | Max curr: 0x%08x\012"
drivers/mmc/host/sdhci.c:122 [sdhci]sdhci_dumpregs =p "sdhci: Host ctl2: 0x%08x\012"
drivers/mmc/host/sdhci.c:129 [sdhci]sdhci_dumpregs =p "sdhci: ADMA Err: 0x%08x | ADMA Ptr: 0x%08x%08x\012"
drivers/mmc/host/sdhci.c:133 [sdhci]sdhci_dumpregs =p "sdhci: ADMA Err: 0x%08x | ADMA Ptr: 0x%08x\012"
drivers/mmc/host/sdhci.c:136 [sdhci]sdhci_dumpregs =p "sdhci: ===========================================\012"
drivers/mmc/host/sdhci.c:707 [sdhci]sdhci_calc_timeout =p "sdhci [%s()]: %s: Too large timeout 0x%x requested for CMD%d!\012"
drivers/mmc/host/sdhci.c:788 [sdhci]sdhci_prepare_data =p "sdhci [%s()]: Reverting to PIO because of transfer size (%d)\012"
drivers/mmc/host/sdhci.c:822 [sdhci]sdhci_prepare_data =p "sdhci [%s()]: Reverting to PIO because of bad alignment\012"
drivers/mmc/host/sdhci.c:2576 [sdhci]sdhci_irq =p "sdhci [%s()]: *** %s got interrupt: 0x%08x\012"
drivers/mmc/host/sdhci.c:2383 [sdhci]sdhci_cmd_irq =p "sdhci [%s()]: Cannot wait for busy signal when also doing a data transfer"
drivers/mmc/host/sdhci.c:2418 [sdhci]sdhci_adma_show_error =p "sdhci [%s()]: %s: %p: DMA 0x%08x%08x, LEN 0x%04x, Attr=0x%02x\012"
drivers/mmc/host/sdhci.c:2423 [sdhci]sdhci_adma_show_error =p "sdhci [%s()]: %s: %p: DMA 0x%08x, LEN 0x%04x, Attr=0x%02x\012"
drivers/mmc/host/sdhci.c:322 [sdhci]sdhci_read_block_pio =p "sdhci [%s()]: PIO reading\012"
drivers/mmc/host/sdhci.c:367 [sdhci]sdhci_write_block_pio =p "sdhci [%s()]: PIO writing\012"
drivers/mmc/host/sdhci.c:443 [sdhci]sdhci_transfer_pio =p "sdhci [%s()]: PIO transfer complete.\012"
drivers/mmc/host/sdhci.c:2530 [sdhci]sdhci_data_irq =p "sdhci [%s()]: %s: DMA base 0x%08x, transferred 0x%06x bytes, next 0x%08x\012"
drivers/mmc/host/sdhci.c:2951 [sdhci]sdhci_add_host =p "sdhci [%s()]: Controller doesn't have SDMA capability\012"
drivers/mmc/host/sdhci.c:2957 [sdhci]sdhci_add_host =p "sdhci [%s()]: Disabling DMA as it is marked broken\012"
drivers/mmc/host/sdhci.c:2967 [sdhci]sdhci_add_host =p "sdhci [%s()]: Disabling ADMA as it is marked broken\012"
drivers/mmc/host/sdhci.c:3146 [sdhci]sdhci_add_host =p "sdhci [%s()]: %s: Auto-CMD23 available\012"
drivers/mmc/host/sdhci.c:3148 [sdhci]sdhci_add_host =p "sdhci [%s()]: %s: Auto-CMD23 unavailable\012"
drivers/mmc/host/omap.c:755 [omap]mmc_omap_irq =p "MMC IRQ %04x (CMD %d): "
drivers/mmc/host/omap.c:771 [omap]mmc_omap_irq =p "data timeout (CMD%d)\012"
drivers/mmc/host/omap.c:783 [omap]mmc_omap_irq =p "data CRC error, bytes left %d\012"
drivers/mmc/host/omap.c:786 [omap]mmc_omap_irq =p "data CRC error\012"
drivers/mmc/host/omap.c:822 [omap]mmc_omap_irq =p "ignoring card status error (CMD%d)\012"
drivers/mmc/host/omap.c:604 [omap]mmc_omap_abort_command =p "Aborting stuck command CMD%d\012"
drivers/mmc/host/omap_hsmmc.c:2078 [omap_hsmmc]omap_hsmmc_start_signal_voltage_switch =p "failed to switch to 3v\012"
drivers/mmc/host/omap_hsmmc.c:2082 [omap_hsmmc]omap_hsmmc_start_signal_voltage_switch =p " i/o voltage switch to 3V\012"
drivers/mmc/host/omap_hsmmc.c:2096 [omap_hsmmc]omap_hsmmc_start_signal_voltage_switch =p "failed to switch 1.8v\012"
drivers/mmc/host/omap_hsmmc.c:2878 [omap_hsmmc]omap_hsmmc_runtime_suspend =p "disabled\012"
drivers/mmc/host/omap_hsmmc.c:2893 [omap_hsmmc]omap_hsmmc_runtime_suspend =p "pending sdio irq, abort suspend\012"
drivers/mmc/host/omap_hsmmc.c:2125 [omap_hsmmc]omap_hsmmc_card_busy_low =p "card busy\012"
drivers/mmc/host/omap_hsmmc.c:637 [omap_hsmmc]omap_hsmmc_stop_clock =p "MMC Clock is not stopped\012"
drivers/mmc/host/omap_hsmmc.c:880 [omap_hsmmc]omap_hsmmc_context_restore =p "context is restored: restore count %d\012"
drivers/mmc/host/omap_hsmmc.c:2920 [omap_hsmmc]omap_hsmmc_runtime_resume =p "enabled\012"
drivers/mmc/host/omap_hsmmc.c:1311 [omap_hsmmc]omap_hsmmc_do_irq =p "AC12 err: 0x%x\012"
drivers/mmc/host/omap_hsmmc.c:542 [omap_hsmmc]omap_hsmmc_reg_get =p "unable to get vmmc regulator %ld\012"
drivers/mmc/host/omap_hsmmc.c:558 [omap_hsmmc]omap_hsmmc_reg_get =p "unable to get vmmc_aux regulator %ld\012"
drivers/mmc/host/omap_hsmmc.c:568 [omap_hsmmc]omap_hsmmc_reg_get =p "unable to get pbias regulator %ld\012"

Our question is : How to enable the omap & omap_hsmmc 's debug info, Or Is it disable in linux-4.1.13?

over 8 years ago

0 Biser Gatchev-XID over 8 years ago

TI__Guru**** 393215 points

the software team have been notified. They will respond here.

0 user4140430 over 8 years ago in reply to Biser Gatchev-XID

Prodigy 30 points

Thanks Biser.

we search the web, found that, the SDIO is in polling mode.

we want it to be IRQ mode, so change the setting in dts, follow the doc[ti-omap-hsmmc.txt] in kernel,

&mmc2 {
vmmc-supply = <&vmmcsd_fixed>;
compatible = "ti,am33xx-hsmmc";
pinctrl-names = "default", "idle";
pinctrl-0 = <&mmc2_pins>;
pinctrl-1 = <&mmc2_idle>;
interrupts-extended = <&intc 28 &gpio0 23 0>;
bus-width = <4>;
status = "okay";

keep-power-in-suspend;
ti,needs-special-hs-handling;
#address-cells = <1>;
#size-cells = <0>;
};

mmc2_pins: pinmux_mmc2_pins {
pinctrl-single,pins = <
0x80 (PIN_INPUT_PULLUP | MUX_MODE2) /* gpmc_csn1.mmc1_clk */
0x84 (PIN_INPUT_PULLUP | MUX_MODE2) /* gpmc_csn2.mmc1_cmd */
0x20 (PIN_INPUT_PULLUP | MUX_MODE2) /* gpmc_ad8.mmc1_dat0 */
0x24 (PIN_INPUT_PULLUP | MUX_MODE2) /* gpmc_ad9.mmc1_dat1 */
0x28 (PIN_INPUT_PULLUP | MUX_MODE2) /* gpmc_ad10.mmc1_dat2 */
0x2c (PIN_INPUT_PULLUP | MUX_MODE2) /* gpmc_ad11.mmc1_dat3 */
0x64 (PIN_OUTPUT_PULLUP | MUX_MODE7) /* gpmc_a9.RESETn */
0x60 (PIN_OUTPUT_PULLUP | MUX_MODE7) /* gpmc_a8.PDn */
>;
};
mmc2_idle: pinmux_mmc2_idle {
pinctrl-single,pins = <
0x24 (0x3f) /* gpmc_ad9.mmc1_dat1 */
>;
};

But the dma transmit is failed. Is the config right?

[ 9.962572] blk_mode:1, ioport:65536
[ 9.962588] mmc1: starting CMD53 arg 92000100 flags 000001b5
[ 9.962596] mmc1: blksz 256 blocks 1 flags 00000100 tsac 1000 ms nsac 0
[ 9.988279] mmc1: req done (CMD53): 0: 00002000 00000000 00000000 00000000
[ 9.988287] mmc1: 0 bytes transferred: -84
[ 9.988355] mwifiex_sdio mmc1:0001:1: FW download, write iomem (0) failed @ 0
[ 10.002361] mmc1: starting CMD52 arg 90000004 flags 00000195
[ 10.002414] mmc1: req done (CMD52): 0: 00001004 00000000 00000000 00000000

0 Kemal R. Shakir over 8 years ago in reply to user4140430

TI__Guru 55345 points

Hello user4140430,

The error code -84 indicated that you are getting illegal byte sequence. Can you check that, will you get this error on the latest Processor SDK?

You can enable MMC core and driver debugging from:
Device Drivers ---> <*> MMC/SD/SDIO card support ---> [*] MMC debugging
GPMC debugging from:
Device Drivers ---> -*- Memory Controller drivers ---> [*] Enable GPMC debug output and skip reset of GPMC during init

See the various configuration parameters at:
/sys/kernel/debug/mmcX/

Best regards,
Kemal

0 user4140430 over 7 years ago in reply to Kemal R. Shakir

Prodigy 30 points

Hello Kemal,

we got the same error in Linux-4.9.28, It is failed with CMD53 command.

[ 71.412389] mmc1: starting CMD52 arg 10006000 flags 00000195
[ 71.412414] omap_hsmmc 481d8000.mmc: mmc1: CMD52, argument 0x10006000
[ 71.412460] omap_hsmmc 481d8000.mmc: IRQ Status is 1
[ 71.412480] mmc1: req done (CMD52): 0: 0000100d 00000000 00000000 00000000
[ 71.412521] mmc1: starting CMD52 arg 10008000 flags 00000195
[ 71.412544] omap_hsmmc 481d8000.mmc: mmc1: CMD52, argument 0x10008000
[ 71.412578] omap_hsmmc 481d8000.mmc: IRQ Status is 1
[ 71.412597] mmc1: req done (CMD52): 0: 00001010 00000000 00000000 00000000
[ 71.412636] mmc1: starting CMD52 arg 10008200 flags 00000195
[ 71.412660] omap_hsmmc 481d8000.mmc: mmc1: CMD52, argument 0x10008200
[ 71.412692] omap_hsmmc 481d8000.mmc: IRQ Status is 1
[ 71.412712] mmc1: req done (CMD52): 0: 00001000 00000000 00000000 00000000
[ 71.412764] mmc1: starting CMD53 arg 92000100 flags 000001b5
[ 71.412783] mmc1: blksz 256 blocks 1 flags 00000100 tsac 1000 ms nsac 0
[ 71.412862] omap_hsmmc 481d8000.mmc: mmc1: CMD53, argument 0x92000100
[ 71.412899] omap_hsmmc 481d8000.mmc: IRQ Status is 208003
[ 71.412930] omap_hsmmc 481d8000.mmc: MMC IRQ 0x208003 : CC TC ERRI DCRC
[ 71.412968] mmc1: req done (CMD53): 0: 00002000 00000000 00000000 00000000
[ 71.412981] mmc1: 0 bytes transferred: -84
[ 71.413039] mwifiex_sdio mmc1:0001:1: FW download, write iomem (0) failed @ 0

the variants in debufs as followed:

root@arm:~# cat /sys/kernel/debug/mmc1/regs
mmc1:
sdio irq mode interrupt
sdio irq disabled
ctx_loss: 1

regs:
CON: 0x00000600
PSTATE: 0x01d70000
HCTL: 0x01000d06
SYSCTL: 0x000d0087
IE: 0x00000000
ISE: 0x00000000
CAPA: 0x06e10080

root@arm:~# cat /sys/kernel/debug/mmc1/ios
clock: 50000000 Hz
vdd: 21 (3.3 ~ 3.4 V)
bus mode: 2 (push-pull)
chip select: 0 (don't care)
power mode: 2 (on)
bus width: 2 (4 bits)
timing spec: 2 (sd high-speed)
signal voltage: 0 (3.30 V)
driver type: 0 (driver type B)

dts config:

&mmc2 {
vmmc-supply = <&vmmcsd_fixed>;
compatible = "ti,am33xx-hsmmc";
pinctrl-names = "default","idle";
pinctrl-0 = <&mmc2_pins>;
pinctrl-1 = <&mmc2_idle>;
bus-width = <4>;
ti,non-removable;
status = "okay";
interrupts-extended = <&intc 28 &gpio0 23 0>;
keep-power-in-suspend;
ti,needs-special-hs-handling;
#address-cells = <1>;
#size-cells = <0>;
};

mmc2_pins: pinmux_mmc2_pins {
pinctrl-single,pins = <
AM33XX_IOPAD(0x880, (PIN_INPUT_PULLUP | MUX_MODE2)) /* gpmc_csn1.mmc1_clk */
AM33XX_IOPAD(0x884, (PIN_INPUT_PULLUP | MUX_MODE2)) /* gpmc_csn2.mmc1_cmd */
AM33XX_IOPAD(0x820, (PIN_INPUT_PULLUP | MUX_MODE2)) /* gpmc_ad8.mmc1_dat0 */
AM33XX_IOPAD(0x824, (PIN_INPUT_PULLUP | MUX_MODE2)) /* gpmc_ad9.mmc1_dat1 */
AM33XX_IOPAD(0x828, (PIN_INPUT_PULLUP | MUX_MODE2)) /* gpmc_ad10.mmc1_dat2 */
AM33XX_IOPAD(0x82c, (PIN_INPUT_PULLUP | MUX_MODE2)) /* gpmc_ad11.mmc1_dat3 */
AM33XX_IOPAD(0x864, (PIN_OUTPUT_PULLUP | MUX_MODE7))/* gpmc_a9.RESETn */
AM33XX_IOPAD(0x860, (PIN_OUTPUT_PULLUP | MUX_MODE7))/* gpmc_a8.PDn */
>;
};

mmc2_idle: pinmux_mmc2_idle {
pinctrl-single,pins = <
AM33XX_IOPAD(0x824, (0x3f)) /* gpmc_ad9.mmc1_dat1 */
>;
};

Processors

Processors forum

Linux/AM3358: MMC debug info