This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

AM5708: MMC free running clock

Part Number: AM5708

This is related to topic: https://e2e.ti.com/support/processors/f/791/t/639301

We have migrated from the 4.4 TI linux kernel to the newer 4.19.79+ kernel which is supported in the latest SDK release for AM57xx SoC.

Using the new U-Blox driver for a 4.20+ kernel on our platform, we see that the driver doesn't boot. According to U-Blox support this could be caused by SDHCI driver handling interrupts & clock:
"The problem is most likely related to SDIO IRQs from the module being lost, because the host switches off the SDIO clock between transfers, instead of keeping it running or switching to 1-bit mode as required by the spec. We've seen this issue on other TI AM57xx platforms as well with newer kernel versions that use sdhci driver instead of the older hsmmc." 

Is there some way we could keep the sdio clock alive between transfers?
We are executing the following prior to loading the module:

echo on > /sys/class/mmc_host/mmc2/device/power/control
echo on > /sys/class/mmc_host/mmc2/power/control
echo 1 > /sys/devices/platform/44000000.ocp/480ad000.mmc/mmc_host/mmc2/rescan

But it isn't sufficient..

Below the full boot-log:

Thanks in advance, 
Stef Boerrigter

Boot Log (Dmesg Output)

root@target:~# dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.73-00043-g58cd7d7-dirty (BEI\boerrs@aln-lx911922) (gcc version 7.3.0 (GCC)) #254 PREEMPT Mon Dec 2 13:35:42 CET 2019
[    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=10c5387d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[    0.000000] OF: fdt: Machine model: TI AM5708 
[    0.000000] Memory policy: Data cache writeback
[    0.000000] Reserved memory: created CMA memory pool at 0x95800000, size 56 MiB
[    0.000000] OF: reserved mem: initialized node ipu2_cma@95800000, compatible id shared-dma-pool
[    0.000000] OMAP4: Map 0x9fe00000 to (ptrval) for dram barrier
[    0.000000] On node 0 totalpages: 119552
[    0.000000]   Normal zone: 1148 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 119552 pages, LIFO batch:31
[    0.000000] CPU: All CPU(s) started in SVC mode.
[    0.000000] DRA722 ES2.1
[    0.000000] random: get_random_bytes called from start_kernel+0xa0/0x49c with crng_init=0
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 118404
[    0.000000] Kernel command line: console=ttyO1,115200n8  rootwait noinitrd  loglevel=7 HDMI-A-1:1280x800@60 vt.global_cursor_default=0 rw nfsroot=192.168.0.254:/srv/target/nfsroot root=/dev/nfs ip=192.168.0.1:192.168.0.254:192.168.0.254:255.255.255.0::eth0:off:: 
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Memory: 390408K/478208K available (10240K kernel code, 791K rwdata, 3080K rodata, 1024K init, 7454K bss, 30456K reserved, 57344K cma-reserved, 0K highmem)
[    0.000000] Virtual kernel memory layout:
                   vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                   fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                   vmalloc : 0xe0000000 - 0xff800000   ( 504 MB)
                   lowmem  : 0xc0000000 - 0xdfe00000   ( 510 MB)
                   pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
                   modules : 0xbf000000 - 0xbfe00000   (  14 MB)
                     .text : 0x(ptrval) - 0x(ptrval)   (11232 kB)
                     .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
                     .data : 0x(ptrval) - 0x(ptrval)   ( 792 kB)
                      .bss : 0x(ptrval) - 0x(ptrval)   (7455 kB)
[    0.000000] Running RCU self tests
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu: 	RCU lockdep checking is enabled.
[    0.000000] 	Tasks RCU enabled.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] OMAP clockevent source: timer1 at 32786 Hz
[    0.000000] arch_timer: cp15 timer(s) running at 6.14MHz (virt).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns
[    0.000005] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns
[    0.000023] Switching to timer-based delay loop, resolution 162ns
[    0.000280] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
[    0.000295] OMAP clocksource: 32k_counter at 32768 Hz
[    0.001187] Console: colour dummy device 80x30
[    0.001221] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    0.001235] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.001250] ... MAX_LOCK_DEPTH:          48
[    0.001264] ... MAX_LOCKDEP_KEYS:        8191
[    0.001277] ... CLASSHASH_SIZE:          4096
[    0.001291] ... MAX_LOCKDEP_ENTRIES:     32768
[    0.001304] ... MAX_LOCKDEP_CHAINS:      65536
[    0.001317] ... CHAINHASH_SIZE:          32768
[    0.001331]  memory used by lock dependency info: 4655 kB
[    0.001344]  per task-struct memory footprint: 1536 bytes
[    0.001392] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475)
[    0.001418] pid_max: default: 32768 minimum: 301
[    0.001641] Security Framework initialized
[    0.001728] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.001748] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.003833] CPU: Testing write buffer coherency: ok
[    0.003945] CPU0: Spectre v2: using ICIALLU workaround
[    0.006421] Setting up static identity map for 0x80100000 - 0x80100060
[    0.006783] rcu: Hierarchical SRCU implementation.
[    0.009952] devtmpfs: initialized
[    0.059014] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
[    0.060337] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.060381] futex hash table entries: 256 (order: 1, 11264 bytes)
[    0.062258] pinctrl core: initialized pinctrl subsystem
[    0.065351] NET: Registered protocol family 16
[    0.065971] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.067743] omap_hwmod: l3_main_2 using broken dt data from ocp
[    0.369518] audit: initializing netlink subsys (disabled)
[    0.371328] cpuidle: using governor ladder
[    0.371476] cpuidle: using governor menu
[    0.380867] audit: type=2000 audit(0.360:1): state=initialized audit_enabled=0 res=1
[    0.392134] gpio gpiochip0: (gpio-0-31): added GPIO chardev (254:0)
[    0.392417] gpiochip_setup_dev: registered GPIOs 0 to 31 on device: gpiochip0 (gpio-0-31)
[    0.392474] OMAP GPIO hardware version 0.1
[    0.393789] gpio gpiochip1: (gpio-32-63): added GPIO chardev (254:1)
[    0.393941] gpiochip_setup_dev: registered GPIOs 32 to 63 on device: gpiochip1 (gpio-32-63)
[    0.395142] gpio gpiochip2: (gpio-64-95): added GPIO chardev (254:2)
[    0.395287] gpiochip_setup_dev: registered GPIOs 64 to 95 on device: gpiochip2 (gpio-64-95)
[    0.396484] gpio gpiochip3: (gpio-96-127): added GPIO chardev (254:3)
[    0.396637] gpiochip_setup_dev: registered GPIOs 96 to 127 on device: gpiochip3 (gpio-96-127)
[    0.397860] gpio gpiochip4: (gpio-128-159): added GPIO chardev (254:4)
[    0.398006] gpiochip_setup_dev: registered GPIOs 128 to 159 on device: gpiochip4 (gpio-128-159)
[    0.399216] gpio gpiochip5: (gpio-160-191): added GPIO chardev (254:5)
[    0.399367] gpiochip_setup_dev: registered GPIOs 160 to 191 on device: gpiochip5 (gpio-160-191)
[    0.400523] gpio gpiochip6: (gpio-192-223): added GPIO chardev (254:6)
[    0.400675] gpiochip_setup_dev: registered GPIOs 192 to 223 on device: gpiochip6 (gpio-192-223)
[    0.401956] gpio gpiochip7: (gpio-224-255): added GPIO chardev (254:7)
[    0.402103] gpiochip_setup_dev: registered GPIOs 224 to 255 on device: gpiochip7 (gpio-224-255)
[    0.435976] No ATAGs?
[    0.436014] hw-breakpoint: Failed to enable monitor mode on CPU 0.
[    0.437949] OMAP DMA hardware revision 0.0
[    0.465211] edma 43300000.edma: memcpy is disabled
[    0.473880] edma 43300000.edma: TI EDMA DMA engine driver
[    0.491232] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
[    0.492181] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vsys5v0[0]'
[    0.492689] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vdd_3v3[0]'
[    0.493179] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vdd_1v8[0]'
[    0.496149] omap-iommu 40d01000.mmu: 40d01000.mmu registered
[    0.496518] omap-iommu 40d02000.mmu: 40d02000.mmu registered
[    0.497013] omap-iommu 58882000.mmu: 58882000.mmu registered
[    0.497516] omap-iommu 55082000.mmu: 55082000.mmu registered
[    0.498216] iommu: Adding device 55020000.ipu to group 2
[    0.499761] SCSI subsystem initialized
[    0.500274] usbcore: registered new interface driver usbfs
[    0.500411] usbcore: registered new interface driver hub
[    0.500572] usbcore: registered new device driver usb
[    0.503217] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz
[    0.504273] omap_i2c 48072000.i2c: bus 1 rev0.12 at 100 kHz
[    0.505104] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz
[    0.506399] omap_i2c 4807a000.i2c: bus 3 rev0.12 at 400 kHz
[    0.506815] pps_core: LinuxPPS API ver. 1 registered
[    0.506832] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.506875] PTP clock support registered
[    0.507851] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400
[    0.508684] Advanced Linux Sound Architecture Driver Initialized.
[    0.511588] clocksource: Switched to clocksource arch_sys_counter
[    0.691131] missing cooling_device property
[    0.691155] failed to build thermal zone board_thermal: -2
[    0.691463] NET: Registered protocol family 2
[    0.692949] tcp_listen_portaddr_hash hash table entries: 256 (order: 1, 10240 bytes)
[    0.693024] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[    0.693101] TCP bind hash table entries: 4096 (order: 5, 147456 bytes)
[    0.693847] TCP: Hash tables configured (established 4096 bind 4096)
[    0.694082] UDP hash table entries: 256 (order: 2, 20480 bytes)
[    0.694206] UDP-Lite hash table entries: 256 (order: 2, 20480 bytes)
[    0.694527] NET: Registered protocol family 1
[    0.695747] RPC: Registered named UNIX socket transport module.
[    0.695800] RPC: Registered udp transport module.
[    0.695816] RPC: Registered tcp transport module.
[    0.695831] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.697784] Unpacking initramfs...
[    1.247625] Freeing initrd memory: 1648K
[    1.248805] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
[    1.251846] Initialise system trusted keyrings
[    1.252276] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[    1.253243] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    1.254690] NFS: Registering the id_resolver key type
[    1.254779] Key type id_resolver registered
[    1.254830] Key type id_legacy registered
[    1.265618] Key type asymmetric registered
[    1.265703] Asymmetric key parser 'x509' registered
[    1.265809] io scheduler noop registered
[    1.265828] io scheduler deadline registered
[    1.265908] io scheduler cfq registered (default)
[    1.265926] io scheduler mq-deadline registered
[    1.265943] io scheduler kyber registered
[    1.272425] of_get_named_gpiod_flags: parsed 'device-enable' property of node '/tca9617bdgk@0[0]' - status (0)
[    1.272635] of_get_named_gpiod_flags: parsed 'device-enable' property of node '/tca9617bdgk@1[0]' - status (0)
[    1.278908] pinctrl-single 4a003400.pinmux: 282 pins, size 1128
[    1.279355] pinctrl-single 4a002e8c.pinmux: initialized with no interrupts
[    1.279374] pinctrl-single 4a002e8c.pinmux: 1 pins, size 4
[    1.287626] pwm-backlight backlight: GPIO lookup for consumer backlight-power-enable
[    1.287639] pwm-backlight backlight: using device tree for GPIO lookup
[    1.287685] of_get_named_gpiod_flags: parsed 'backlight-power-enable-gpios' property of node '/backlight[0]' - status (0)
[    1.287708] gpio gpiochip4: Persistence not supported for GPIO 18
[    1.287727] pwm-backlight backlight: GPIO lookup for consumer enable
[    1.287737] pwm-backlight backlight: using device tree for GPIO lookup
[    1.287779] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/backlight[0]' - status (0)
[    1.287844] gpio gpiochip0: Persistence not supported for GPIO 23
[    1.288234] pwm-backlight backlight: Linked as a consumer to regulator.2
[    1.290127] usbcore: registered new interface driver udlfb
[    1.290231] usbcore: registered new interface driver smscufx
[    1.305222] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    1.308982] omap_uart 4806a000.serial: no wakeirq for uart0
[    1.309044] of_get_named_gpiod_flags: parsed 'rts-gpio' property of node '/ocp/serial@4806a000[0]' - status (0)
[    1.309138] serial_omap_probe_rs485: RSP RX Timeout set to 244 us
[    1.309157] serial_omap_probe_rs485: Driver vs Serial line discipline sync active
[    1.309494] 4806a000.serial: ttyO0 at MMIO 0x4806a000 (irq = 43, base_baud = 3000000) is a OMAP UART0
[    1.310261] omap_uart 4806c000.serial: no wakeirq for uart1
[    1.310305] of_get_named_gpiod_flags: can't parse 'rts-gpio' property of node '/ocp/serial@4806c000[0]'
[    1.310400] 4806c000.serial: ttyO1 at MMIO 0x4806c000 (irq = 44, base_baud = 3000000) is a OMAP UART1
[    2.192730] console [ttyO1] enabled
[    2.197592] usbcore: registered new interface driver udl
[    2.204058] omapdss_dss 58000000.dss: Linked as a consumer to regulator.2
[    2.211252] omapdss_dss 58000000.dss: GPIO lookup for consumer lcd-power-enable
[    2.211264] omapdss_dss 58000000.dss: using device tree for GPIO lookup
[    2.211310] of_get_named_gpiod_flags: parsed 'lcd-power-enable-gpios' property of node '/ocp/dss@58000000[0]' - status (0)
[    2.211331] gpio gpiochip4: Persistence not supported for GPIO 19
[    2.211903] omapdss_dss 58000000.dss: Dropping the link to regulator.2
[    2.222480] dmm 4e000000.dmm: workaround for errata i878 in use
[    2.230716] dmm 4e000000.dmm: initialized all PAT entries
[    2.245976] panel-simple display: Linked as a consumer to regulator.2
[    2.252989] panel-simple display: GPIO lookup for consumer enable
[    2.253001] panel-simple display: using device tree for GPIO lookup
[    2.253049] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/display[0]' - status (0)
[    2.253071] gpio gpiochip6: Persistence not supported for GPIO 24
[    2.270526] loop: module loaded
[    2.274463] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[0]' - status (0)
[    2.274522] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[1]' - status (0)
[    2.274579] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[2]' - status (0)
[    2.274638] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[3]' - status (0)
[    2.274762] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[4]' - status (0)
[    2.302440] BUCK0: supplied by vdd_3v3
[    2.308500] BUCK1: supplied by vdd_3v3
[    2.314310] LDO0: supplied by vdd_5v0
[    2.319252] LDO1: supplied by vdd_5v0
[    2.325433] BUCK0: supplied by vdd_5v0
[    2.331001] BUCK1: supplied by vdd_5v0
[    2.336627] LDO0: supplied by vdd_3v3
[    2.341893] LDO1: supplied by vdd_3v3
[    2.352078] mdio_bus fixed-0: GPIO lookup for consumer reset
[    2.352091] mdio_bus fixed-0: using lookup tables for GPIO lookup
[    2.352152] mdio_bus fixed-0: No GPIO consumer reset found
[    2.352325] libphy: Fixed MDIO Bus: probed
[    2.361294] mdio_bus 48485000.mdio: GPIO lookup for consumer reset
[    2.361307] mdio_bus 48485000.mdio: using device tree for GPIO lookup
[    2.361336] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/ethernet@48484000/mdio@48485000[0]'
[    2.361363] of_get_named_gpiod_flags: can't parse 'reset-gpio' property of node '/ocp/ethernet@48484000/mdio@48485000[0]'
[    2.361376] mdio_bus 48485000.mdio: using lookup tables for GPIO lookup
[    2.361389] mdio_bus 48485000.mdio: No GPIO consumer reset found
[    2.411644] davinci_mdio 48485000.mdio: davinci mdio revision 1.6, bus freq 1000000
[    2.419669] libphy: 48485000.mdio: probed
[    2.433507] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/ethernet@48484000/mdio@48485000/ethernet-phy@1[0]'
[    2.434039] davinci_mdio 48485000.mdio: phy[1]: device 48485000.mdio:01, driver TI DP83822
[    2.443969] cpsw 48484000.ethernet: Read MACID from Registers = 74:e1:82:90:56:20
[    2.452251] cpsw 48484000.ethernet: initialized cpsw ale version 1.4
[    2.458901] cpsw 48484000.ethernet: ALE Table size 1024
[    2.464524] cpsw 48484000.ethernet: cpts: overflow check period 500 (jiffies)
[    2.474174] usbcore: registered new interface driver rtl8xxxu
[    2.490615] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    2.497491] ehci-platform: EHCI generic platform driver
[    2.503572] ehci-omap: OMAP-EHCI Host Controller driver
[    2.509534] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    2.516069] ohci-platform: OHCI generic platform driver
[    2.523749] xhci-hcd xhci-hcd.4.auto: xHCI Host Controller
[    2.529611] xhci-hcd xhci-hcd.4.auto: new USB bus registered, assigned bus number 1
[    2.538005] xhci-hcd xhci-hcd.4.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x0000000002010010
[    2.547910] xhci-hcd xhci-hcd.4.auto: irq 169, io mem 0x48890000
[    2.555572] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    2.564337] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.571921] usb usb1: Product: xHCI Host Controller
[    2.577023] usb usb1: Manufacturer: Linux 4.19.73-00043-g58cd7d7-dirty xhci-hcd
[    2.584705] usb usb1: SerialNumber: xhci-hcd.4.auto
[    2.591815] hub 1-0:1.0: USB hub found
[    2.595961] hub 1-0:1.0: 1 port detected
[    2.601554] xhci-hcd xhci-hcd.4.auto: xHCI Host Controller
[    2.607419] xhci-hcd xhci-hcd.4.auto: new USB bus registered, assigned bus number 2
[    2.615527] xhci-hcd xhci-hcd.4.auto: Host supports USB 3.0 SuperSpeed
[    2.622567] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    2.631373] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
[    2.640049] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.647637] usb usb2: Product: xHCI Host Controller
[    2.652776] usb usb2: Manufacturer: Linux 4.19.73-00043-g58cd7d7-dirty xhci-hcd
[    2.660429] usb usb2: SerialNumber: xhci-hcd.4.auto
[    2.666628] hub 2-0:1.0: USB hub found
[    2.670627] hub 2-0:1.0: 1 port detected
[    2.675944] xhci-hcd xhci-hcd.5.auto: xHCI Host Controller
[    2.681828] xhci-hcd xhci-hcd.5.auto: new USB bus registered, assigned bus number 3
[    2.690126] xhci-hcd xhci-hcd.5.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x0000000002010010
[    2.700096] xhci-hcd xhci-hcd.5.auto: irq 170, io mem 0x488d0000
[    2.708346] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    2.717034] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.724618] usb usb3: Product: xHCI Host Controller
[    2.729720] usb usb3: Manufacturer: Linux 4.19.73-00043-g58cd7d7-dirty xhci-hcd
[    2.737397] usb usb3: SerialNumber: xhci-hcd.5.auto
[    2.743526] hub 3-0:1.0: USB hub found
[    2.747522] hub 3-0:1.0: 1 port detected
[    2.752482] xhci-hcd xhci-hcd.5.auto: xHCI Host Controller
[    2.758247] xhci-hcd xhci-hcd.5.auto: new USB bus registered, assigned bus number 4
[    2.766362] xhci-hcd xhci-hcd.5.auto: Host supports USB 3.0 SuperSpeed
[    2.773447] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
[    2.782645] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
[    2.791297] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.798887] usb usb4: Product: xHCI Host Controller
[    2.804023] usb usb4: Manufacturer: Linux 4.19.73-00043-g58cd7d7-dirty xhci-hcd
[    2.811696] usb usb4: SerialNumber: xhci-hcd.5.auto
[    2.817784] hub 4-0:1.0: USB hub found
[    2.821860] hub 4-0:1.0: 1 port detected
[    2.826888] usbcore: registered new interface driver cdc_acm
[    2.832905] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    2.841415] usbcore: registered new interface driver usb-storage
[    2.848465] mousedev: PS/2 mouse device common for all mice
[    2.855796] atmel_mxt_ts 1-004a: GPIO lookup for consumer reset
[    2.855808] atmel_mxt_ts 1-004a: using device tree for GPIO lookup
[    2.855838] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/i2c@48072000/touch@4a[0]'
[    2.855866] of_get_named_gpiod_flags: can't parse 'reset-gpio' property of node '/ocp/i2c@48072000/touch@4a[0]'
[    2.855878] atmel_mxt_ts 1-004a: using lookup tables for GPIO lookup
[    2.855891] atmel_mxt_ts 1-004a: No GPIO consumer reset found
[    2.881793] atmel_mxt_ts 1-004a: __mxt_read_reg: i2c transfer failed (-121)
[    2.889252] atmel_mxt_ts 1-004a: mxt_bootloader_read: i2c recv failed (-121)
[    2.896659] atmel_mxt_ts 1-004a: Trying alternate bootloader address
[    2.903503] atmel_mxt_ts 1-004a: mxt_bootloader_read: i2c recv failed (-121)
[    2.911249] atmel_mxt_ts: probe of 1-004a failed with error -121
[    2.917886] usbcore: registered new interface driver usbtouchscreen
[    2.953442] rtc-pcf85063 3-0051: rtc core: registered rtc-pcf85063 as rtc0
[    2.960793] i2c /dev entries driver
[    2.974948] omap_wdt: OMAP Watchdog Timer Rev 0x01: initial timeout 60 sec
[    2.985537] cpu cpu0: Linked as a consumer to regulator.9
[    2.991357] cpu cpu0: Linked as a consumer to regulator.5
[    3.002884] sdhci: Secure Digital Host Controller Interface driver
[    3.009349] sdhci: Copyright(c) Pierre Ossman
[    3.015277] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.022092] sdhci-omap 4809c000.mmc: GPIO lookup for consumer cd
[    3.022104] sdhci-omap 4809c000.mmc: using device tree for GPIO lookup
[    3.022153] of_get_named_gpiod_flags: parsed 'cd-gpios' property of node '/ocp/mmc@4809c000[0]' - status (0)
[    3.022176] gpio gpiochip5: Persistence not supported for GPIO 27
[    3.022195] omap_gpio 4805d000.gpio: Could not set line 27 debounce to 200000 microseconds (-22)
[    3.031391] sdhci-omap 4809c000.mmc: Got CD GPIO
[    3.036320] sdhci-omap 4809c000.mmc: GPIO lookup for consumer wp
[    3.036331] sdhci-omap 4809c000.mmc: using device tree for GPIO lookup
[    3.036360] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@4809c000[0]'
[    3.036387] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@4809c000[0]'
[    3.036400] sdhci-omap 4809c000.mmc: using lookup tables for GPIO lookup
[    3.036412] sdhci-omap 4809c000.mmc: No GPIO consumer wp found
[    3.036732] sdhci-omap 4809c000.mmc: Linked as a consumer to regulator.4
[    3.044059] sdhci-omap 4809c000.mmc: Linked as a consumer to regulator.2
[    3.051210] sdhci-omap 4809c000.mmc: Dropping the link to regulator.2
[    3.058281] sdhci-omap 4809c000.mmc: Linked as a consumer to regulator.2
[    3.066494] mmc_add_host: mmc0
[    3.070100] mmc_add_host: mmc0
[    3.099784] mmc0: SDHCI controller on 4809c000.mmc [4809c000.mmc] using ADMA
[    3.110338] sdhci-omap 480b4000.mmc: GPIO lookup for consumer cd
[    3.110361] sdhci-omap 480b4000.mmc: using device tree for GPIO lookup
[    3.110420] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp/mmc@480b4000[0]'
[    3.110596] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp/mmc@480b4000[0]'
[    3.110623] sdhci-omap 480b4000.mmc: using lookup tables for GPIO lookup
[    3.110649] sdhci-omap 480b4000.mmc: No GPIO consumer cd found
[    3.110682] sdhci-omap 480b4000.mmc: GPIO lookup for consumer wp
[    3.110703] sdhci-omap 480b4000.mmc: using device tree for GPIO lookup
[    3.110755] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@480b4000[0]'
[    3.110806] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@480b4000[0]'
[    3.110831] sdhci-omap 480b4000.mmc: using lookup tables for GPIO lookup
[    3.110854] sdhci-omap 480b4000.mmc: No GPIO consumer wp found
[    3.113315] sdhci-omap 480b4000.mmc: Linked as a consumer to regulator.3
[    3.120642] sdhci-omap 480b4000.mmc: Dropping the link to regulator.3
[    3.127981] sdhci-omap 480b4000.mmc: Linked as a consumer to regulator.3
[    3.137335] mmc_add_host: mmc1
[    3.140936] mmc_add_host: mmc1
[    3.169782] mmc1: SDHCI controller on 480b4000.mmc [480b4000.mmc] using ADMA
[    3.178559] sdhci-omap 480ad000.mmc: GPIO lookup for consumer cd
[    3.178574] sdhci-omap 480ad000.mmc: using device tree for GPIO lookup
[    3.178615] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp/mmc@480ad000[0]'
[    3.178650] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp/mmc@480ad000[0]'
[    3.178668] sdhci-omap 480ad000.mmc: using lookup tables for GPIO lookup
[    3.178684] sdhci-omap 480ad000.mmc: No GPIO consumer cd found
[    3.178705] sdhci-omap 480ad000.mmc: GPIO lookup for consumer wp
[    3.178719] sdhci-omap 480ad000.mmc: using device tree for GPIO lookup
[    3.178846] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@480ad000[0]'
[    3.178881] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@480ad000[0]'
[    3.178898] sdhci-omap 480ad000.mmc: using lookup tables for GPIO lookup
[    3.178914] sdhci-omap 480ad000.mmc: No GPIO consumer wp found
[    3.179544] sdhci-omap 480ad000.mmc: Linked as a consumer to regulator.2
[    3.187220] sdhci-omap 480ad000.mmc: Dropping the link to regulator.2
[    3.194524] sdhci-omap 480ad000.mmc: Linked as a consumer to regulator.2
[    3.204337] mmc_add_host: mmc2
[    3.207793] random: fast init done
[    3.212143] mmc_add_host: mmc2
[    3.215412] mmc0: host does not support reading read-only switch, assuming write-enable
[    3.227544] mmc0: new high speed SDHC card at address aaaa
[    3.236488] mmcblk0: mmc0:aaaa SA08G 7.40 GiB 
[    3.245874]  mmcblk0: p1 p2
[    3.248961] mmc2: SDHCI controller on 480ad000.mmc [480ad000.mmc] using PIO
[    3.261204] ledtrig-cpu: registered to indicate activity on CPUs
[    3.274819] ti-iodelay 4844a000.padconf: Set reg 0x194 Delay(a: 285 g: 0), Elements(C=0 F=8)0x29008
[    3.286393] optee: probing for conduit method from DT.
[    3.291878] ti-iodelay 4844a000.padconf: Set reg 0x1ac Delay(a: 189 g: 0), Elements(C=0 F=5)0x29005
[    3.301342] ti-iodelay 4844a000.padconf: Set reg 0x1b8 Delay(a: 0 g: 120), Elements(C=0 F=2)0x29002
[    3.311228] optee: revision 3.2 (0dd915f1)
[    3.312041] optee: initialized driver
[    3.325495] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/i2c@4807a000/tlv320aic3104@18[0]'
[    3.325523] of_get_named_gpiod_flags: can't parse 'gpio-reset' property of node '/ocp/i2c@4807a000/tlv320aic3104@18[0]'
[    3.325887] tlv320aic3x-codec 3-0018: Linked as a consumer to regulator.2
[    3.333154] ti-iodelay 4844a000.padconf: Set reg 0x1c4 Delay(a: 0 g: 70), Elements(C=0 F=1)0x29001
[    3.342924] tlv320aic3x-codec 3-0018: Linked as a consumer to regulator.3
[    3.350165] ti-iodelay 4844a000.padconf: Set reg 0x1d0 Delay(a: 730 g: 360), Elements(C=1 F=12)0x2902c
[    3.366645] oprofile: using timer interrupt.
[    3.371203] ti-iodelay 4844a000.padconf: Set reg 0x1dc Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
[    3.381353] Initializing XFRM netlink socket
[    3.385995] NET: Registered protocol family 17
[    3.390685] NET: Registered protocol family 15
[    3.395468] ti-iodelay 4844a000.padconf: Set reg 0x1e8 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
[    3.405192] Key type dns_resolver registered
[    3.409898] ti-iodelay 4844a000.padconf: Set reg 0x1f4 Delay(a: 70 g: 0), Elements(C=0 F=2)0x29002
[    3.419517] ThumbEE CPU extension supported.
[    3.424117] Registering SWP/SWPB emulation handler
[    3.429201] ti-iodelay 4844a000.padconf: Set reg 0x200 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
[    3.438561] omap_voltage_late_init: Voltage driver support not added
[    3.445439] Power Management for TI OMAP4+ devices.
[    3.450729] ti-iodelay 4844a000.padconf: Set reg 0x368 Delay(a: 0 g: 120), Elements(C=0 F=2)0x29002
[    3.462383] Loading compiled-in X.509 certificates
[    3.467607] ti-iodelay 4844a000.padconf: Set reg 0x190 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
[    3.484526] ti-iodelay 4844a000.padconf: Set reg 0x1a8 Delay(a: 231 g: 0), Elements(C=0 F=6)0x29006
[    3.500812] ti-iodelay 4844a000.padconf: Set reg 0x1b4 Delay(a: 39 g: 0), Elements(C=0 F=1)0x29001
[    3.510822] Key type encrypted registered
[    3.515925] ima: No TPM chip found, activating TPM-bypass!
[    3.522134] ima: Allocated hash algorithm: sha1
[    3.526960] ti-iodelay 4844a000.padconf: Set reg 0x1c0 Delay(a: 91 g: 0), Elements(C=0 F=2)0x29002
[    3.536811] evm: Initialising EVM extended attributes:
[    3.542359] evm: security.ima
[    3.545539] ti-iodelay 4844a000.padconf: Set reg 0x1d8 Delay(a: 176 g: 0), Elements(C=0 F=5)0x29005
[    3.555388] evm: security.capability
[    3.559382] evm: HMAC attrs: 0x1
[    3.563130] ti-iodelay 4844a000.padconf: Set reg 0x1e4 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
[    3.583232] ti-iodelay 4844a000.padconf: Set reg 0x1f0 Delay(a: 101 g: 0), Elements(C=0 F=2)0x29002
[    3.601647] ti-iodelay 4844a000.padconf: Set reg 0x1fc Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
[    3.610947] ti-iodelay 4844a000.padconf: Set reg 0x364 Delay(a: 360 g: 0), Elements(C=0 F=10)0x2900a
[    3.659583] mmc1: new HS200 MMC card at address 0001
[    3.674020] mmcblk1: mmc1:0001 004G60 3.67 GiB 
[    3.680001] mmcblk1boot0: mmc1:0001 004G60 partition 1 2.00 MiB
[    3.702924] mmcblk1boot1: mmc1:0001 004G60 partition 2 2.00 MiB
[    3.710440] mmcblk1gp0: mmc1:0001 004G60 partition 4 4.00 MiB
[    3.732894] mmcblk1gp1: mmc1:0001 004G60 partition 5 4.00 MiB
[    3.746612] mmcblk1rpmb: mmc1:0001 004G60 partition 3 512 KiB, chardev (242:0)
[    3.756547] omapdss_dss 58000000.dss: Linked as a consumer to regulator.2
[    3.763865]  mmcblk1: p1 p2
[    3.769970] omapdss_dss 58000000.dss: GPIO lookup for consumer lcd-power-enable
[    3.769989] omapdss_dss 58000000.dss: using device tree for GPIO lookup
[    3.770423] of_get_named_gpiod_flags: parsed 'lcd-power-enable-gpios' property of node '/ocp/dss@58000000[0]' - status (0)
[    3.770469] gpio gpiochip4: Persistence not supported for GPIO 19
[    3.772150] DSS: OMAP DSS rev 6.1
[    3.778431] omapdss_dss 58000000.dss: bound 58001000.dispc (ops dispc_component_ops)
[    3.824181] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    3.831311] [drm] No driver support for vblank timestamp query.
[    3.896641] [drm] Enabling DMM ywrap scrolling
[    3.920759] Console: switching to colour frame buffer device 160x50
[    4.199476] omapdrm omapdrm.0: fb0: omapdrm frame buffer device
[    4.212501] [drm] Initialized omapdrm 1.0.0 20110917 for omapdrm.0 on minor 0
[    4.224306] of_get_named_gpiod_flags: parsed 'amplifier-sd-gpio' property of node '/sound@0[0]' - status (0)
[    4.225017] of_get_named_gpiod_flags: can't parse 'simple-audio-card,hp-det-gpio' property of node '/sound@0[0]'
[    4.225074] of_get_named_gpiod_flags: can't parse 'simple-audio-card,mic-det-gpio' property of node '/sound@0[0]'
[    4.227337] asoc-simple-card sound@0: tlv320aic3x-hifi <-> 48468000.mcasp mapping ok
[    4.247080] of_get_named_gpiod_flags: parsed 'gpios' property of node '/on-off-key/on-off-key[0]' - status (0)
[    4.247108] gpio gpiochip4: Persistence not supported for GPIO 1
[    4.247596] input: on-off-key as /devices/platform/on-off-key/input/input0
[    4.258745] rtc-pcf85063 3-0051: setting system clock to 2019-09-15 09:00:41 UTC (1568538041)
[    4.271209] net eth0: initializing cpsw version 1.15 (0)
[    4.301412] TI DP83822 48485000.mdio:01: attached PHY driver [TI DP83822] (mii_bus:phy_addr=48485000.mdio:01, irq=POLL)
[    4.491677] Waiting up to 2 more seconds for network.
[    4.671733] Waiting up to 2 more seconds for network.
[    4.851676] Waiting up to 1 more seconds for network.
[    5.031676] Waiting up to 1 more seconds for network.
[    5.211677] Waiting up to 1 more seconds for network.
[    5.391739] Waiting up to 1 more seconds for network.
[    5.571677] Waiting up to 1 more seconds for network.
[    5.751672] Waiting up to 1 more seconds for network.
[    5.931670] Waiting up to 0 more seconds for network.
[    6.111679] Waiting up to 0 more seconds for network.
[    6.291783] Waiting up to 0 more seconds for network.
[    6.351678] IP-Config: Complete:
[    6.355119]      device=eth0, hwaddr=74:e1:82:90:56:20, ipaddr=192.168.0.1, mask=255.255.255.0, gw=192.168.0.254
[    6.366278]      host=192.168.0.1, domain=, nis-domain=(none)
[    6.373091]      bootserver=192.168.0.254, rootserver=192.168.0.254, rootpath=
[    6.382941] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    6.393220] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    6.400960] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[    6.411519] ALSA device list:
[    6.414857] cfg80211: failed to load regulatory.db
[    6.420208]   #0: Target-Audio
[    6.425638] Freeing unused kernel memory: 1024K
[    6.430635] Run /init as init process
[    6.436672] cpsw 48484000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx
[    7.254527] systemd[1]: systemd 234 running in system mode. (-PAM -AUDIT -SELINUX -IMA -APPARMOR -SMACK +SYSVINIT -UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL -XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN default-hierarchy=hybrid)
[    7.278760] systemd[1]: Detected architecture arm.
[    7.316553] systemd[1]: Set hostname to <target>.
[    7.946087] random: systemd: uninitialized urandom read (16 bytes read)
[    7.953509] systemd[1]: Listening on Network Service Netlink Socket.
[    7.993385] random: systemd: uninitialized urandom read (16 bytes read)
[    8.000707] systemd[1]: Listening on udev Kernel Socket.
[    8.031798] random: systemd: uninitialized urandom read (16 bytes read)
[    8.040008] systemd[1]: Listening on Journal Socket (/dev/log).
[    8.072125] systemd[1]: Reached target Paths.
[    8.114048] systemd[1]: Created slice System Slice.
[    8.148894] systemd[1]: Mounting Kernel Debug File System...
[    8.198046] systemd[1]: Mounting POSIX Message Queue File System...
[    8.830325] random: crng init done
[    8.833947] random: 7 urandom warning(s) missed due to ratelimiting
[    9.651515] systemd-journald[128]: Received request to flush runtime journal from PID 1
[   12.973530] power_module: loading out-of-tree module taints kernel.
[   13.045099] of_get_named_gpiod_flags: parsed 'wlan-enable-gpio' property of node '/power-module[0]' - status (0)
[   13.045164] of_get_named_gpiod_flags: parsed 'power-good-gpio' property of node '/power-module[0]' - status (0)
[   13.045388] of_get_named_gpiod_flags: parsed 'bsp-support-gpios' property of node '/power-module[0]' - status (0)
[   13.045576] of_get_named_gpiod_flags: parsed 'bsp-support-gpios' property of node '/power-module[1]' - status (0)
[   13.156208] mmc2: new high speed SDIO card at address 0001
[   14.112968] EXT4-fs (mmcblk1gp0): mounted filesystem with ordered data mode. Opts: (null)
[   14.150970] EXT4-fs (mmcblk1gp1): mounted filesystem with ordered data mode. Opts: (null)
[   24.371626] mlan: module license 'Marvell Proprietary' taints kernel.
[   24.378496] Disabling lock debugging due to kernel taint
[   24.454788] wlan: Loading MWLAN driver
[   24.465491] vendor=0x02DF device=0x9139 class=0 function=1
[   24.473168] rx_work=0 cpu_num=1
[   24.483761] Request firmware: mrvl/sd8801_uapsta.bin
[   25.284818] Wlan: FW download over, firmwarelen=256188 downloaded 256188
[   25.495062] WLAN FW is active
[   25.498220] QUEUE_CMD: cmd=0xa9 is queued
[   25.504999] QUEUE_CMD: cmd=0x3 is queued
[   25.509124] DNLD_CMD (1568538062.750397): 0xa9, act 0x0, len 8, seqno 0x1
[   25.518762] DNLD_CMD:
[   25.518773] a9 00 08 00 01 00 00 00 
[   30.561669] Driver version = SD8801-0.0.0.p0-C4X14C635-GPL-(FP68) 
[   30.568216] main_state = 1
[   30.571081] ioctl_pending = 0
[   30.579071] tx_pending = 0
[   30.585657] rx_pending = 0
[   30.588496] lock_count = 28
[   30.591470] malloc_count = 26
[   30.598227] mbufalloc_count = 0
[   30.601519] hs_skip_count = 0
[   30.607315] hs_force_count = 0
[   30.610539] Wakeup device...
[   30.616178] woal_request_fw failed - mrvl/sd8801_uapsta.bin
[   30.623345] Firmware Init Failed

  • Hi Stef,

    stef boerrigter said:
    Is there some way we could keep the sdio clock alive between transfers?

    If the issue is indeed regarding the SDIO clock getting turned off then the concern might be related to the CON_CLKEXTFREE control bit (see discussion of register MMCHS_SYSTEST in the device TRM).

    A couple of ideas of things to try:

    1. Instrument the MMC driver's drivers/mmc/host/sdhci-omap.c:sdhci_omap_enable_sdio_irq() function (link) to perform a debug print also showing the 'enable' parameter upon function entry, such as by adding:
      printk("%s: enable=%d\n", __func__, enable);
      This function is one place the CON_CLKEXTFREE bit is accessed (as well as where interrupts are turned on/off) so knowing the last action(s) of this function may provide some clues, and
    2. Remove all reg &= ~CON_CLKEXTFREE (and related) accesses from the drivers/mmc/host/sdhci-omap.c driver to see if this has any observable impact

    Regards, Andreas

  • Hi Andreas,

    Thanks for your answer, 
    I have added the debug print statement; and can confirm that the MMC adapter SDIO IRQ's are indeed enabled.

    [ 15.076015] sdhci_omap_enable_sdio_irq - mmc2: enable=1

    I don't see it beeing disabled though but i removed the clock disabling to be sure.

    Whilst searching for CON_CLKEXTFREE in the code, i saw it beeing used in two functions: 
    - sdhci_omap_card_busy
    - sdhci_omap_enable_sdio_irq

    In both functions i removed the ~(CON_CLKEXTFREE) and while using a scope i can confirm the clock remains active. Altough the loading of the marvel U-Blox module still fails:

    [   14.451335] mmc2: new high speed SDIO card at address 0001
    [   14.953149] mlan: module license 'Marvell Proprietary' taints kernel.
    [   14.960960] Disabling lock debugging due to kernel taint
    [   15.041613] wlan: Loading MWLAN driver
    [   15.048228] vendor=0x02DF device=0x9139 class=0 function=1
    [   15.057559] rx_work=0 cpu_num=1
    [   15.076015] sdhci_omap_enable_sdio_irq - mmc2: enable=1
    [   15.082122] Request firmware: mrvl/sd8801_uapsta.bin
    [   15.371803] EXT4-fs (mmcblk1gp0): mounted filesystem with ordered data mode. Opts: (null)
    [   15.420725] EXT4-fs (mmcblk1gp1): mounted filesystem with ordered data mode. Opts: (null)
    [   16.324917] Wlan: FW download over, firmwarelen=256188 downloaded 256188
    [   16.821193] WLAN FW is active
    [   16.824683] QUEUE_CMD: cmd=0xa9 is queued
    [   16.853693] QUEUE_CMD: cmd=0x3 is queued
    [   16.863489] DNLD_CMD (1568607471.260805): 0xa9, act 0x0, len 8, seqno 0x1
    [   16.902744] DNLD_CMD:
    [   16.902756] a9 00 08 00 01 00 00 00 
    [   21.925440] Driver version = SD8801-0.0.0.p0-C4X14C635-GPL-(FP68) 
    [   21.931978] main_state = 1
    [   21.934846] ioctl_pending = 0
    [   21.943654] tx_pending = 0
    [   21.950446] rx_pending = 0
    [   21.953285] lock_count = 28
    [   21.958716] malloc_count = 26
    [   21.961827] mbufalloc_count = 0
    [   21.965116] hs_skip_count = 0
    [   21.972025] hs_force_count = 0
    [   21.975246] Wakeup device...
    [   21.980891] woal_request_fw failed - mrvl/sd8801_uapsta.bin
    [   21.988070] Firmware Init Failed
    
    • According to U-Blox the following is required during boot-up:
      "The problem is most likely related to SDIO IRQs from the module being lost, because the host switches off the SDIO clock between transfers, instead of keeping it running or switching to 1-bit mode as required by the spec. We've seen this issue on other TI AM57xx platforms as well with newer kernel versions that use sdhci driver instead of the older hsmmc."|

      When adding prints to the card_busy function i see this beeing called a lot during initialization of the Lily Module. This function also disables / enables interrupts. 

      What could be a way forward in enabling this Marvel based U-Blox LILY module?

  • Hi Stef,

    before doing anything else I'd suggest trying the two things below, also a combination of the two:

    1. Use the latest-latest Marvell WiFi firmware from https://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git/tree/mrvl 
    2. Try the latest TI integration Kernel v5.4 available at https://git.ti.com/gitweb?p=ti-linux-kernel/ti-linux-kernel.git;a=shortlog;h=refs/heads/ti-linux-5.4.y by porting your DTS and Kernel configuration over. While this Kernel tree is not ready for production yet (it is a staging area for next year's SDK) major functionality and board support is already working and this may give us some additional data points, possibly even fixing the issue under discussion (if we get lucky). I did have a quick look through the commit logs and didn't see anything obvious so I wouldn't put my hopes too high nevertheless it's something we should try.

    Let me know what you find and we go from there. Note that there seems to be related E2E thread here: https://e2e.ti.com/support/processors/f/791/t/860178

    Regards,
    Andreas

  • Hi Andreas,

    I tried option 1; new firmware but it makes no difference.

    Option 2 is a long shot in my opinion, i'll keep it on my backlog as an option. 

    I came up with an Option 3: Use Legacy Omap-hsmmc driver for MMC3 (which is connected to U-Blox module), and keep MMC1 & 2 with sdhci-omap.)

    Porting the omap-hsmmc.c driver from 4.4 to 4.19 is pretty simple, but it seems that the module is still not responding (different though):

    I have tried with wake_irq (gpio7-0) and without (falling back to polling) but both seem stuck on: reqeust firmware as you can see in the bootlog below. Also after minutes there is no callback / timer expiration that triggers a failure. it just keeps hanging in this part. 

    Differences i see between 4.4 & 4.19: 
      - 4.4 switches the MMC contoller to PM Suspend during FW download, 4.19 doesn.t
      - Is there any change in Power mode & suspending that you are aware of? 
         - Could this be related?
         - Do you have any other hints to port the omap_hsmmc driver and enable it in the 4.19 kernel?

    Boot Log:

    [    0.000000] Booting Linux on physical CPU 0x0
    [    0.000000] Linux version 4.19.73-00046-g088e111-dirty (BEI\boerrs@aln-lx911922) (gcc version 7.3.0 (GCC)) #56 PREEMPT Wed Dec 4 15:57:24 CET 2019
    [    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=10c5387d
    [    0.000000] CPU: div instructions available: patching division code
    [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
    [    0.000000] OF: fdt: Machine model: TI AM5708 Rational-WA55-HighSecure
    [    0.000000] Memory policy: Data cache writeback
    [    0.000000] Reserved memory: created CMA memory pool at 0x95800000, size 56 MiB
    [    0.000000] OF: reserved mem: initialized node ipu2_cma@95800000, compatible id shared-dma-pool
    [    0.000000] OMAP4: Map 0x9fe00000 to (ptrval) for dram barrier
    [    0.000000] On node 0 totalpages: 119552
    [    0.000000]   Normal zone: 1148 pages used for memmap
    [    0.000000]   Normal zone: 0 pages reserved
    [    0.000000]   Normal zone: 119552 pages, LIFO batch:31
    [    0.000000] CPU: All CPU(s) started in SVC mode.
    [    0.000000] DRA722 ES2.1
    [    0.000000] random: get_random_bytes called from start_kernel+0xa0/0x49c with crng_init=0
    [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
    [    0.000000] pcpu-alloc: [0] 0 
    [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 118404
    [    0.000000] Kernel command line: console=ttyO1,115200n8  rootwait noinitrd  loglevel=7 HDMI-A-1:1280x800@60 vt.global_cursor_default=0 rw nfsroot=192.168.0.254:/srv/wa55/nfsroot root=/dev/nfs ip=192.168.0.1:192.168.0.254:192.168.0.254:255.255.255.0::eth0:off:: 
    [    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
    [    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
    [    0.000000] Memory: 390404K/478208K available (10240K kernel code, 794K rwdata, 3096K rodata, 1024K init, 7454K bss, 30460K reserved, 57344K cma-reserved, 0K highmem)
    [    0.000000] Virtual kernel memory layout:
                       vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                       fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                       vmalloc : 0xe0000000 - 0xff800000   ( 504 MB)
                       lowmem  : 0xc0000000 - 0xdfe00000   ( 510 MB)
                       pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
                       modules : 0xbf000000 - 0xbfe00000   (  14 MB)
                         .text : 0x(ptrval) - 0x(ptrval)   (11232 kB)
                         .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
                         .data : 0x(ptrval) - 0x(ptrval)   ( 794 kB)
                          .bss : 0x(ptrval) - 0x(ptrval)   (7455 kB)
    [    0.000000] Running RCU self tests
    [    0.000000] rcu: Preemptible hierarchical RCU implementation.
    [    0.000000] rcu: 	RCU lockdep checking is enabled.
    [    0.000000] 	Tasks RCU enabled.
    [    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
    [    0.000000] OMAP clockevent source: timer1 at 32786 Hz
    [    0.000000] arch_timer: cp15 timer(s) running at 6.14MHz (virt).
    [    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns
    [    0.000005] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns
    [    0.000024] Switching to timer-based delay loop, resolution 162ns
    [    0.000284] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
    [    0.000300] OMAP clocksource: 32k_counter at 32768 Hz
    [    0.001202] Console: colour dummy device 80x30
    [    0.001236] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
    [    0.001252] ... MAX_LOCKDEP_SUBCLASSES:  8
    [    0.001266] ... MAX_LOCK_DEPTH:          48
    [    0.001280] ... MAX_LOCKDEP_KEYS:        8191
    [    0.001295] ... CLASSHASH_SIZE:          4096
    [    0.001309] ... MAX_LOCKDEP_ENTRIES:     32768
    [    0.001323] ... MAX_LOCKDEP_CHAINS:      65536
    [    0.001336] ... CHAINHASH_SIZE:          32768
    [    0.001350]  memory used by lock dependency info: 4655 kB
    [    0.001365]  per task-struct memory footprint: 1536 bytes
    [    0.001414] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475)
    [    0.001441] pid_max: default: 32768 minimum: 301
    [    0.001663] Security Framework initialized
    [    0.001751] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [    0.001771] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [    0.003849] CPU: Testing write buffer coherency: ok
    [    0.003962] CPU0: Spectre v2: using ICIALLU workaround
    [    0.006438] Setting up static identity map for 0x80100000 - 0x80100060
    [    0.006804] rcu: Hierarchical SRCU implementation.
    [    0.009989] devtmpfs: initialized
    [    0.058448] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
    [    0.059730] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
    [    0.059774] futex hash table entries: 256 (order: 1, 11264 bytes)
    [    0.061696] pinctrl core: initialized pinctrl subsystem
    [    0.064799] NET: Registered protocol family 16
    [    0.065414] DMA: preallocated 256 KiB pool for atomic coherent allocations
    [    0.067157] omap_hwmod: l3_main_2 using broken dt data from ocp
    [    0.365373] audit: initializing netlink subsys (disabled)
    [    0.367146] cpuidle: using governor ladder
    [    0.367296] cpuidle: using governor menu
    [    0.370796] audit: type=2000 audit(0.360:1): state=initialized audit_enabled=0 res=1
    [    0.388074] gpio gpiochip0: (gpio-0-31): added GPIO chardev (254:0)
    [    0.388350] gpiochip_setup_dev: registered GPIOs 0 to 31 on device: gpiochip0 (gpio-0-31)
    [    0.388409] OMAP GPIO hardware version 0.1
    [    0.389731] gpio gpiochip1: (gpio-32-63): added GPIO chardev (254:1)
    [    0.389884] gpiochip_setup_dev: registered GPIOs 32 to 63 on device: gpiochip1 (gpio-32-63)
    [    0.391133] gpio gpiochip2: (gpio-64-95): added GPIO chardev (254:2)
    [    0.391284] gpiochip_setup_dev: registered GPIOs 64 to 95 on device: gpiochip2 (gpio-64-95)
    [    0.392480] gpio gpiochip3: (gpio-96-127): added GPIO chardev (254:3)
    [    0.392634] gpiochip_setup_dev: registered GPIOs 96 to 127 on device: gpiochip3 (gpio-96-127)
    [    0.393856] gpio gpiochip4: (gpio-128-159): added GPIO chardev (254:4)
    [    0.394014] gpiochip_setup_dev: registered GPIOs 128 to 159 on device: gpiochip4 (gpio-128-159)
    [    0.395211] gpio gpiochip5: (gpio-160-191): added GPIO chardev (254:5)
    [    0.395362] gpiochip_setup_dev: registered GPIOs 160 to 191 on device: gpiochip5 (gpio-160-191)
    [    0.396517] gpio gpiochip6: (gpio-192-223): added GPIO chardev (254:6)
    [    0.396668] gpiochip_setup_dev: registered GPIOs 192 to 223 on device: gpiochip6 (gpio-192-223)
    [    0.397925] gpio gpiochip7: (gpio-224-255): added GPIO chardev (254:7)
    [    0.398070] gpiochip_setup_dev: registered GPIOs 224 to 255 on device: gpiochip7 (gpio-224-255)
    [    0.432345] No ATAGs?
    [    0.432382] hw-breakpoint: Failed to enable monitor mode on CPU 0.
    [    0.434301] OMAP DMA hardware revision 0.0
    [    0.461612] edma 43300000.edma: memcpy is disabled
    [    0.469943] edma 43300000.edma: TI EDMA DMA engine driver
    [    0.487707] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
    [    0.488654] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vsys5v0[0]'
    [    0.489163] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vdd_3v3[0]'
    [    0.489663] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vdd_1v8[0]'
    [    0.492676] omap-iommu 40d01000.mmu: 40d01000.mmu registered
    [    0.493049] omap-iommu 40d02000.mmu: 40d02000.mmu registered
    [    0.493544] omap-iommu 58882000.mmu: 58882000.mmu registered
    [    0.494052] omap-iommu 55082000.mmu: 55082000.mmu registered
    [    0.494754] iommu: Adding device 55020000.ipu to group 2
    [    0.496316] SCSI subsystem initialized
    [    0.496832] usbcore: registered new interface driver usbfs
    [    0.496969] usbcore: registered new interface driver hub
    [    0.497131] usbcore: registered new device driver usb
    [    0.499745] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz
    [    0.500814] omap_i2c 48072000.i2c: bus 1 rev0.12 at 100 kHz
    [    0.501807] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz
    [    0.503119] omap_i2c 4807a000.i2c: bus 3 rev0.12 at 400 kHz
    [    0.503547] pps_core: LinuxPPS API ver. 1 registered
    [    0.503564] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
    [    0.503613] PTP clock support registered
    [    0.504587] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400
    [    0.505422] Advanced Linux Sound Architecture Driver Initialized.
    [    0.508199] clocksource: Switched to clocksource arch_sys_counter
    [    0.688519] missing cooling_device property
    [    0.688544] failed to build thermal zone board_thermal: -2
    [    0.688851] NET: Registered protocol family 2
    [    0.690286] tcp_listen_portaddr_hash hash table entries: 256 (order: 1, 10240 bytes)
    [    0.690361] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
    [    0.690440] TCP bind hash table entries: 4096 (order: 5, 147456 bytes)
    [    0.691186] TCP: Hash tables configured (established 4096 bind 4096)
    [    0.691422] UDP hash table entries: 256 (order: 2, 20480 bytes)
    [    0.691547] UDP-Lite hash table entries: 256 (order: 2, 20480 bytes)
    [    0.691872] NET: Registered protocol family 1
    [    0.693091] RPC: Registered named UNIX socket transport module.
    [    0.693144] RPC: Registered udp transport module.
    [    0.693160] RPC: Registered tcp transport module.
    [    0.693176] RPC: Registered tcp NFSv4.1 backchannel transport module.
    [    0.695127] Unpacking initramfs...
    [    1.244769] Freeing initrd memory: 1648K
    [    1.245998] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
    [    1.249116] Initialise system trusted keyrings
    [    1.249539] workingset: timestamp_bits=14 max_order=17 bucket_order=3
    [    1.250474] squashfs: version 4.0 (2009/01/31) Phillip Lougher
    [    1.251916] NFS: Registering the id_resolver key type
    [    1.252003] Key type id_resolver registered
    [    1.252055] Key type id_legacy registered
    [    1.262776] Key type asymmetric registered
    [    1.262863] Asymmetric key parser 'x509' registered
    [    1.262968] io scheduler noop registered
    [    1.262988] io scheduler deadline registered
    [    1.263065] io scheduler cfq registered (default)
    [    1.263084] io scheduler mq-deadline registered
    [    1.263102] io scheduler kyber registered
    [    1.269623] of_get_named_gpiod_flags: parsed 'device-enable' property of node '/tca9617bdgk@0[0]' - status (0)
    [    1.269837] of_get_named_gpiod_flags: parsed 'device-enable' property of node '/tca9617bdgk@1[0]' - status (0)
    [    1.276106] pinctrl-single 4a003400.pinmux: 282 pins, size 1128
    [    1.276551] pinctrl-single 4a002e8c.pinmux: initialized with no interrupts
    [    1.276571] pinctrl-single 4a002e8c.pinmux: 1 pins, size 4
    [    1.284837] pwm-backlight backlight: GPIO lookup for consumer backlight-power-enable
    [    1.284850] pwm-backlight backlight: using device tree for GPIO lookup
    [    1.284897] of_get_named_gpiod_flags: parsed 'backlight-power-enable-gpios' property of node '/backlight[0]' - status (0)
    [    1.284921] gpio gpiochip4: Persistence not supported for GPIO 18
    [    1.284940] pwm-backlight backlight: GPIO lookup for consumer enable
    [    1.284951] pwm-backlight backlight: using device tree for GPIO lookup
    [    1.284993] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/backlight[0]' - status (0)
    [    1.285061] gpio gpiochip0: Persistence not supported for GPIO 23
    [    1.285454] pwm-backlight backlight: Linked as a consumer to regulator.2
    [    1.287339] usbcore: registered new interface driver udlfb
    [    1.287445] usbcore: registered new interface driver smscufx
    [    1.302490] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
    [    1.306236] omap_uart 4806a000.serial: no wakeirq for uart0
    [    1.306299] of_get_named_gpiod_flags: parsed 'rts-gpio' property of node '/ocp/serial@4806a000[0]' - status (0)
    [    1.306393] serial_omap_probe_rs485: RSP RX Timeout set to 244 us
    [    1.306412] serial_omap_probe_rs485: Driver vs Serial line discipline sync active
    [    1.306752] 4806a000.serial: ttyO0 at MMIO 0x4806a000 (irq = 43, base_baud = 3000000) is a OMAP UART0
    [    1.307539] omap_uart 4806c000.serial: no wakeirq for uart1
    [    1.307584] of_get_named_gpiod_flags: can't parse 'rts-gpio' property of node '/ocp/serial@4806c000[0]'
    [    1.307680] 4806c000.serial: ttyO1 at MMIO 0x4806c000 (irq = 44, base_baud = 3000000) is a OMAP UART1
    [    2.189736] console [ttyO1] enabled
    [    2.194606] usbcore: registered new interface driver udl
    [    2.201072] omapdss_dss 58000000.dss: Linked as a consumer to regulator.2
    [    2.208309] omapdss_dss 58000000.dss: GPIO lookup for consumer lcd-power-enable
    [    2.208321] omapdss_dss 58000000.dss: using device tree for GPIO lookup
    [    2.208368] of_get_named_gpiod_flags: parsed 'lcd-power-enable-gpios' property of node '/ocp/dss@58000000[0]' - status (0)
    [    2.208391] gpio gpiochip4: Persistence not supported for GPIO 19
    [    2.208922] omapdss_dss 58000000.dss: Dropping the link to regulator.2
    [    2.219506] dmm 4e000000.dmm: workaround for errata i878 in use
    [    2.227739] dmm 4e000000.dmm: initialized all PAT entries
    [    2.242993] panel-simple display: Linked as a consumer to regulator.2
    [    2.250016] panel-simple display: GPIO lookup for consumer enable
    [    2.250028] panel-simple display: using device tree for GPIO lookup
    [    2.250075] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/display[0]' - status (0)
    [    2.250097] gpio gpiochip6: Persistence not supported for GPIO 24
    [    2.267622] loop: module loaded
    [    2.271554] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[0]' - status (0)
    [    2.271613] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[1]' - status (0)
    [    2.271669] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[2]' - status (0)
    [    2.271729] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[3]' - status (0)
    [    2.271853] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[4]' - status (0)
    [    2.299079] BUCK0: supplied by vdd_3v3
    [    2.305147] BUCK1: supplied by vdd_3v3
    [    2.310974] LDO0: supplied by vdd_5v0
    [    2.315927] LDO1: supplied by vdd_5v0
    [    2.322095] BUCK0: supplied by vdd_5v0
    [    2.327657] BUCK1: supplied by vdd_5v0
    [    2.333271] LDO0: supplied by vdd_3v3
    [    2.338551] LDO1: supplied by vdd_3v3
    [    2.350818] spi_nand_base: SPI-NAND type mfr_id: 2c, dev_id: 14 is not in id table.
    [    2.360134] spi_nand_base: SPI-NAND: MT29F1G01ABAFDSF is found.
    [    2.368969] Bad block table found at page 65472, version 0x01
    [    2.377060] Bad block table found at page 65408, version 0x01
    [    2.395324] mdio_bus fixed-0: GPIO lookup for consumer reset
    [    2.395338] mdio_bus fixed-0: using lookup tables for GPIO lookup
    [    2.395399] mdio_bus fixed-0: No GPIO consumer reset found
    [    2.395579] libphy: Fixed MDIO Bus: probed
    [    2.404710] mdio_bus 48485000.mdio: GPIO lookup for consumer reset
    [    2.404723] mdio_bus 48485000.mdio: using device tree for GPIO lookup
    [    2.404753] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/ethernet@48484000/mdio@48485000[0]'
    [    2.404782] of_get_named_gpiod_flags: can't parse 'reset-gpio' property of node '/ocp/ethernet@48484000/mdio@48485000[0]'
    [    2.404796] mdio_bus 48485000.mdio: using lookup tables for GPIO lookup
    [    2.404810] mdio_bus 48485000.mdio: No GPIO consumer reset found
    [    2.458240] davinci_mdio 48485000.mdio: davinci mdio revision 1.6, bus freq 1000000
    [    2.466281] libphy: 48485000.mdio: probed
    [    2.478513] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/ethernet@48484000/mdio@48485000/ethernet-phy@1[0]'
    [    2.479095] davinci_mdio 48485000.mdio: phy[1]: device 48485000.mdio:01, driver TI DP83822
    [    2.489040] cpsw 48484000.ethernet: Read MACID from Registers = 74:e1:82:90:56:20
    [    2.497008] cpsw 48484000.ethernet: initialized cpsw ale version 1.4
    [    2.503961] cpsw 48484000.ethernet: ALE Table size 1024
    [    2.509588] cpsw 48484000.ethernet: cpts: overflow check period 500 (jiffies)
    [    2.519326] usbcore: registered new interface driver rtl8xxxu
    [    2.535817] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
    [    2.542698] ehci-platform: EHCI generic platform driver
    [    2.548786] ehci-omap: OMAP-EHCI Host Controller driver
    [    2.554728] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
    [    2.561258] ohci-platform: OHCI generic platform driver
    [    2.569104] xhci-hcd xhci-hcd.4.auto: xHCI Host Controller
    [    2.574966] xhci-hcd xhci-hcd.4.auto: new USB bus registered, assigned bus number 1
    [    2.583361] xhci-hcd xhci-hcd.4.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x0000000002010010
    [    2.593266] xhci-hcd xhci-hcd.4.auto: irq 170, io mem 0x48890000
    [    2.600943] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
    [    2.609708] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    2.617261] usb usb1: Product: xHCI Host Controller
    [    2.622397] usb usb1: Manufacturer: Linux 4.19.73-00046-g088e111-dirty xhci-hcd
    [    2.630070] usb usb1: SerialNumber: xhci-hcd.4.auto
    [    2.637090] hub 1-0:1.0: USB hub found
    [    2.641348] hub 1-0:1.0: 1 port detected
    [    2.646958] xhci-hcd xhci-hcd.4.auto: xHCI Host Controller
    [    2.652822] xhci-hcd xhci-hcd.4.auto: new USB bus registered, assigned bus number 2
    [    2.660925] xhci-hcd xhci-hcd.4.auto: Host supports USB 3.0 SuperSpeed
    [    2.667940] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
    [    2.676799] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
    [    2.685478] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    2.693068] usb usb2: Product: xHCI Host Controller
    [    2.698171] usb usb2: Manufacturer: Linux 4.19.73-00046-g088e111-dirty xhci-hcd
    [    2.705849] usb usb2: SerialNumber: xhci-hcd.4.auto
    [    2.712050] hub 2-0:1.0: USB hub found
    [    2.716044] hub 2-0:1.0: 1 port detected
    [    2.721294] xhci-hcd xhci-hcd.5.auto: xHCI Host Controller
    [    2.727062] xhci-hcd xhci-hcd.5.auto: new USB bus registered, assigned bus number 3
    [    2.735464] xhci-hcd xhci-hcd.5.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x0000000002010010
    [    2.745424] xhci-hcd xhci-hcd.5.auto: irq 171, io mem 0x488d0000
    [    2.753720] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
    [    2.762409] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    2.769999] usb usb3: Product: xHCI Host Controller
    [    2.775106] usb usb3: Manufacturer: Linux 4.19.73-00046-g088e111-dirty xhci-hcd
    [    2.782786] usb usb3: SerialNumber: xhci-hcd.5.auto
    [    2.788870] hub 3-0:1.0: USB hub found
    [    2.792866] hub 3-0:1.0: 1 port detected
    [    2.797700] xhci-hcd xhci-hcd.5.auto: xHCI Host Controller
    [    2.803559] xhci-hcd xhci-hcd.5.auto: new USB bus registered, assigned bus number 4
    [    2.811678] xhci-hcd xhci-hcd.5.auto: Host supports USB 3.0 SuperSpeed
    [    2.818768] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
    [    2.827582] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
    [    2.836620] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    2.844212] usb usb4: Product: xHCI Host Controller
    [    2.849348] usb usb4: Manufacturer: Linux 4.19.73-00046-g088e111-dirty xhci-hcd
    [    2.856995] usb usb4: SerialNumber: xhci-hcd.5.auto
    [    2.863122] hub 4-0:1.0: USB hub found
    [    2.867120] hub 4-0:1.0: 1 port detected
    [    2.872247] usbcore: registered new interface driver cdc_acm
    [    2.878165] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
    [    2.886766] usbcore: registered new interface driver usb-storage
    [    2.893810] mousedev: PS/2 mouse device common for all mice
    [    2.901315] atmel_mxt_ts 1-004a: GPIO lookup for consumer reset
    [    2.901327] atmel_mxt_ts 1-004a: using device tree for GPIO lookup
    [    2.901358] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/i2c@48072000/touch@4a[0]'
    [    2.901386] of_get_named_gpiod_flags: can't parse 'reset-gpio' property of node '/ocp/i2c@48072000/touch@4a[0]'
    [    2.901400] atmel_mxt_ts 1-004a: using lookup tables for GPIO lookup
    [    2.901413] atmel_mxt_ts 1-004a: No GPIO consumer reset found
    [    2.928401] atmel_mxt_ts 1-004a: __mxt_read_reg: i2c transfer failed (-121)
    [    2.935865] atmel_mxt_ts 1-004a: mxt_bootloader_read: i2c recv failed (-121)
    [    2.943264] atmel_mxt_ts 1-004a: Trying alternate bootloader address
    [    2.950108] atmel_mxt_ts 1-004a: mxt_bootloader_read: i2c recv failed (-121)
    [    2.957876] atmel_mxt_ts: probe of 1-004a failed with error -121
    [    2.964501] usbcore: registered new interface driver usbtouchscreen
    [    3.000053] rtc-pcf85063 3-0051: rtc core: registered rtc-pcf85063 as rtc0
    [    3.007405] i2c /dev entries driver
    [    3.021568] omap_wdt: OMAP Watchdog Timer Rev 0x01: initial timeout 60 sec
    [    3.032133] cpu cpu0: Linked as a consumer to regulator.9
    [    3.037952] cpu cpu0: Linked as a consumer to regulator.5
    [    3.049537] sdhci: Secure Digital Host Controller Interface driver
    [    3.056007] sdhci: Copyright(c) Pierre Ossman
    [    3.061243] sdhci-pltfm: SDHCI platform and OF driver helper
    [    3.068017] sdhci-omap 4809c000.mmc: GPIO lookup for consumer cd
    [    3.068029] sdhci-omap 4809c000.mmc: using device tree for GPIO lookup
    [    3.068080] of_get_named_gpiod_flags: parsed 'cd-gpios' property of node '/ocp/mmc@4809c000[0]' - status (0)
    [    3.068104] gpio gpiochip5: Persistence not supported for GPIO 27
    [    3.068123] omap_gpio 4805d000.gpio: Could not set line 27 debounce to 200000 microseconds (-22)
    [    3.077353] sdhci-omap 4809c000.mmc: Got CD GPIO
    [    3.082270] sdhci-omap 4809c000.mmc: GPIO lookup for consumer wp
    [    3.082281] sdhci-omap 4809c000.mmc: using device tree for GPIO lookup
    [    3.082311] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@4809c000[0]'
    [    3.082337] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@4809c000[0]'
    [    3.082352] sdhci-omap 4809c000.mmc: using lookup tables for GPIO lookup
    [    3.082365] sdhci-omap 4809c000.mmc: No GPIO consumer wp found
    [    3.082679] sdhci-omap 4809c000.mmc: Linked as a consumer to regulator.4
    [    3.090019] sdhci-omap 4809c000.mmc: Linked as a consumer to regulator.2
    [    3.097177] sdhci-omap 4809c000.mmc: Dropping the link to regulator.2
    [    3.104224] sdhci-omap 4809c000.mmc: Linked as a consumer to regulator.2
    [    3.139130] mmc0: SDHCI controller on 4809c000.mmc [4809c000.mmc] using ADMA
    [    3.148156] sdhci-omap 480b4000.mmc: GPIO lookup for consumer cd
    [    3.148180] sdhci-omap 480b4000.mmc: using device tree for GPIO lookup
    [    3.148908] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp/mmc@480b4000[0]'
    [    3.148964] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp/mmc@480b4000[0]'
    [    3.148991] sdhci-omap 480b4000.mmc: using lookup tables for GPIO lookup
    [    3.149017] sdhci-omap 480b4000.mmc: No GPIO consumer cd found
    [    3.149540] sdhci-omap 480b4000.mmc: GPIO lookup for consumer wp
    [    3.149562] sdhci-omap 480b4000.mmc: using device tree for GPIO lookup
    [    3.149619] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@480b4000[0]'
    [    3.149672] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@480b4000[0]'
    [    3.149699] sdhci-omap 480b4000.mmc: using lookup tables for GPIO lookup
    [    3.149724] sdhci-omap 480b4000.mmc: No GPIO consumer wp found
    [    3.150839] sdhci-omap 480b4000.mmc: Linked as a consumer to regulator.3
    [    3.159297] sdhci-omap 480b4000.mmc: Dropping the link to regulator.3
    [    3.167997] sdhci-omap 480b4000.mmc: Linked as a consumer to regulator.3
    [    3.201123] mmc1: SDHCI controller on 480b4000.mmc [480b4000.mmc] using ADMA
    [    3.211942] omap_hsmmc 480ad000.mmc: GPIO lookup for consumer cd
    [    3.211966] omap_hsmmc 480ad000.mmc: using device tree for GPIO lookup
    [    3.212027] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp/mmc@480ad000[0]'
    [    3.212083] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp/mmc@480ad000[0]'
    [    3.212111] omap_hsmmc 480ad000.mmc: using lookup tables for GPIO lookup
    [    3.212136] omap_hsmmc 480ad000.mmc: No GPIO consumer cd found
    [    3.212169] omap_hsmmc 480ad000.mmc: GPIO lookup for consumer wp
    [    3.212190] omap_hsmmc 480ad000.mmc: using device tree for GPIO lookup
    [    3.212244] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@480ad000[0]'
    [    3.212297] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@480ad000[0]'
    [    3.212323] omap_hsmmc 480ad000.mmc: using lookup tables for GPIO lookup
    [    3.212347] omap_hsmmc 480ad000.mmc: No GPIO consumer wp found
    [    3.214252] omap_hsmmc 480ad000.mmc: Linked as a consumer to regulator.2
    [    3.222193] omap_hsmmc 480ad000.mmc: no SDIO IRQ support, falling back to polling
    [    3.248974] random: fast init done
    [    3.259819] ledtrig-cpu: registered to indicate activity on CPUs
    [    3.277809] optee: probing for conduit method from DT.
    [    3.284341] optee: revision 3.2 (0dd915f1)
    [    3.285350] optee: initialized driver
    [    3.298028] ti-iodelay 4844a000.padconf: Set reg 0x194 Delay(a: 285 g: 0), Elements(C=0 F=9)0x29009
    [    3.315124] of_get_named_gpiod_flags: can't parse 'reset-gpios' property of node '/ocp/i2c@4807a000/tlv320aic3104@18[0]'
    [    3.315155] of_get_named_gpiod_flags: can't parse 'gpio-reset' property of node '/ocp/i2c@4807a000/tlv320aic3104@18[0]'
    [    3.315349] tlv320aic3x-codec 3-0018: Linked as a consumer to regulator.2
    [    3.322684] ti-iodelay 4844a000.padconf: Set reg 0x1ac Delay(a: 189 g: 0), Elements(C=0 F=6)0x29006
    [    3.332496] tlv320aic3x-codec 3-0018: Linked as a consumer to regulator.3
    [    3.342626] ti-iodelay 4844a000.padconf: Set reg 0x1b8 Delay(a: 0 g: 120), Elements(C=0 F=2)0x29002
    [    3.354701] oprofile: using timer interrupt.
    [    3.359676] Initializing XFRM netlink socket
    [    3.364215] NET: Registered protocol family 17
    [    3.369017] ti-iodelay 4844a000.padconf: Set reg 0x1c4 Delay(a: 0 g: 70), Elements(C=0 F=1)0x29001
    [    3.378561] NET: Registered protocol family 15
    [    3.383276] ti-iodelay 4844a000.padconf: Set reg 0x1d0 Delay(a: 730 g: 360), Elements(C=1 F=15)0x2902f
    [    3.393255] Key type dns_resolver registered
    [    3.397971] ThumbEE CPU extension supported.
    [    3.402579] ti-iodelay 4844a000.padconf: Set reg 0x1dc Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
    [    3.411981] Registering SWP/SWPB emulation handler
    [    3.416999] omap_voltage_late_init: Voltage driver support not added
    [    3.423733] ti-iodelay 4844a000.padconf: Set reg 0x1e8 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
    [    3.433119] Power Management for TI OMAP4+ devices.
    [    3.438348] ti-iodelay 4844a000.padconf: Set reg 0x1f4 Delay(a: 70 g: 0), Elements(C=0 F=2)0x29002
    [    3.447724] ti-iodelay 4844a000.padconf: Set reg 0x200 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
    [    3.458953] Loading compiled-in X.509 certificates
    [    3.471826] mmc0: host does not support reading read-only switch, assuming write-enable
    [    3.485255] ti-iodelay 4844a000.padconf: Set reg 0x368 Delay(a: 0 g: 120), Elements(C=0 F=2)0x29002
    [    3.495540] Key type encrypted registered
    [    3.500287] ima: No TPM chip found, activating TPM-bypass!
    [    3.506083] ima: Allocated hash algorithm: sha1
    [    3.511072] ti-iodelay 4844a000.padconf: Set reg 0x190 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
    [    3.520820] mmc0: new high speed SDHC card at address aaaa
    [    3.527734] evm: Initialising EVM extended attributes:
    [    3.533518] ti-iodelay 4844a000.padconf: Set reg 0x1a8 Delay(a: 231 g: 0), Elements(C=0 F=7)0x29007
    [    3.544735] mmcblk0: mmc0:aaaa SA08G 7.40 GiB 
    [    3.549608] evm: security.ima
    [    3.552718] evm: security.capability
    [    3.556465] evm: HMAC attrs: 0x1
    [    3.562833] ti-iodelay 4844a000.padconf: Set reg 0x1b4 Delay(a: 39 g: 0), Elements(C=0 F=1)0x29001
    [    3.572687]  mmcblk0: p1 p2
    [    3.588335] ti-iodelay 4844a000.padconf: Set reg 0x1c0 Delay(a: 91 g: 0), Elements(C=0 F=2)0x29002
    [    3.597740] ti-iodelay 4844a000.padconf: Set reg 0x1d8 Delay(a: 176 g: 0), Elements(C=0 F=5)0x29005
    [    3.628265] ti-iodelay 4844a000.padconf: Set reg 0x1e4 Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
    [    3.637585] ti-iodelay 4844a000.padconf: Set reg 0x1f0 Delay(a: 101 g: 0), Elements(C=0 F=3)0x29003
    [    3.668267] ti-iodelay 4844a000.padconf: Set reg 0x1fc Delay(a: 0 g: 0), Elements(C=0 F=0)0x29000
    [    3.677587] ti-iodelay 4844a000.padconf: Set reg 0x364 Delay(a: 360 g: 0), Elements(C=0 F=11)0x2900b
    [    3.718712] mmc1: new HS200 MMC card at address 0001
    [    3.737926] omapdss_dss 58000000.dss: Linked as a consumer to regulator.2
    [    3.746483] mmcblk1: mmc1:0001 004G60 3.67 GiB 
    [    3.752628] mmcblk1boot0: mmc1:0001 004G60 partition 1 2.00 MiB
    [    3.759029] omapdss_dss 58000000.dss: GPIO lookup for consumer lcd-power-enable
    [    3.759048] omapdss_dss 58000000.dss: using device tree for GPIO lookup
    [    3.759132] of_get_named_gpiod_flags: parsed 'lcd-power-enable-gpios' property of node '/ocp/dss@58000000[0]' - status (0)
    [    3.759178] gpio gpiochip4: Persistence not supported for GPIO 19
    [    3.759662] DSS: OMAP DSS rev 6.1
    [    3.765932] omapdss_dss 58000000.dss: bound 58001000.dispc (ops dispc_component_ops)
    [    3.775463] mmcblk1boot1: mmc1:0001 004G60 partition 2 2.00 MiB
    [    3.782936] mmcblk1gp0: mmc1:0001 004G60 partition 4 4.00 MiB
    [    3.792576] mmcblk1gp1: mmc1:0001 004G60 partition 5 4.00 MiB
    [    3.799238] mmcblk1rpmb: mmc1:0001 004G60 partition 3 512 KiB, chardev (242:0)
    [    3.808174]  mmcblk1: p1 p2
    [    3.819690] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
    [    3.826685] [drm] No driver support for vblank timestamp query.
    [    3.867302] [drm] Enabling DMM ywrap scrolling
    [    3.881891] Console: switching to colour frame buffer device 160x50
    [    4.066059] omapdrm omapdrm.0: fb0: omapdrm frame buffer device
    [    4.075538] [drm] Initialized omapdrm 1.0.0 20110917 for omapdrm.0 on minor 0
    [    4.087484] of_get_named_gpiod_flags: parsed 'amplifier-sd-gpio' property of node '/sound@0[0]' - status (0)
    [    4.088414] of_get_named_gpiod_flags: can't parse 'simple-audio-card,hp-det-gpio' property of node '/sound@0[0]'
    [    4.088472] of_get_named_gpiod_flags: can't parse 'simple-audio-card,mic-det-gpio' property of node '/sound@0[0]'
    [    4.090767] asoc-simple-card sound@0: tlv320aic3x-hifi <-> 48468000.mcasp mapping ok
    [    4.110777] of_get_named_gpiod_flags: parsed 'gpios' property of node '/on-off-key/on-off-key[0]' - status (0)
    [    4.110807] gpio gpiochip4: Persistence not supported for GPIO 1
    [    4.111310] input: on-off-key as /devices/platform/on-off-key/input/input0
    [    4.122435] rtc-pcf85063 3-0051: setting system clock to 2019-09-17 11:30:20 UTC (1568719820)
    [    4.134886] net eth0: initializing cpsw version 1.15 (0)
    [    4.165209] TI DP83822 48485000.mdio:01: attached PHY driver [TI DP83822] (mii_bus:phy_addr=48485000.mdio:01, irq=POLL)
    [    4.358287] Waiting up to 2 more seconds for network.
    [    4.538287] Waiting up to 2 more seconds for network.
    [    4.718334] Waiting up to 1 more seconds for network.
    [    4.898350] Waiting up to 1 more seconds for network.
    [    5.078285] Waiting up to 1 more seconds for network.
    [    5.258266] Waiting up to 1 more seconds for network.
    [    5.438286] Waiting up to 1 more seconds for network.
    [    5.618281] Waiting up to 1 more seconds for network.
    [    5.798283] Waiting up to 0 more seconds for network.
    [    5.978337] Waiting up to 0 more seconds for network.
    [    6.158287] Waiting up to 0 more seconds for network.
    [    6.218291] IP-Config: Complete:
    [    6.221728]      device=eth0, hwaddr=74:e1:82:90:56:20, ipaddr=192.168.0.1, mask=255.255.255.0, gw=192.168.0.254
    [    6.233167]      host=192.168.0.1, domain=, nis-domain=(none)
    [    6.239701]      bootserver=192.168.0.254, rootserver=192.168.0.254, rootpath=
    [    6.249766] cfg80211: Loading compiled-in X.509 certificates for regulatory database
    [    6.260263] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
    [    6.269275] cpsw 48484000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx
    [    6.279602] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
    [    6.289092] ALSA device list:
    [    6.292212]   #0: WA55-Audio
    [    6.297431] Freeing unused kernel memory: 1024K
    [    6.302441] cfg80211: failed to load regulatory.db
    [    6.308411] Run /init as init process
    [    7.125211] systemd[1]: systemd 234 running in system mode. (-PAM -AUDIT -SELINUX -IMA -APPARMOR -SMACK +SYSVINIT -UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL -XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN default-hierarchy=hybrid)
    [    7.148554] systemd[1]: Detected architecture arm.
    [    7.183213] systemd[1]: Set hostname to <wa55-hs>.
    [    7.807726] random: systemd: uninitialized urandom read (16 bytes read)
    [    7.816514] systemd[1]: Reached target Remote File Systems.
    [    7.849043] random: systemd: uninitialized urandom read (16 bytes read)
    [    7.857557] systemd[1]: Listening on udev Control Socket.
    [    7.888667] random: systemd: uninitialized urandom read (16 bytes read)
    [    7.897844] systemd[1]: Listening on Journal Socket.
    [    7.928764] systemd[1]: Reached target Paths.
    [    7.959174] systemd[1]: Listening on Journal Audit Socket.
    [    7.990389] systemd[1]: Listening on Syslog Socket.
    [    8.018803] systemd[1]: Listening on udev Kernel Socket.
    [    8.759351] random: crng init done
    [    8.765632] random: 7 urandom warning(s) missed due to ratelimiting
    [    9.575713] systemd-journald[131]: Received request to flush runtime journal from PID 1
    [   12.913790] power_module: loading out-of-tree module taints kernel.
    [   12.962704] of_get_named_gpiod_flags: parsed 'wlan-enable-gpio' property of node '/power-module[0]' - status (0)
    [   12.962770] of_get_named_gpiod_flags: parsed 'power-good-gpio' property of node '/power-module[0]' - status (0)
    [   12.962997] of_get_named_gpiod_flags: parsed 'bsp-support-gpios' property of node '/power-module[0]' - status (0)
    [   12.963189] of_get_named_gpiod_flags: parsed 'bsp-support-gpios' property of node '/power-module[1]' - status (0)
    [   14.026738] EXT4-fs (mmcblk1gp0): mounted filesystem with ordered data mode. Opts: (null)
    [   14.060008] EXT4-fs (mmcblk1gp1): mounted filesystem with ordered data mode. Opts: (null)
    [   15.389069] mmc2: new high speed SDIO card at address 0001
    [   15.577131] mlan: module license 'Marvell Proprietary' taints kernel.
    [   15.664634] Disabling lock debugging due to kernel taint
    [   15.715264] wlan: Loading MWLAN driver
    [   15.731964] vendor=0x02DF device=0x9139 class=0 function=1
    [   15.763038] rx_work=0 cpu_num=1
    [   15.790892] Request firmware: mrvl/sd8801_uapsta.bin
    

  • Hi Stef,

    stef boerrigter said:
    I tried option 1; new firmware but it makes no difference.

    Ok thanks for checking.

    stef boerrigter said:
    Option 2 is a long shot in my opinion, i'll keep it on my backlog as an option. 

    Yes it is a longshot nevertheless one of many things to try. I have on a few occasions debugged problems only later to find out they were already fixed upstream, so for me it has become one of the first things to check (upstream in general).

    stef boerrigter said:
    I came up with an Option 3: Use Legacy Omap-hsmmc driver for MMC3 (which is connected to U-Blox module), and keep MMC1 & 2 with sdhci-omap.)

    I was actually going to suggest this too but didn't want to put everything in my earlier reply as this seemed rather advanced. Nevertheless glad you thought along the same lines and already gave this a shot.

    stef boerrigter said:
    I have tried with wake_irq (gpio7-0) and without (falling back to polling) but both seem stuck on: reqeust firmware as you can see in the bootlog below. Also after minutes there is no callback / timer expiration that triggers a failure. it just keeps hanging in this part. 

    Differences i see between 4.4 & 4.19: 
      - 4.4 switches the MMC contoller to PM Suspend during FW download, 4.19 doesn.t
      - Is there any change in Power mode & suspending that you are aware of? 
         - Could this be related?
         - Do you have any other hints to port the omap_hsmmc driver and enable it in the 4.19 kernel?

    Yes PM could be play in here, so additional experiments probably won't hurt. I know you already tried manipulating PM behavior via sysfs, but in addition what about the following:

    1. Remove the call to pm_runtime_enable(dev); from sdhci_omap_probe(), and/or
    2. Insert a call to pm_runtime_forbid(dev) right after the call to pm_runtime_get_sync(dev) in sdhci_omap_probe()

    The good thing is you do have a working system using Kernel 4.4 so there is hope we should get it to work eventually. If we could find a way to easily bisect the Kernel history to when exactly the issue was introduced that would be helpful...

    Also while I have quite a bit of experience with using Marvell radios via PCIe I have not used the mwifiex driver over SDIO I/F. While you can experiment with the above some more give me a day or two to better digest the low-level aspects involved here and also consult with some of my colleagues as to what could be good next steps to try.

    Regards, Andreas

  • Hi Andreas,

    Thanks for your help, i have tried your suggestions on both drivers (omap_hsmmc.c & sdhci-omap.c) and below the actions & results :

    A: remove pm_runtime_enable(): 
       - sdhci-omap.c:  Probe fails

    [ 3.189925] sdhci-omap 480ad000.mmc: pm_runtime_get_sync failed
    [ 3.196484] sdhci-omap: probe of 480ad000.mmc failed with error -13

       - omap-hsmmc.c: kernel panic during boot. 

    B: add pm_runtime_forbid(dev) right after runtime_get_sync:

        - sdhci-omap-c: no difference observed, still failing to load marvell driver.

        - omap-hsmmc: no difference observed, still failing to load marvell driver.

    Additional: 
    I can confirm the omap_hsmmc.c driver ported from 4.4 kernel to 4.19 works for our eMMC & SD Card connected to MMC1(0) & MMC2(1). Think this information is helpfull

    Further:
    I think the power-safe functionality for this Lily module is the other way around:

    1. The module uses wake IRQ (2nd IRQ next to SDIO IRQ) to handle wake during deep-sleep: 

        mmc3_pins_hs: pinmux_mmc3_pins_hs {
    		pinctrl-single,pins = <
    			DRA7XX_CORE_IOPAD(0x377c, PIN_INPUT_PULLUP | MUX_MODE0) 	/* mmc3_clk.mmc3_clk */
    			DRA7XX_CORE_IOPAD(0x3780, PIN_INPUT_PULLUP | MUX_MODE0) 	/* mmc3_cmd.mmc3_cmd */
    			DRA7XX_CORE_IOPAD(0x3784, PIN_INPUT_PULLUP | MUX_MODE0) 	/* mmc3_dat0.mmc3_dat0 */
    			DRA7XX_CORE_IOPAD(0x3788, PIN_INPUT_PULLUP | MUX_MODE0) 	/* mmc3_dat1.mmc3_dat1 */
    			DRA7XX_CORE_IOPAD(0x378c, PIN_INPUT_PULLUP | MUX_MODE0) 	/* mmc3_dat2.mmc3_dat2 */
    			DRA7XX_CORE_IOPAD(0x3790, PIN_INPUT_PULLUP | MUX_MODE0) 	/* mmc3_dat3.mmc3_dat3 */
    		>;
    	};
    
    	mmc3_pins_idle: pinmux_mmc3_pins_idle {
            pinctrl-single,pins = <
                DRA7XX_CORE_IOPAD(0x3788, PIN_INPUT_PULLUP | WAKEUP_EN | MUX_MODE14) /* mmc3_dat1.gpio7_0 */
            >;
    	};

    So during sleep / idle mode pin Data1 from SDIO bus (data 0,1,2,3) is re-muxed to GPIO7_0 and that GPIO7_0 pin is used as Wake IRQ; so it can be signaled from the Lily U-Blox radio module to the MMC interface that it should wake again from deep sleep.

    2. Difference in Linux 4.4 (working) and 4.19 (not working); both with (almost) identical omap-hsmmc driver: 

    • While starting the driver in 4.4 i see a (simplified) boot order:
      1. MMC device probed & configured
      2. MMC device power mode set to ON (always enable)
      3. WLAN module probed
      4. Wake IRQ disabled & mmc module enters "omap_hsmmc_runtime_resume"
      5. communicatin starts & driver asks for firmware
      6. Wake IRQ enabled & mmc module enters "omap_hsmmc_runtime_suspend"
      7. ....
      8. Wake IRQ disabled & mmc module enters "omap_hsmmc_runtime_resume"
      9. Driver mentions: Firmware downloa over, (Complete)
    • While starting the driver in 4.19, i see the following (simplified) boot order:
      1. MMC device probed & configured
      2. MMC device power mode set to ON (always enable)
      3. WLAN module probed
      4. Wake IRQ disabled & mmc module enters "omap_hsmmc_runtime_resume"
      5. communicatin starts & driver asks for firmware
      6. Driver hangs 'forever' in void mmc_wait_for_req_done(struct mmc_host *host, struct mmc_request *mrq) (drivers/mmc/core/core.c) -> wait_for_completion(&mrq->completion);
        1. This call is triggered from lily driver; mlinux/moal_sdio_mmc.c -> moal_write_data_sync -> [ Entry in linux kernel here: sdio_writesb -> sdio_io_rw_ext_helper -> mmc_io_rw_extended (remaining byte mode) -> mmc_wait_for_req -> mmc_wait_for_req_done

    Best Regards,
    Stef

  • Stef,

    stef boerrigter said:
    2. Difference in Linux 4.4 (working) and 4.19 (not working); both with (almost) identical omap-hsmmc driver: 

    From your analysis it looks like interrupts are not used during the initial firmware setup phase we are trying to get past so we might need to look some other place?

    Then it also looks like the host driver may not be our issue? The secret may then be in the MMC core (drivers/mmc/core/), or some other related place.

    This being said, we do have a working MMC-based WiFi solution on 4.19 Kernel on the AM57xx-based BeagleBone-AI. The WiFi module is different (Broadcom, not Marvell), and it also uses a dedicated interrupt line rather than that "interesting" muxing scheme of the SD data line, nevertheless you could have a look there if your general "&mmc" DTS setup (basically, ignore the "brcmf" subnode) matches to what you use for the Marvell-based U-Blox module:

    https://github.com/beagleboard/linux/blob/4.19/arch/arm/boot/dts/am5729-beagleboneai.dts#L934

    I've also briefly talked with one of the developers involved with the AM57xx-based BB-AI WiFi implementation and he said the only issue they really had seen during migration from a v4.9.x Kernel with the old MMC driver to a newer v4.14/v4.19 Kernel with the updated MMC driver was that the IRQ's edge/level setting needed to be updated.  Maybe you can double-check this aspect as well.

    https://github.com/beagleboard/BeagleBoard-DeviceTrees/commit/aad0907458a770408b5d4932968bc979ac24397f

    Regards, Andreas

  • Hi Andreas,

    I have looked at the patches, and modified our IRQ Type from Level_Low to EGDE_FALLING & LEVEL_HIGH to EDGE_RISING. this made no difference. Also the brcmf changes seem not to be related.

    I have asked the U-Blox team to help us out on this topic, prefferably sharing the information here also, i think this might run into a dead end otherwise. Thanks for your support so far.

    Regards, Stef

  • Hi Andreas,

    I have had brief contact with U-Blox R&D and they point me towards an not (satisfying) topic answer from some time ago; http://e2e.ti.com/support/processors/f/791/t/821970

    Could you have a look at this topic as well and map this issue to the issue i'm raising? How to proceed using this device on the TI MMC Busses? 

    Thanks in advance,
    Stef Boerrigter

  • Hi Stef,

    thanks for reaching out to the U-Blox team again however I don't see how this older thread is helpful here.

    You mentioned earlier you had it working on Kernel 4.4, can you please share a boot log of your working scenario?

    I suggest we further look into two things:

    1. Interrupts - are they getting triggered at all? For this you can instrument drivers/mmc/host/sdhci.c:sdhci_thread_irq() with printk() statements (might need to rate-limit debug printing here)
    2. How about DMA? In your Kernel 4.19-based setup DMA is not used for the MMC3 HW module (a.k.a. "mmc2" in Linux) as evident from your log print "mmc2: SDHCI controller on 480ad000.mmc [480ad000.mmc] using PIO" (the key is "PIO"). I wonder if your older, working scenario says "DMA" there?

    Specifically regarding the 2nd point I found the following interesting commit...

    ARM: dts: dra7: Use sdhci-omap programming model
    https://git.ti.com/cgit/processor-sdk/processor-sdk-linux/commit/?h=processor-sdk-linux-4.19.y&id=940293affa7ed7c0bdb1820ecf7a8f12e901d030

    ...which switches the driver from omap_hsmmc.c to sdhci-omap.c while at the same time also taking away the DMA channel mapping from mmc3 by removing the dmas = <&sdma_xbar 77>, <&sdma_xbar 78>; and dma-names = "tx", "rx"; nodes while adding sdhci-caps-mask = <0x0 0x400000>; declaring SDMA not being supported. Now, I am not sure why this was done but I am going to find out. There's nothing obvious in the device documentation as to why it should (no longer?) be usable so there might be some other reason, and all this may or may not help us with the issue at hand; nevertheless it is a difference worth looking into a bit further.

    Regards, Andreas

  • Hi Andreas,

    See below the 4.4 working omap_hsmmc bootlog, no mention about PIO or (a)DMA though for all omap_hsmmc devices...

    Regarding the two questions:

    1. i added printk in sdhci_thread_irq as you requested but i saw no calls, then i added print to sdhci_irq function also:

    static int sdhci_irq_ctr = 0;
    if(strncmp(mmc_hostname(host->mmc), "mmc2", 4) == 0)
    {
    sdhci_irq_ctr++;
    printk("SB: ------ %s %s: %d [%d] \n", __func__, mmc_hostname(host->mmc), sdhci_irq_ctr, irq);
    }

    Interrupts keep on getting fired, i have checked briefly with mmc1 and it seems to be around the same amount after the lily wifi driver is loaded around same interval..:

    [   49.617316] mlan: module license 'Marvell Proprietary' taints kernel.
    [   49.624376] Disabling lock debugging due to kernel taint
    [   49.647311] wlan: Loading MWLAN driver
    [   49.656114] SB: ------ sdhci_irq mmc2: 1536 [72]  
    [   49.663168] SB: ------ sdhci_irq mmc2: 1537 [72]  
    [   49.668227] vendor=0x02DF device=0x9139 class=0 function=1
    [   49.675907] SB: ------ sdhci_irq mmc2: 1538 [72]  
    [   49.682099] SB: ------ sdhci_irq mmc2: 1539 [72]  
    [   49.687283] SB: ------ sdhci_irq mmc2: 1540 [72]  
    [   49.693961] rx_work=0 cpu_num=1
    [   49.697461] SB: ------ sdhci_irq mmc2: 1541 [72]  
    [   49.704268] SB: ------ sdhci_irq mmc2: 1542 [72]  
    [   49.709465] SB: ------ sdhci_irq mmc2: 1543 [72]  
    [   49.716302] SB: ------ sdhci_irq mmc2: 1544 [72]  
    [   49.722400] SB: ------ sdhci_irq mmc2: 1545 [72]  
    [   49.727590] SB: ------ sdhci_irq mmc2: 1546 [72]  
    [   49.734268] SB: ------ sdhci_irq mmc2: 1547 [72]  
    [   49.739456] SB: ------ sdhci_irq mmc2: 1548 [72]  
    [   49.744918] SB: ------ sdhci_irq mmc2: 1549 [72]  
    [   49.750236] SB: ------ sdhci_irq mmc2: 1550 [72]  
    [   49.760641] SB: ------ sdhci_irq mmc2: 1551 [72]  
    [   49.765829] SB: ------ sdhci_irq mmc2: 1552 [72]  
    [   49.772591] SB: ------ sdhci_irq mmc2: 1553 [72]  
    [   49.777776] SB: ------ sdhci_irq mmc2: 1554 [72]  
    [   49.782976] Request firmware: mrvl/sd8801_uapsta.bin
    [   49.792942] wlan_sdio mmc2:0001:1: Direct firmware load for mrvl/sd8801_uapsta.bin failed with error -2
    [   49.803002] WLAN: request_firmware() failed, error code = -2
    [   49.808938] woal_request_fw failed
    [   49.816057] Firmware Init Failed
    [   49.819601] SB: ------ sdhci_irq mmc2: 1555 [72]  
    [   49.826463] SB: ------ sdhci_irq mmc2: 1556 [72]  
    [   49.832505] SB: ------ sdhci_irq mmc2: 1557 [72]  
    [   49.837690] SB: ------ sdhci_irq mmc2: 1558 [72]  
    [   49.844901] woal_add_card failed
    [   49.848439] SB: ------ sdhci_irq mmc2: 1559 [72]  
    [   49.855261] SB: ------ sdhci_irq mmc2: 1560 [72]  
    [   49.861235] wlan_sdio: probe of mmc2:0001:1 failed with error -1
    [   49.869117] wlan: Driver loaded successfully
    root@wa55-hs:~# [   50.009981] SB: ------ sdhci_irq mmc2: 1561 [72]  
    [   51.049969] SB: ------ sdhci_irq mmc2: 1562 [72]  
    

    2: The working example i have added extra printk in probe function of omap-hsmmc driver to display if ADMA / DMA is beeing initialized: 

    [ 3.959246] SB: - omap_hsmmc_probe: using ADMA mmc0
    [ 4.017467] SB: - omap_hsmmc_probe: using ADMA mmc1
    [ 4.071086] SB: - omap_hsmmc_probe: using DMA mmc2

    So it seems that MMC0 & 1 use the ADMA and MMC2 doesn't have this capability and uses 'regular?' DMA in 4.4 kernel

    Full dmesg Bootlog 4.4 working (without printk's from step 2):

    [    0.000000] Booting Linux on physical CPU 0x0
    [    0.000000] Initializing cgroup subsys cpuset
    [    0.000000] Initializing cgroup subsys cpu
    [    0.000000] Initializing cgroup subsys cpuacct
    [    0.000000] Linux version 4.4.41 (oe-user@oe-host) (gcc version 7.3.0 (GCC) ) #1 PREEMPT Wed Oct 9 14:46:24 UTC 2019
    [    0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=10c5387d
    [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
    [    0.000000] Machine model: TI AM5708 Rational-WA55-HighSecure
    [    0.000000] Reserved memory: created CMA memory pool at 0x95800000, size 56 MiB
    [    0.000000] Reserved memory: initialized node ipu2_cma@95800000, compatible id shared-dma-pool
    [    0.000000] Memory policy: Data cache writeback
    [    0.000000] OMAP4: Map 0x9fe00000 to fe600000 for dram barrier
    [    0.000000] On node 0 totalpages: 119552
    [    0.000000] free_area_init_node: node 0, pgdat c0ccebb8, node_mem_map df95c000
    [    0.000000]   Normal zone: 1152 pages used for memmap
    [    0.000000]   Normal zone: 0 pages reserved
    [    0.000000]   Normal zone: 119552 pages, LIFO batch:31
    [    0.000000] CPU: All CPU(s) started in SVC mode.
    [    0.000000] DRA722 ES2.1
    [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
    [    0.000000] pcpu-alloc: [0] 0 
    [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 118400
    [    0.000000] Kernel command line: console=ttyO1,115200n8  rootwait noinitrd  loglevel=7 HDMI-A-1:1280x800@60 vt.global_cursor_default=0 rw nfsroot=192.168.0.254:/srv/wa55/nfsroot root=/dev/nfs ip=192.168.0.1:192.168.0.254:192.168.0.254:255.255.255.0::eth0:off:: 
    [    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
    [    0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
    [    0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
    [    0.000000] Memory: 392440K/478208K available (8194K kernel code, 690K rwdata, 2812K rodata, 1424K init, 8202K bss, 28424K reserved, 57344K cma-reserved, 0K highmem)
    [    0.000000] Virtual kernel memory layout:
                       vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                       fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                       vmalloc : 0xe0800000 - 0xff800000   ( 496 MB)
                       lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
                       pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
                       modules : 0xbf000000 - 0xbfe00000   (  14 MB)
                         .text : 0xc0008000 - 0xc0ac7cd4   (11008 kB)
                         .init : 0xc0ac8000 - 0xc0c2c000   (1424 kB)
                         .data : 0xc0c2c000 - 0xc0cd88d4   ( 691 kB)
                          .bss : 0xc0cda000 - 0xc14dc8f0   (8203 kB)
    [    0.000000] Running RCU self tests
    [    0.000000] Preemptible hierarchical RCU implementation.
    [    0.000000] 	RCU lockdep checking is enabled.
    [    0.000000] 	Build-time adjustment of leaf fanout to 32.
    [    0.000000] NR_IRQS:16 nr_irqs:16 16
    [    0.000000] OMAP clockevent source: timer1 at 32786 Hz
    [    0.000000] Architected cp15 timer(s) running at 6.14MHz (virt).
    [    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns
    [    0.000004] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns
    [    0.000015] Switching to timer-based delay loop, resolution 162ns
    [    0.000297] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns
    [    0.000306] OMAP clocksource: 32k_counter at 32768 Hz
    [    0.001060] Console: colour dummy device 80x30
    [    0.001092] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
    [    0.001099] ... MAX_LOCKDEP_SUBCLASSES:  8
    [    0.001104] ... MAX_LOCK_DEPTH:          48
    [    0.001109] ... MAX_LOCKDEP_KEYS:        8191
    [    0.001115] ... CLASSHASH_SIZE:          4096
    [    0.001119] ... MAX_LOCKDEP_ENTRIES:     32768
    [    0.001125] ... MAX_LOCKDEP_CHAINS:      65536
    [    0.001129] ... CHAINHASH_SIZE:          32768
    [    0.001134]  memory used by lock dependency info: 5167 kB
    [    0.001139]  per task-struct memory footprint: 1536 bytes
    [    0.001151] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475)
    [    0.001163] pid_max: default: 32768 minimum: 301
    [    0.001268] Security Framework initialized
    [    0.001323] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [    0.001332] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
    [    0.003163] Initializing cgroup subsys io
    [    0.003221] Initializing cgroup subsys memory
    [    0.003259] Initializing cgroup subsys devices
    [    0.003336] Initializing cgroup subsys freezer
    [    0.003387] Initializing cgroup subsys perf_event
    [    0.003426] CPU: Testing write buffer coherency: ok
    [    0.004247] Setting up static identity map for 0x80008200 - 0x80008260
    [    0.008179] devtmpfs: initialized
    [    0.079049] evm: security.ima
    [    0.079059] evm: security.capability
    [    0.079595] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0
    [    0.081241] omap_hwmod: l3_main_2 using broken dt data from ocp
    [    0.354054] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
    [    0.355660] pinctrl core: initialized pinctrl subsystem
    [    0.358898] NET: Registered protocol family 16
    [    0.359385] DMA: preallocated 256 KiB pool for atomic coherent allocations
    [    0.390731] cpuidle: using governor ladder
    [    0.420730] cpuidle: using governor menu
    [    0.434646] gpiochip_add: registered GPIOs 0 to 31 on device: gpio
    [    0.435674] OMAP GPIO hardware version 0.1
    [    0.436871] gpiochip_add: registered GPIOs 32 to 63 on device: gpio
    [    0.438524] gpiochip_add: registered GPIOs 64 to 95 on device: gpio
    [    0.440126] gpiochip_add: registered GPIOs 96 to 127 on device: gpio
    [    0.442104] gpiochip_add: registered GPIOs 128 to 159 on device: gpio
    [    0.443777] gpiochip_add: registered GPIOs 160 to 191 on device: gpio
    [    0.445423] gpiochip_add: registered GPIOs 192 to 223 on device: gpio
    [    0.447099] gpiochip_add: registered GPIOs 224 to 255 on device: gpio
    [    0.481613] No ATAGs?
    [    0.481635] hw-breakpoint: Failed to enable monitor mode on CPU 0.
    [    0.482286] omap4_sram_init:Unable to allocate sram needed to handle errata I688
    [    0.482296] omap4_sram_init:Unable to get sram pool needed to handle errata I688
    [    0.483573] OMAP DMA hardware revision 0.0
    [    0.557394] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported)
    [    0.558902] edma 43300000.edma: memcpy is disabled
    [    0.570543] edma 43300000.edma: TI EDMA DMA engine driver
    [    0.571216] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vsys5v0[0]'
    [    0.571785] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vdd_3v3[0]'
    [    0.572295] of_get_named_gpiod_flags: can't parse 'gpio' property of node '/fixedregulator-vdd_1v8[0]'
    [    0.575201] omap-iommu 55082000.mmu: 55082000.mmu registered
    [    0.577367] SCSI subsystem initialized
    [    0.577941] usbcore: registered new interface driver usbfs
    [    0.578058] usbcore: registered new interface driver hub
    [    0.578215] usbcore: registered new device driver usb
    [    0.580673] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz
    [    0.581749] omap_i2c 48072000.i2c: bus 1 rev0.12 at 100 kHz
    [    0.582497] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz
    [    0.583840] omap_i2c 4807a000.i2c: bus 3 rev0.12 at 400 kHz
    [    0.584138] pps_core: LinuxPPS API ver. 1 registered
    [    0.584146] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
    [    0.584187] PTP clock support registered
    [    0.585407] omap-mailbox 4883e000.mailbox: omap mailbox rev 0x400
    [    0.585792] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400
    [    0.586440] Advanced Linux Sound Architecture Driver Initialized.
    [    0.590063] clocksource: Switched to clocksource arch_sys_counter
    [    0.727409] missing cooling_device property
    [    0.727422] failed to build thermal zone board_thermal: -2
    [    0.727857] NET: Registered protocol family 2
    [    0.729102] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
    [    0.729171] TCP bind hash table entries: 4096 (order: 5, 147456 bytes)
    [    0.730340] TCP: Hash tables configured (established 4096 bind 4096)
    [    0.730453] UDP hash table entries: 256 (order: 2, 20480 bytes)
    [    0.730611] UDP-Lite hash table entries: 256 (order: 2, 20480 bytes)
    [    0.731277] NET: Registered protocol family 1
    [    0.732088] RPC: Registered named UNIX socket transport module.
    [    0.732098] RPC: Registered udp transport module.
    [    0.732106] RPC: Registered tcp transport module.
    [    0.732113] RPC: Registered tcp NFSv4.1 backchannel transport module.
    [    0.733286] Unpacking initramfs...
    [    1.262848] Freeing initrd memory: 1624K (c4200000 - c4396000)
    [    1.263647] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
    [    1.268543] futex hash table entries: 256 (order: 1, 11264 bytes)
    [    1.268711] audit: initializing netlink subsys (disabled)
    [    1.268827] audit: type=2000 audit(1.249:1): initialized
    [    1.269903] Initialise system trusted keyring
    [    1.271787] squashfs: version 4.0 (2009/01/31) Phillip Lougher
    [    1.273186] NFS: Registering the id_resolver key type
    [    1.273262] Key type id_resolver registered
    [    1.273271] Key type id_legacy registered
    [    1.281358] Key type asymmetric registered
    [    1.281419] Asymmetric key parser 'x509' registered
    [    1.281494] io scheduler noop registered
    [    1.281509] io scheduler deadline registered
    [    1.281533] io scheduler cfq registered (default)
    [    1.284668] of_get_named_gpiod_flags: parsed 'device-enable' property of node '/tca9617bdgk@0[0]' - status (0)
    [    1.284816] of_get_named_gpiod_flags: parsed 'device-enable' property of node '/tca9617bdgk@1[0]' - status (0)
    [    1.290299] pinctrl-single 4a003400.pinmux: 282 pins at pa fc003400 size 1128
    [    1.290581] pinctrl-single 4a002e8c.pinmux: 1 pins at pa fc002e8c size 4
    [    1.295432] pwm-backlight backlight: GPIO lookup for consumer backlight-power-enable
    [    1.295443] pwm-backlight backlight: using device tree for GPIO lookup
    [    1.295488] of_get_named_gpiod_flags: parsed 'backlight-power-enable-gpios' property of node '/backlight[0]' - status (0)
    [    1.295508] pwm-backlight backlight: GPIO lookup for consumer enable
    [    1.295516] pwm-backlight backlight: using device tree for GPIO lookup
    [    1.295543] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/backlight[0]' - status (0)
    [    1.297571] usbcore: registered new interface driver udlfb
    [    1.297702] usbcore: registered new interface driver smscufx
    [    1.303673] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
    [    1.307739] omap_uart 4806a000.serial: no wakeirq for uart0
    [    1.307773] of_get_named_gpiod_flags: parsed 'rts-gpio' property of node '/ocp/serial@4806a000[0]' - status (0)
    [    1.307797] serial_omap_probe_rs485: RSP RX Timeout set to 244 us
    [    1.307806] serial_omap_probe_rs485: Driver vs Serial line discipline sync active
    [    1.308183] 4806a000.serial: ttyO0 at MMIO 0x4806a000 (irq = 299, base_baud = 3000000) is a OMAP UART0
    [    1.309130] omap_uart 4806c000.serial: no wakeirq for uart1
    [    1.309143] of_get_named_gpiod_flags: can't parse 'rts-gpio' property of node '/ocp/serial@4806c000[0]'
    [    1.309351] 4806c000.serial: ttyO1 at MMIO 0x4806c000 (irq = 300, base_baud = 3000000) is a OMAP UART1
    [    2.174242] console [ttyO1] enabled
    [    2.179282] [drm] Initialized drm 1.1.0 20060810
    [    2.184273] usbcore: registered new interface driver udl
    [    2.191778] OMAP DSS rev 6.1
    [    2.195778] omapdss_dss 58000000.dss: bound 58001000.dispc (ops dispc_component_ops)
    [    2.207775] panel-dpi display: GPIO lookup for consumer enable
    [    2.207785] panel-dpi display: using device tree for GPIO lookup
    [    2.207819] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/display[0]' - status (0)
    [    2.207870] panel-dpi display: GPIO lookup for consumer lcd-power-enable
    [    2.207879] panel-dpi display: using device tree for GPIO lookup
    [    2.207907] of_get_named_gpiod_flags: parsed 'lcd-power-enable-gpios' property of node '/display[0]' - status (0)
    [    2.232700] panel-dpi display: Obtained video timing via EDID address 0x57
    [    2.241994] dmm 4e000000.dmm: initialized all PAT entries
    [    2.266085] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
    [    2.273055] [drm] No driver support for vblank timestamp query.
    [    2.297280] [drm] Enabling DMM ywrap scrolling
    [    2.522379] Console: switching to colour frame buffer device 160x50
    [    2.711978] omapdrm omapdrm.0: fb0: omapdrm frame buffer device
    [    2.742365] [drm] Initialized omapdrm 1.0.0 20110917 on minor 0
    [    2.767244] loop: module loaded
    [    2.771126] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[0]' - status (0)
    [    2.771183] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[1]' - status (0)
    [    2.771248] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[2]' - status (0)
    [    2.771325] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[3]' - status (0)
    [    2.771457] of_get_named_gpiod_flags: parsed 'revision-gpios' property of node '/board-revision[4]' - status (0)
    [    2.807664] spi_nand_base: SPI-NAND type mfr_id: 2c, dev_id: 14 is not in id table.
    [    2.816909] spi_nand_base: SPI-NAND: MT29F1G01ABAFD12 is found.
    [    2.825573] Bad block table found at page 65472, version 0x01
    [    2.833696] Bad block table found at page 65408, version 0x01
    [    2.841823] nand_read_bbt: bad block at 0x000000000000
    [    2.847187] nand_read_bbt: bad block at 0x000000020000
    [    2.852569] nand_read_bbt: bad block at 0x000000040000
    [    2.857933] nand_read_bbt: bad block at 0x000001a00000
    [    2.863312] nand_read_bbt: bad block at 0x000001a20000
    [    2.868672] nand_read_bbt: bad block at 0x000001a40000
    [    2.874044] nand_read_bbt: bad block at 0x000001a60000
    [    2.879411] nand_read_bbt: bad block at 0x000001a80000
    [    2.884789] nand_read_bbt: bad block at 0x000001aa0000
    [    2.890161] nand_read_bbt: bad block at 0x000001ac0000
    [    2.895520] nand_read_bbt: bad block at 0x000001ae0000
    [    2.900945] nand_read_bbt: bad block at 0x000001b00000
    [    2.906305] nand_read_bbt: bad block at 0x000001b20000
    [    2.911681] nand_read_bbt: bad block at 0x000001b40000
    [    2.917045] nand_read_bbt: bad block at 0x000001b60000
    [    2.922412] nand_read_bbt: bad block at 0x000001b80000
    [    2.927773] nand_read_bbt: bad block at 0x000001ba0000
    [    2.933143] nand_read_bbt: bad block at 0x000001bc0000
    [    2.938503] nand_read_bbt: bad block at 0x000001be0000
    [    2.951032] 1 ofpart partitions found on MTD device MT29F1G01ABAFD12
    [    2.957676] Creating 1 MTD partitions on "MT29F1G01ABAFD12":
    [    2.963663] 0x000000000000-0x000008000000 : "Serial NAND p1"
    [    2.972781] libphy: Fixed MDIO Bus: probed
    [    3.030109] davinci_mdio 48485000.mdio: davinci mdio revision 1.6
    [    3.036502] libphy: 48485000.mdio: probed
    [    3.048349] davinci_mdio 48485000.mdio: phy[1]: device 48485000.mdio:01, driver TI DP83822 10/100 Mbps PHY
    [    3.059519] cpsw 48484000.ethernet: Read MACID from Registers = 04:79:b7:a0:9c:b6
    [    3.067636] cpsw 48484000.ethernet: cpts: overflow check period 800
    [    3.076084] usbcore: registered new interface driver rtl8xxxu
    [    3.489781] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
    [    3.496634] ehci-platform: EHCI generic platform driver
    [    3.502575] ehci-omap: OMAP-EHCI Host Controller driver
    [    3.508376] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
    [    3.514874] ohci-platform: OHCI generic platform driver
    [    3.521340] xhci-hcd xhci-hcd.4.auto: xHCI Host Controller
    [    3.527209] xhci-hcd xhci-hcd.4.auto: new USB bus registered, assigned bus number 1
    [    3.535497] xhci-hcd xhci-hcd.4.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x00210010
    [    3.544670] xhci-hcd xhci-hcd.4.auto: irq 415, io mem 0x48890000
    [    3.551683] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
    [    3.558776] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    3.566335] usb usb1: Product: xHCI Host Controller
    [    3.571442] usb usb1: Manufacturer: Linux 4.4.41 xhci-hcd
    [    3.577076] usb usb1: SerialNumber: xhci-hcd.4.auto
    [    3.584311] hub 1-0:1.0: USB hub found
    [    3.588395] hub 1-0:1.0: 1 port detected
    [    3.594353] xhci-hcd xhci-hcd.4.auto: xHCI Host Controller
    [    3.600166] xhci-hcd xhci-hcd.4.auto: new USB bus registered, assigned bus number 2
    [    3.608347] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
    [    3.617151] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
    [    3.624259] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    3.631824] usb usb2: Product: xHCI Host Controller
    [    3.636917] usb usb2: Manufacturer: Linux 4.4.41 xhci-hcd
    [    3.642570] usb usb2: SerialNumber: xhci-hcd.4.auto
    [    3.649008] hub 2-0:1.0: USB hub found
    [    3.653029] hub 2-0:1.0: 1 port detected
    [    3.658154] xhci-hcd xhci-hcd.5.auto: xHCI Host Controller
    [    3.663977] xhci-hcd xhci-hcd.5.auto: new USB bus registered, assigned bus number 3
    [    3.672234] xhci-hcd xhci-hcd.5.auto: hcc params 0x0220f04c hci version 0x100 quirks 0x00210010
    [    3.681393] xhci-hcd xhci-hcd.5.auto: irq 416, io mem 0x488d0000
    [    3.688039] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002
    [    3.696023] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    3.703621] usb usb3: Product: xHCI Host Controller
    [    3.708718] usb usb3: Manufacturer: Linux 4.4.41 xhci-hcd
    [    3.714367] usb usb3: SerialNumber: xhci-hcd.5.auto
    [    3.720751] hub 3-0:1.0: USB hub found
    [    3.724720] hub 3-0:1.0: 1 port detected
    [    3.729691] xhci-hcd xhci-hcd.5.auto: xHCI Host Controller
    [    3.735497] xhci-hcd xhci-hcd.5.auto: new USB bus registered, assigned bus number 4
    [    3.743710] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
    [    3.753013] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003
    [    3.760152] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
    [    3.767704] usb usb4: Product: xHCI Host Controller
    [    3.772843] usb usb4: Manufacturer: Linux 4.4.41 xhci-hcd
    [    3.778479] usb usb4: SerialNumber: xhci-hcd.5.auto
    [    3.784897] hub 4-0:1.0: USB hub found
    [    3.788872] hub 4-0:1.0: 1 port detected
    [    3.794068] usbcore: registered new interface driver cdc_acm
    [    3.799981] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
    [    3.808585] usbcore: registered new interface driver usb-storage
    [    3.815529] couldn't find an available UDC
    [    3.816363] mousedev: PS/2 mouse device common for all mice
    [    3.823871] atmel_mxt_ts 1-004a: __mxt_read_reg: i2c transfer failed (-121)
    [    3.831364] atmel_mxt_ts 1-004a: mxt_bootloader_read: i2c recv failed (-121)
    [    3.838727] atmel_mxt_ts 1-004a: Trying alternate bootloader address
    [    3.845568] atmel_mxt_ts 1-004a: mxt_bootloader_read: i2c recv failed (-121)
    [    3.853162] atmel_mxt_ts: probe of 1-004a failed with error -121
    [    3.859666] usbcore: registered new interface driver usbtouchscreen
    [    3.866370] rtc-pcf85063 3-0051: chip found, driver version 0.0.1
    [    3.892335] rtc-pcf85063 3-0051: rtc core: registered rtc-pcf85063 as rtc0
    [    3.899603] i2c /dev entries driver
    [    3.907315] /thermal-zones/board_thermal: could not get #thermal-sensor-cells for /ocp/i2c@4807a000/tmon@48
    [    3.917516] lm75 3-0048: hwmon0: sensor 'tmp75'
    [    3.924514] omap_wdt: OMAP Watchdog Timer Rev 0x01: initial timeout 60 sec
    [    3.933850] omap_hsmmc 4809c000.mmc: GPIO lookup for consumer cd
    [    3.933861] omap_hsmmc 4809c000.mmc: using device tree for GPIO lookup
    [    3.933894] of_get_named_gpiod_flags: parsed 'cd-gpios' property of node '/ocp/mmc@4809c000[0]' - status (0)
    [    3.933914] omap_hsmmc 4809c000.mmc: Got CD GPIO
    [    3.938735] omap_hsmmc 4809c000.mmc: GPIO lookup for consumer wp
    [    3.938743] omap_hsmmc 4809c000.mmc: using device tree for GPIO lookup
    [    3.938753] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@4809c000[0]'
    [    3.938762] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@4809c000[0]'
    [    3.938770] omap_hsmmc 4809c000.mmc: using lookup tables for GPIO lookup
    [    3.938781] omap_hsmmc 4809c000.mmc: lookup for GPIO wp failed
    [    3.990467] omap_hsmmc 480b4000.mmc: GPIO lookup for consumer cd
    [    3.990478] omap_hsmmc 480b4000.mmc: using device tree for GPIO lookup
    [    3.990488] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp/mmc@480b4000[0]'
    [    3.990498] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp/mmc@480b4000[0]'
    [    3.990506] omap_hsmmc 480b4000.mmc: using lookup tables for GPIO lookup
    [    3.990517] omap_hsmmc 480b4000.mmc: lookup for GPIO cd failed
    [    3.990529] omap_hsmmc 480b4000.mmc: GPIO lookup for consumer wp
    [    3.990536] omap_hsmmc 480b4000.mmc: using device tree for GPIO lookup
    [    3.990545] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@480b4000[0]'
    [    3.990554] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@480b4000[0]'
    [    3.990562] omap_hsmmc 480b4000.mmc: using lookup tables for GPIO lookup
    [    3.990572] omap_hsmmc 480b4000.mmc: lookup for GPIO wp failed
    [    3.990868] omap_hsmmc 480b4000.mmc: no pinctrl state for hs mode
    [    3.997369] vdd_1v8: supplied by vdd_3v3
    [    4.050448] omap_hsmmc 480ad000.mmc: GPIO lookup for consumer cd
    [    4.050458] omap_hsmmc 480ad000.mmc: using device tree for GPIO lookup
    [    4.050468] of_get_named_gpiod_flags: can't parse 'cd-gpios' property of node '/ocp/mmc@480ad000[0]'
    [    4.050478] of_get_named_gpiod_flags: can't parse 'cd-gpio' property of node '/ocp/mmc@480ad000[0]'
    [    4.050486] omap_hsmmc 480ad000.mmc: using lookup tables for GPIO lookup
    [    4.050495] omap_hsmmc 480ad000.mmc: lookup for GPIO cd failed
    [    4.050507] omap_hsmmc 480ad000.mmc: GPIO lookup for consumer wp
    [    4.050514] omap_hsmmc 480ad000.mmc: using device tree for GPIO lookup
    [    4.050523] of_get_named_gpiod_flags: can't parse 'wp-gpios' property of node '/ocp/mmc@480ad000[0]'
    [    4.050532] of_get_named_gpiod_flags: can't parse 'wp-gpio' property of node '/ocp/mmc@480ad000[0]'
    [    4.050540] omap_hsmmc 480ad000.mmc: using lookup tables for GPIO lookup
    [    4.050549] omap_hsmmc 480ad000.mmc: lookup for GPIO wp failed
    [    4.101190] ledtrig-cpu: registered to indicate activity on CPUs
    [    4.120414] optee firmware:optee: probing for conduit method from DT.
    [    4.140542] optee firmware:optee: initialized driver
    [    4.152275] of_get_named_gpiod_flags: can't parse 'gpio-reset' property of node '/ocp/i2c@4807a000/tlv320aic3104@18[0]'
    [    4.169069] oprofile: using timer interrupt.
    [    4.180584] Initializing XFRM netlink socket
    [    4.185114] NET: Registered protocol family 17
    [    4.189805] NET: Registered protocol family 15
    [    4.210367] Key type dns_resolver registered
    [    4.215027] omap_voltage_late_init: Voltage driver support not added
    [    4.241277] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [    4.247742] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [    4.260195] lp8733-buck0: supplied by vdd_3v3
    [    4.271389] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm
    [    4.277846] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm
    [    4.304803] Power Management for TI OMAP4+ devices.
    [    4.320258] ThumbEE CPU extension supported.
    [    4.324751] Registering SWP/SWPB emulation handler
    [    4.341079] Loading compiled-in X.509 certificates
    [    4.390619] Key type encrypted registered
    [    4.394841] ima: No TPM chip found, activating TPM-bypass!
    [    4.410824] evm: HMAC attrs: 0x1
    [    4.421283] of_get_named_gpiod_flags: can't parse 'simple-audio-card,hp-det-gpio' property of node '/sound@0[0]'
    [    4.421296] of_get_named_gpiod_flags: can't parse 'simple-audio-card,mic-det-gpio' property of node '/sound@0[0]'
    [    4.421327] of_get_named_gpiod_flags: parsed 'amplifier-sd-gpio' property of node '/sound@0[0]' - status (0)
    [    4.424411] asoc-simple-card sound@0: tlv320aic3x-hifi <-> 48468000.mcasp mapping ok
    [    4.456321] of_get_named_gpiod_flags: parsed 'gpios' property of node '/on-off-key/on-off-key[0]' - status (0)
    [    4.456888] input: on-off-key as /devices/platform/on-off-key/input/input0
    [    4.471705] rtc-pcf85063 3-0051: setting system clock to 2019-12-12 10:04:39 UTC (1576145079)
    [    4.573570] net eth0: initializing cpsw version 1.15 (0)
    [    4.580152] net eth0: initialized cpsw ale version 1.4
    [    4.585532] net eth0: ALE Table size 1024
    [    4.680117] dp83848_config_init ---------Override DP83822 PHY Settings-----------
    [    4.687959] dp83848_config_init PHY Address: 0x1
    [    4.710091] Software Reset Device
    [    4.715293] dp83848_config_init RCSR : 0x0241 (Original) -> 0x1241 (Overridden)
    [    4.737138] net eth0: phy found : id is : 0x2000a240
    [    4.940101] Waiting up to 2 more seconds for network.
    [    5.120099] Waiting up to 2 more seconds for network.
    [    5.300112] Waiting up to 1 more seconds for network.
    [    5.380181] mmc0: host does not support reading read-only switch, assuming write-enable
    [    5.392144] mmc0: new high speed SDHC card at address aaaa
    [    5.399592] mmcblk0: mmc0:aaaa SA08G 7.40 GiB 
    [    5.408253]  mmcblk0: p1 p2
    [    5.453392] mmc1: MAN_BKOPS_EN bit is not set
    [    5.464129] mmc1: new HS200 MMC card at address 0001
    [    5.470362] mmcblk1: mmc1:0001 008G30 7.27 GiB 
    [    5.475562] mmcblk1boot0: mmc1:0001 008G30 partition 1 8.00 MiB
    [    5.481793] Waiting up to 1 more seconds for network.
    [    5.487566] mmcblk1boot1: mmc1:0001 008G30 partition 2 8.00 MiB
    [    5.494252] mmcblk1gp0: mmc1:0001 008G30 partition 4 4.00 MiB
    [    5.502023] mmcblk1gp1: mmc1:0001 008G30 partition 5 4.00 MiB
    [    5.510244]  mmcblk1: p1 p2
    [    5.660118] Waiting up to 1 more seconds for network.
    [    5.840143] Waiting up to 1 more seconds for network.
    [    6.020145] Waiting up to 1 more seconds for network.
    [    6.200147] Waiting up to 1 more seconds for network.
    [    6.380146] Waiting up to 0 more seconds for network.
    [    6.560146] Waiting up to 0 more seconds for network.
    [    6.735739] cpsw 48484000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx
    [    6.744225] Waiting up to 0 more seconds for network.
    [    6.760968] IP-Config: Complete:
    [    6.764385]      device=eth0, hwaddr=04:79:b7:a0:9c:b6, ipaddr=192.168.0.1, mask=255.255.255.0, gw=192.168.0.254
    [    6.775210]      host=192.168.0.1, domain=, nis-domain=(none)
    [    6.781365]      bootserver=192.168.0.254, rootserver=192.168.0.254, rootpath=
    [    6.790412] ALSA device list:
    [    6.793543]   #0: WA55-Audio
    [    6.801481] Freeing unused kernel memory: 1424K (c0ac8000 - c0c2c000)
    [    6.808278] This architecture does not have kernel memory protection.
    [    7.513196] random: nonblocking pool is initialized
    [    7.670024] systemd[1]: systemd 234 running in system mode. (-PAM -AUDIT -SELINUX -IMA -APPARMOR -SMACK +SYSVINIT -UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL -XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN default-hierarchy=hybrid)
    [    7.692849] systemd[1]: Detected architecture arm.
    [    7.722000] systemd[1]: Set hostname to <wa55-hs>.
    [    7.732060] systemd[1]: Initializing machine ID from random generator.
    [    8.640412] systemd[1]: Listening on Syslog Socket.
    [    8.660928] systemd[1]: Listening on Journal Socket.
    [    8.682004] systemd[1]: Listening on udev Control Socket.
    [    8.700470] systemd[1]: Reached target Paths.
    [    8.720873] systemd[1]: Listening on Network Service Netlink Socket.
    [    8.750826] systemd[1]: Created slice System Slice.
    [    8.784091] systemd[1]: Mounting Kernel Configuration File System...
    [    8.820580] systemd[1]: Reached target Slices.
    [    8.840882] systemd[1]: Listening on udev Kernel Socket.
    [    8.860918] systemd[1]: Listening on Journal Audit Socket.
    [    8.887485] systemd[1]: Starting Apply Kernel Variables...
    [    8.923989] systemd[1]: Created slice system-serial\x2dgetty.slice.
    [    8.967668] systemd[1]: Mounting POSIX Message Queue File System...
    [    9.008328] systemd[1]: Starting Remount Root and Kernel File Systems...
    [    9.050535] systemd[1]: Reached target Swap.
    [    9.114648] systemd[1]: Mounting Temporary Directory (/tmp)...
    [    9.170502] systemd[1]: Reached target Remote File Systems.
    [    9.196389] systemd[1]: Mounting Kernel Debug File System...
    [    9.220864] systemd[1]: Listening on Journal Socket (/dev/log).
    [    9.255780] systemd[1]: Starting Journal Service...
    [    9.295013] systemd[1]: Starting Create list of required static device nodes for the current kernel...
    [    9.373882] systemd[1]: Mounted Kernel Debug File System.
    [    9.410474] systemd[1]: Mounted Kernel Configuration File System.
    [    9.450745] systemd[1]: Mounted POSIX Message Queue File System.
    [    9.490710] systemd[1]: Mounted Temporary Directory (/tmp).
    [    9.540794] systemd[1]: Started Apply Kernel Variables.
    [    9.591367] systemd[1]: Started Remount Root and Kernel File Systems.
    [    9.634656] systemd[1]: Started Create list of required static device nodes for the current kernel.
    [    9.661317] systemd[1]: Started Journal Service.
    [    9.964902] systemd-journald[135]: Received request to flush runtime journal from PID 1
    [   13.086629] [drm] Initialized pvr 1.14.3699939 20110701 on minor 1
    [   13.130772] omap-rproc 55020000.ipu: assigned reserved memory node ipu2_cma@95800000
    [   13.139001]  remoteproc0: 55020000.ipu is available
    [   13.176414] of_get_named_gpiod_flags: parsed 'battery-level-gpio' property of node '/pwm_battery_level[0]' - status (0)
    [   13.176443] PWM-BATTERY-LEVEL:  pwm_baterry_level_probe Done 0 
    [   13.226603] of_get_named_gpiod_flags: parsed 'wlan-enable-gpio' property of node '/power-module[0]' - status (0)
    [   13.226655] of_get_named_gpiod_flags: parsed 'power-good-gpio' property of node '/power-module[0]' - status (0)
    [   13.226790] of_get_named_gpiod_flags: parsed 'bsp-support-gpios' property of node '/power-module[0]' - status (0)
    [   13.226889] of_get_named_gpiod_flags: parsed 'bsp-support-gpios' property of node '/power-module[1]' - status (0)
    [   13.232992]  remoteproc0: Note: remoteproc is still under development and considered experimental.
    [   13.258511]  remoteproc0: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [   13.295553] ti-pruss 4b280000.pruss: creating PRU cores and other child platform devices
    [   13.424319] irq: no irq domain found for /ocp/pruss@4b280000/intc@4b2a0000 !
    [   13.547295] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/usb-enable[0]' - status (0)
    [   13.548665] of_get_named_gpiod_flags: parsed 'enable-gpios' property of node '/usb-enable[1]' - status (0)
    [   13.549193] of_get_named_gpiod_flags: parsed 'oc-detect-gpios' property of node '/usb-enable[0]' - status (0)
    [   13.549387] of_get_named_gpiod_flags: parsed 'oc-detect-gpios' property of node '/usb-enable[1]' - status (0)
    [   13.558187] irq: no irq domain found for /ocp/pruss@4b280000/intc@4b2a0000 !
    [   13.687792]  remoteproc0: registered virtio0 (type 7)
    [   13.827090]  remoteproc1: 4b2b4000.pru0 is available
    [   13.869075]  remoteproc1: Note: remoteproc is still under development and considered experimental.
    [   13.947343]  remoteproc1: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [   14.035661] pru-rproc 4b2b4000.pru0: booting the PRU core manually
    [   14.078438]  remoteproc1: powering up 4b2b4000.pru0
    [   14.122551]  remoteproc1: Booting fw image am57xx-pru2_0-fw, size 27428
    [   14.166153]  remoteproc1: remote processor 4b2b4000.pru0 is now up
    [   14.197157] pru-rproc 4b2b4000.pru0: PRU rproc node /ocp/pruss@4b280000/pru0@4b2b4000 probed successfully
    [   14.224442]  remoteproc2: 4b2b8000.pru1 is available
    [   14.229652]  remoteproc2: Note: remoteproc is still under development and considered experimental.
    [   14.246546]  remoteproc0: powering up 55020000.ipu
    [   14.252647]  remoteproc2: THE BINARY FORMAT IS NOT YET FINALIZED, and backward compatibility isn't yet guaranteed.
    [   14.286531]  remoteproc2: powering up 4b2b8000.pru1
    [   14.297943]  remoteproc0: Booting fw image dra7-ipu2-fw.xem4, size 3747236
    [   14.307122]  remoteproc2: Booting fw image am57xx-pru2_1-fw, size 93252
    [   14.316184] omap-iommu 55082000.mmu: 55082000.mmu: version 2.1
    [   14.326114] ti-pruss 4b280000.pruss: configured system_events = 0x00000000000c0000 intr_channels = 0x0000000a host_intr = 0x0000000a
    [   14.345305]  remoteproc2: remote processor 4b2b8000.pru1 is now up
    [   14.353049] virtio_rpmsg_bus virtio1: rpmsg host is online
    [   14.353240] virtio_rpmsg_bus virtio1: creating channel pru-rotary-driver addr 0x21
    [   14.377269]  remoteproc2: registered virtio1 (type 7)
    [   14.383475] pru-rproc 4b2b8000.pru1: PRU rproc node /ocp/pruss@4b280000/pru1@4b2b8000 probed successfully
    [   14.562890]  remoteproc0: remote processor 55020000.ipu is now up
    [   14.575764] virtio_rpmsg_bus virtio0: rpmsg host is online
    [   14.581776] virtio_rpmsg_bus virtio0: creating channel rpmsg-rpc addr 0x65
    [   14.608148] virtio_rpmsg_bus virtio0: creating channel rpmsg-rpc addr 0x66
    [   14.633716] rpmsg_rpc rpmsg1: probing service dce-callback with src 1024 dst 101
    [   14.654249] rpmsg_rpc rpmsg1: published functions = 4
    [   14.662455] rpmsg_rpc rpmsg2: probing service rpmsg-dce with src 1025 dst 102
    [   14.683431] rpmsg_rpc rpmsg2: published functions = 9
    [   14.855480] EXT4-fs (mmcblk1gp1): mounted filesystem with ordered data mode. Opts: (null)
    [   14.886159] EXT4-fs (mmcblk1gp0): mounted filesystem with ordered data mode. Opts: (null)
    [   15.377782] PVR_K: UM DDK-(3699939) and KM DDK-(3699939) match. [ OK ]
    [   17.110905] RSP485: INIT...
    [   17.142439] RSP SNIFFER: INIT
    [   17.200755] RSP SNIFFER READY FOR USE
    [   17.213287] rotary_enc rpmsg0: new channel: 0x400 -> 0x21!
    [   17.266586] input: rotary_encoder_input as /devices/virtual/input/input1
    [   17.343559] GPIO Requested
    [   17.346505] rotary_enc rpmsg0: PRU Rotary Encoder Keyboard driver registered
    [   17.427619] RSP LINE-DISC INIT -- IOCTL Version
    [   17.458448] RSP LINE-DISC READY FOR USE
    [   17.741776] mmc2: new high speed SDIO card at address 0001
    [   17.888625] mlan: module license 'Marvell Proprietary' taints kernel.
    [   17.917593] Disabling lock debugging due to kernel taint
    [   18.021511] wlan: Loading MWLAN driver
    [   18.042362] vendor=0x02DF device=0x9139 class=0 function=1
    [   18.062178] rx_work=0 cpu_num=1
    [   18.092636] Request firmware: mrvl/sd8801_uapsta.bin
    [   18.951827] Wlan: FW download over, firmwarelen=234524 downloaded 234524
    [   19.261902] WLAN FW is active
    [   19.288557] fw_cap_info=0xba3, dev_cap_mask=0xffffffff
    [   19.304617] wlan: version = SD8801-14.85.36.p101-C3X14C160-GPL-(FP85) 
    [   19.326172] wlan: Driver loaded successfully
    

  • Hi Stef,

    stef boerrigter said:

    2: The working example i have added extra printk in probe function of omap-hsmmc driver to display if ADMA / DMA is beeing initialized: 

    [ 3.959246] SB: - omap_hsmmc_probe: using ADMA mmc0
    [ 4.017467] SB: - omap_hsmmc_probe: using ADMA mmc1
    [ 4.071086] SB: - omap_hsmmc_probe: using DMA mmc2

    So it seems that MMC0 & 1 use the ADMA and MMC2 doesn't have this capability and uses 'regular?' DMA in 4.4 kernel

    Yes MMC1/MMC2 HW modules (a.k.a. mmc0/mmc1 in Linux) vs. MMC3/MMC4 HW module have different DMA hardware capabilities, as per device technical reference manual, so some difference here is expected.

    Also I had since gotten a chance to talk to our driver developer specifically regarding DMA and he said that the SDMA nodes were taken away in the later Kernels since that was not supported by sdhci library and it didn’t make sense to add it only for sdhci-omap. However that’s changing now (lkml.org/.../145). But it should work in PIO mode even if doesn’t have DMA, which is how we have the WiFi module working on the "BeagleBone AI".

    Regards, Andreas

  • Hi Andreas, TI Team,

    I know that it should work also without dma, altough it would mean a significant performance penalty to not do it of-course. 

    Regarding the issue; i have had contact with the U-Blox team, and they asked me to capture some SDIO traffic data, and the following was the result:

    1. See the following image; this is a SDIO capture between MMC3 and Lily module using the 4.4 kernel, where the data transfer is working as expected using omap-HSMMC driver. The AM5708 keeps the SDIO clock running untill the DATA_1 line (as interrupt) triggers an interrupt, after this the data is transfer is picked up again. 


    2. The image below shows the 4.19 kernel using the omap sdhci variant as default in the 4.19 kernel from the TI SDK. As you can see in the image the Host stops the clock, therefore missing the DATA_1 interrupt. 

    Can you explain why these drivers behave so different? and more important, how we can restore such behaviour on the SOC? since we had it working on our platform it is just a software configuration thing.

    Looking forward to your reply,

    Best Regards,
    Stef

  • any update to be reported on this topic?

  • Hi Stef,

    stef boerrigter said:
    since we had it working on our platform it is just a software configuration thing.

    Yes :)

    On a more serious note, let me dive into this again to see if there is something that we might have missed. I'll also reach out one more time to our MMC driver developer to see if he has any additional inputs. Expect to hear back in 1-2 working days.

    Regards, Andreas

  • Thanks Andreas,

    Also our WiFi module supplier mentions the following regarding the SDHC-MMC driver:

    "NXP (marvell) confirmed that the SDIO clock should be kept running to be able to signal IRQs from the FW to the host:

    That actually can cause the problem described in the ticket. If the host switches off the SDIO clock after a command has been transferred to the FW, the FW response on that command cannot be indicated to the host. That leads to timeout errors in the protocol between FW and host driver, and hence communication with the device fails. Likewise, any other events triggered by the FW cannot be indicated to the host if the SDIO clock is off.

    I think the simplest approach would be to disable SDIO clock gating. This feature makes sense if an SD memory device is attached, but for SDIO type devices which require a working interrupt, it is less useful. SDIO clock gating should usually be a configuration option in the SDIO bus driver.

    We do not support out-of-band interrupts with our FW implementation to work around this problem."

    To summarize i'm seeking answers / solutions for the following two questions/issues: 

    1. Omap-hsmmc driver backport from 4.4 kernel to 4.19 doesn't work, no communication starting (see 2 / 3 comments back for logic analyzer captures)

    2. omap-sdhci driver in 4.19 kernel doesn't see IRQ due to SDIO-clock-gating. 

  • Stef,

    I had checked with our driver developer again if he has additional suggestions, and here is his response (unfiltered) for your reference:

    Setting CON_CLKEXTFREE in sdhci_omap_enable_sdio_irq() should have kept the clock to the card always enabled which is already present. What was the hack that has to be added?
    sdhci-omap doesn't support power management at all i.e the clocks to the MMC controller should never go off (that's why you only see get_sync in probe and put_sync in remove). The omap_hsmmc_configure_wake_irq() is required for configuring when the module is completely powered off.
    Did you check if there are any pinmux differences between 4.4 and 4.19? IODELAY values certainly changed between the two kernels but I'm not sure if that's causing any impact.

    As a next step I'm trying to get my hands on one of these Lily modules to experiment with different settings and compare non-working vs. working scenario.

    One thing for example that could be tried is to see if there are any differences in the MMC controller configuration (and the configuration of related modules) at a comparable point in time that is common between the working (4.4) vs non-working (4.19) scenarios by dumping various control registers, such as when the print of "WLAN FW is active" happens or some time beyond that. Sometimes one can go backwards from register setting differences and see what the software needs to do differently.

    Regards, Andreas

  • Andreas Dannenberg said:
    As a next step I'm trying to get my hands on one of these Lily modules to experiment with different settings and compare non-working vs. working scenario.

    Just to close this out here, I was since able to get one of those Marvell-based U-Blox Wi-Fi modules into my hands to debug locally, and was able to find the root cause and fix the MMC/SDIO communication issues with that module that were reported using Kernel 4.19.

    Long story short, it turns out that functionality is actually working on AM57xx devices using our TI Kernel 5.4-based integration tree (that will be the base for the upcoming 7.xx versions of the Processor SDK for Linux, available at https://git.ti.com/cgit/ti-linux-kernel/ti-linux-kernel/log/?h=ti-linux-5.4.y), and I was able to identify and backport related changes from the drivers/mmc/host/sdhci.c driver from Kernel 5.4 to Kernel 4.19.

    First, here is the list of commits that are in the TI Kernel 5.4.y on that sdhci.c file but NOT in 4.19.y:

    adannenb@beast:~/git/linux
    $ git log --oneline --no-merges ti-linux-5.4.y-sd-wifi-dev ^ti-linux-4.19.y-sd-wifi-dev drivers/mmc/host/sdhci.c
    10448fb57940 mmc: sdhci: Add a quirk for broken command queuing
    ecfcddc0f110 mmc: sdhci: Update the tuning failed messages to pr_debug level
    e4425c477ace Revert "mmc: sdhci: Fix incorrect switch to HS mode"
    4ee7dde4c777 mmc: sdhci: Let drivers define their DMA mask
    d1c536e31773 mmc: sdhci: improve ADMA error reporting
    0e62614b6c22 mmc: sdhci: Convert to use sdio_irq_claimed()
    af5d2b7b0d24 mmc: sdhci: Drop redundant code for SDIO IRQs
    a84ad3242e53 mmc: sdhci: Drop redundant check in sdhci_ack_sdio_irq()
    c894e33ddc19 mmc: sdhci: Fix incorrect switch to HS mode
    38eee2e82c57 mmc: sdhci: use lower/upper_32_bits() macros for DMA addresses
    8784edc8fa93 mmc: sdhci: constify references of parameters to __sdhci_read_caps()
    7353788c6a63 mmc: sdhci: Export sdhci_abort_tuning function symbol
    1beabbdba708 mmc: sdhci: Add PLL Enable support to internal clock setup
    4a9e0d1a6256 mmc: sdhci: Change timeout of loop for checking internal clock stable
    c6303c5d52d5 mmc: sdhci-sprd: Fix the incorrect soft reset operation when runtime resuming
    2874c5fd2842 treewide: Replace GPLv2 boilerplate/reference with SPDX - rule 152
    89f3c365f3e1 mmc: sdhci: Fix SDIO IRQ thread deadlock
    c07a48c26519 mmc: sdhci: Remove finish_tasklet
    19d2f695f4e8 mmc: sdhci: Call mmc_request_done() from IRQ handler if possible
    e9a072993d69 mmc: sdhci: Move some processing to __sdhci_finish_mrq()
    97a1abae46a6 mmc: sdhci: Move timer and has_requests functions
    2e72ab9b2f56 mmc: sdhci: Reorganize sdhci_finish_mrq() and __sdhci_finish_mrq()
    1d8cd065f7ab mmc: sdhci: allow host to specify maximum tuning loops
    fb24ea52f78e drivers: Remove explicit invocations of mmiowb()
    6d5cd068ee59 mmc: sdhci: use WP GPIO in sdhci_check_ro()
    4c4faff62bf5 mmc: sdhci: Add ADMA3 DMA support for V4 enabled host
    401059df9b62 mmc: sdhci: correct the maximum timeout when enable CMDQ
    2b06e1597ac2 mmc: sdhci: add delay after the last tuning command
    750afb08ca71 cross-tree: phase out dma_zalloc_coherent()
    97207c12780d mmc: sdhci: Fix sdhci_do_enable_v4_mode
    bd29f58bc061 mmc: sdhci: Add quirk to disable LED control
    af849c86109d mmc: sdhci: Handle auto-command errors
    869f8a69bb3a mmc: sdhci: Rename SDHCI_ACMD12_ERR and SDHCI_INT_ACMD12ERR
    4bf780996669 mmc: sdhci: Fix data command CRC error handling
    a68dd9a008e1 mmc: sdhci: Convert sdhci_allocate_bounce_buffer() to return void
    b704441e38f6 mmc: sdhci: fix the timeout check window for clock and reset
    07be55b567a5 mmc: sdhci: fix __sdhci_adma_write_desc
    7ed71a9df4ba mmc: sdhci: SDMA may use Auto-CMD23 in v4 mode
    427b6514d095 mmc: sdhci: Add Auto CMD Auto Select support
    e65953d4a117 mmc: sdhci: Add 32-bit block count support for v4 mode
    685e444bbaa0 mmc: sdhci: Add ADMA2 64-bit addressing support for V4 mode
    917a0c52d6c3 mmc: sdhci: Change SDMA address register for v4 mode
    b3f80b434f72 mmc: sdhci: Add sd host v4 mode
    18da1990d2dd mmc: sdhci: Add version V4 definition
    54552e4948cb mmc: sdhci: introduce adma_write_desc() hook to struct sdhci_ops
    e93be38af155 mmc: sdhci: add adma_table_cnt member to struct sdhci_host
    d462c1b47452 mmc: sdhci: Export sdhci_request()
    7d8bb1f46e13 mmc: sdhci: add tuning error codes

    Turns out applying (cherry-picking) the patches listed starting with 7d8bb1f46e13 ("mmc: sdhci: add tuning error codes") up to 89f3c365f3e1 ("mmc: sdhci: Fix SDIO IRQ thread deadlock") will fix the issue. Note that I did not optimize my “cherry-pick” list further at this point since the more you deviate the more conflicts (and potential undesirable side effects) you create. Also some of the other changes including some I did not cherry pick may also be beneficial for other reasons, so I would encourage reviewing the entire list for additional patches that could be beneficial, and of course to perform proper system testing to make sure no regressions are introduced in related functionality (such as eMMC/MMC/SD card access).

    For convenience attached a tarball that contains the aforementioned patches to fix the issue to apply (via 'git am') on top of the Kernel 4.19-based TI tree as it is being used in the currently-shipping Kernel 4.19-based AM57xx Processor SDK Linux v6.xx.

    In addition, I would expect future v7.xx versions of the processor SDK to not need those patches, as said SDKs will be based on the on our TI Kernel 5.4-based integration tree.

    Regards, Andreas

    sdio-wifi-patches-for-ti-linux-4.19.y-22-Jan-2020.tar.gz

  • Hi Andreas,

    The above solution fixed our issue. the only problem left was a performance issue on the MMC bus. 
    Reverting (partial) commit: 

    940293affa7ed7c0bdb1820ecf7a8f12e901d030 (“ARM: dts: dra7: Use sdhci-omap programming model”)

    To get the MMC3 interface back to omap-hsmmc driver, and to use External DMA for the interface solves the issue. 

    We have tested and reviewed this internally and conclude that it is sufficient for us.

    We do hope that the SDK 7 release supports performant SDHCI driver on the MMC3 and 4 interface, with external DMA if possible so that we can merge upstream after the SDK 7 release later this year.

    Best Regards,
    Stef

  • Stef,

    thanks for closing the loop and summarizing the outcome.

    stef boerrigter said:
    We do hope that the SDK 7 release supports performant SDHCI driver on the MMC3 and 4 interface, with external DMA if possible so that we can merge upstream after the SDK 7 release later this year.

    Understood. Let me re-iterate this with our development team. I had also talked to Jason Kridner from the BeagleBone team, and he mentioned that the WiFi TCP throughput on the AM57xx-based BB-AI where an SDIO-based BCMxxx WiFi module is connected in a similar fashion is around 100MBit/s (I have not verified this myself, but it is on my list). Assuming this number can be readily re-created the question is why is it so different from compared with the Marvell-based U-Blox module. Then, for us to really do improvements we need a readily-available platform we can regression-test this in our test farm. If the BB-AI is truly not affected by this performance issue this poses a new challenge of finding a suitable platform.

    Regards, Andreas